Soluciona problemas de latencia en la biblioteca cliente de Java

Introducción

Si tu app experimenta una latencia más alta de lo normal, un rendimiento deficiente o tiempos de espera con el cliente de Datastore de Java, es posible que el problema se deba a la configuración de gRPC del cliente y no al backend de Firestore o Datastore. En esta guía, se te ayudará a diagnosticar y resolver problemas comunes de limitación del cliente, configuración incorrecta del grupo de canales y rotación excesiva de canales.

Diagnóstico

Cuando se usan clientes de Java, habilitar el registro detallado de gRPC y gax-java es fundamental para supervisar la dinámica del grupo de canales, diagnosticar la limitación, los problemas de reutilización de conexiones o identificar la rotación excesiva de canales.

Habilita el registro para clientes de Java

Para habilitar el registro detallado, modifica el archivo logging.properties de la siguiente manera:

## This tracks the lifecycle events of each grpc channel 
io.grpc.ChannelLogger.level=FINEST
## Tracks channel pool events(resizing, shrinking) from GAX level
com.google.api.gax.grpc.ChannelPool.level=FINEST

Además, actualiza el nivel de registro de salida en logging.properties para capturar estos registros:


# This could be changed to a file or other log output
handlers=java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.level=FINEST
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter

Aplica la configuración

El archivo logging.properties se puede aplicar con uno de los siguientes métodos:

1. A través de una propiedad del sistema de JVM

Agrega este argumento cuando inicies la aplicación Java:

-Djava.util.logging.config.file=/path/to/logging.properties

2. Carga de forma programática

Este método es útil para las pruebas de integración o las aplicaciones en las que la configuración de registro se administra dentro del código. Asegúrate de que este código se ejecute al principio del ciclo de vida de la aplicación.

LogManager logManager = LogManager.getLogManager();
  try (final InputStream is = Main.class.getResourceAsStream("/logging.properties")) {
logManager.readConfiguration(is);
}

Ejemplo de registro

Después de habilitar el registro detallado, verás una combinación de mensajes de com.google.api.gax.grpc.ChannelPool y io.grpc.ChannelLogger:

Canales con aprovisionamiento insuficiente que activaron la expansión del grupo de canales:

09:15:30.123 [pool-1-thread-1] DEBUG com.google.api.gax.grpc.ChannelPool - Detected throughput peak of 40, expanding channel pool size: 4 -> 6. 
09:15:30.124 [grpc-nio-worker-ELG-1-5] DEBUG io.grpc.ChannelLogger - [Channel<5>: (datastore.googleapis.com:443)] Entering IDLE state 
09:15:30.124 [grpc-nio-worker-ELG-1-5] DEBUG io.grpc.ChannelLogger - [Channel<6>: (datastore.googleapis.com:443)] Entering IDLE state 
09:15:30.125 [grpc-nio-worker-ELG-1-5] TRACE io.grpc.ChannelLogger - [Channel<5>: (datastore.googleapis.com:443)] newCall() called 
09:15:30.126 [grpc-nio-worker-ELG-1-5] DEBUG io.grpc.ChannelLogger - [Channel<5>: (datastore.googleapis.com:443)] Entering CONNECTING state 09:15:30.127 [grpc-nio-worker-ELG-1-5] DEBUG io.grpc.ChannelLogger - [Channel<5>: (datastore.googleapis.com:443)] Entering READY state with picker: Picker{result=PickResult{subchannel=Subchannel<7>: (datastore.googleapis.com:443), streamTracerFactory=null, status=Status{code=OK, description=null, cause=null}, drop=false, authority-override=null}} 
09:15:31.201 [grpc-nio-worker-ELG-1-6] TRACE io.grpc.ChannelLogger - [Channel<6>: (datastore.googleapis.com:443)] newCall() called 
09:15:31.202 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.ChannelLogger - [Channel<6>: (datastore.googleapis.com:443)] Entering CONNECTING state 09:15:31.203 [grpc-nio-worker-ELG-1-6] DEBUG io.grpc.ChannelLogger - [Channel<6>: (datastore.googleapis.com:443)] Entering READY state with picker: Picker{result=PickResult{subchannel=Subchannel<8>: (datastore.googleapis.com:443), streamTracerFactory=null, status=Status{code=OK, description=null, cause=null}, drop=false, authority-override=null}}

Canales con exceso de aprovisionamiento que provocaron la reducción del grupo de canales:

09:13:59.609 [grpc-nio-worker-ELG-1-4] DEBUG io.grpc.ChannelLogger - [Channel<21>: (datastore.googleapis.com:443)] Entering READY state with picker: Picker{result=PickResult{subchannel=Subchannel<23>: (datastore.googleapis.com:443), streamTracerFactory=null, status=Status{code=OK, description=null, cause=null}, drop=false, authority-override=null}}
09:14:01.998 [pool-1-thread-1] DEBUG com.google.api.gax.grpc.ChannelPool - Detected throughput drop to 0, shrinking channel pool size: 8 -> 6.
09:14:01.999 [pool-1-thread-1] TRACE io.grpc.ChannelLogger - [Channel<13>: (datastore.googleapis.com:443)] shutdown() called
09:14:01.999 [pool-1-thread-1] DEBUG io.grpc.ChannelLogger - [Channel<13>: (datastore.googleapis.com:443)] Entering SHUTDOWN state
09:14:01.999 [pool-1-thread-1] DEBUG io.grpc.ChannelLogger - [Channel<13>: (datastore.googleapis.com:443)] Terminated
09:14:01.999 [pool-1-thread-1] TRACE io.grpc.ChannelLogger - [Channel<15>: (datastore.googleapis.com:443)] shutdown() called
09:14:01.999 [pool-1-thread-1] DEBUG io.grpc.ChannelLogger - [Channel<15>: (datastore.googleapis.com:443)] Entering SHUTDOWN state
09:14:01.999 [pool-1-thread-1] DEBUG io.grpc.ChannelLogger - [Channel<15>: (datastore.googleapis.com:443)] Terminated

Estas entradas de registro son útiles para lo siguiente:

  1. Supervisa las decisiones de cambio de tamaño del canal
  2. Identificación de la reutilización del canal Deserción
  3. Cómo detectar problemas de conectividad del transporte

Cómo interpretar los registros para diagnosticar síntomas

Cuando soluciones problemas de rendimiento, como latencia alta o errores, comienza por habilitar el registro para com.google.api.gax.grpc.ChannelPool y io.grpc.ChannelLogger. Luego, relaciona los síntomas que observas con las situaciones comunes de esta guía para interpretar los registros y encontrar una solución.

Síntoma 1: Latencia alta durante el inicio o los aumentos repentinos de tráfico

Es posible que notes que las primeras solicitudes después de que se inicia tu aplicación son lentas o que la latencia aumenta drásticamente cada vez que el tráfico aumenta repentinamente.

Causa posible

Esta latencia suele ocurrir cuando tu grupo de canales no tiene la capacidad suficiente. Cada canal de gRPC puede controlar una cantidad limitada de solicitudes simultáneas (100, limitado por el middleware de Google). Una vez que se alcance este límite, las RPCs nuevas se pondrán en cola del lado del cliente y esperarán una ranura disponible. Esta puesta en cola es la principal fuente de latencia.

Si bien el grupo de canales está diseñado para adaptarse a los cambios en la carga, su lógica de cambio de tamaño se ejecuta periódicamente (de forma predeterminada, cada minuto) y se expande de forma gradual (de forma predeterminada, agrega como máximo 2 canales a la vez). Por lo tanto, existe un retraso inherente entre el aumento inicial del tráfico y la expansión del grupo. La latencia se producirá durante este período, mientras las solicitudes nuevas esperan a que se liberen los canales saturados o a que el grupo agregue canales nuevos en su próximo ciclo de cambio de tamaño.

Registros que debes buscar

Busca registros que indiquen que el grupo de canales se está expandiendo. Esta es la evidencia principal de que el cliente está reaccionando a un pico de tráfico que superó su capacidad actual.

Registro de expansión del grupo de canales:

[pool-1-thread-1] DEBUG com.google.api.gax.grpc.ChannelPool - Detected throughput peak of 40, expanding channel pool size: 4 -> 6.

Interpretación: El grupo detectó un aumento repentino del tráfico y está abriendo nuevas conexiones para controlar el aumento de la carga. La expansión frecuente, en especial cerca del inicio, es un signo claro de que tu configuración inicial no es suficiente para tu carga de trabajo típica.

Cómo resolver el problema

El objetivo es tener suficientes canales listos antes de que llegue el tráfico, lo que evitará que el cliente tenga que crearlos bajo presión.

Aumenta initialChannelCount (alta latencia en el inicio):

Si observas una latencia alta durante el inicio, la solución más eficaz es aumentar el valor de initialChannelCount en ChannelPoolSettings. De forma predeterminada, este valor se establece en 10, lo que podría ser demasiado bajo para las aplicaciones que controlan un tráfico significativo durante el inicio.

Para encontrar el valor correcto de la aplicación, debes hacer lo siguiente:

  1. Habilita el registro de nivel FINEST para com.google.api.gax.grpc.ChannelPool.
  2. Ejecuta tu aplicación con una carga de trabajo inicial típica o un aumento repentino del tráfico.
  3. Observa los registros de expansión del grupo de canales para ver en qué tamaño se estabiliza el grupo.

Por ejemplo, si ves registros como los siguientes:
[pool-1-thread-1] DEBUG com.google.api.gax.grpc.ChannelPool - Detected throughput peak of 80, expanding channel pool size: 4 -> 6.

y, luego, un minuto después, verás los registros:

[pool-1-thread-1] DEBUG com.google.api.gax.grpc.ChannelPool - Detected throughput peak of 95, expanding channel pool size: 6 -> 8.

Si ves que el tamaño del grupo de canales expandido se estabilizó en 8 canales y no se encuentran más registros de expansión, esto indica que tu aplicación necesitaba 8 canales para controlar su carga de trabajo. Un buen punto de partida sería establecer tu initialChannelCount en 8. Esto garantiza que las conexiones se establezcan por adelantado, lo que reduce o elimina la latencia causada por el ajuste de escala sobre la marcha.

El objetivo es garantizar que el grupo tenga capacidad suficiente para controlar la carga máxima sin poner en cola las solicitudes.

Aumento de minChannelCount (aumentos de tráfico):

Si experimentas una latencia alta, en especial al comienzo de los picos de tráfico, es una señal de que tu tráfico aumenta más rápido de lo que el grupo de canales puede crear conexiones nuevas de forma reactiva. Esto es común en las aplicaciones con ráfagas de tráfico repentinas y predecibles.

El grupo se estabiliza con una pequeña cantidad de canales durante el tráfico normal y agrega más de forma proactiva a medida que aumenta el tráfico para evitar la saturación. Este proceso de escalamiento lleva tiempo, lo que hace que las solicitudes iniciales en una ráfaga se pongan en cola, lo que genera una latencia alta.

Aumentar minChannelCount establece un valor de referencia más alto de canales abiertos de forma permanente. Esto garantiza que ya haya suficiente capacidad disponible para controlar el aumento inicial, lo que elimina la demora en el ajuste de escala y el aumento de latencia asociado.

Aumento de maxChannelCount (aumentos de tráfico):

Si observas una latencia alta durante los picos de tráfico y tus registros muestran que el grupo de canales alcanza su tamaño máximo de forma constante (maxChannelCount), es probable que el límite actual sea demasiado bajo para tu tráfico máximo. De forma predeterminada, maxChannelCount se establece en 200. Para determinar un mejor valor, usa la guía de configuración del grupo de conexiones para calcular la cantidad óptima de conexiones según las consultas por segundo (QPS) máximas y la latencia promedio de las solicitudes de tu aplicación.

Síntoma 2: Agotamiento del tiempo de espera o fallas de RPC intermitentes

A veces, la aplicación funciona bien la mayor parte del tiempo, pero, en ocasiones, sufre tiempos de espera intermitentes o RPCs fallidas, incluso durante períodos de tráfico normal.

Causa posible: Inestabilidad de la red

Se descartan las conexiones entre el cliente y el servicio de Datastore. El cliente de gRPC intentará volver a conectarse automáticamente, pero este proceso puede causar fallas temporales y latencia.

Registros que debes buscar

El registro más importante para diagnosticar problemas de red es TRANSIENT_FAILURE.

  • Registro de fallas transitorias:
[grpc-nio-worker-ELG-1-7] DEBUG io.grpc.ChannelLogger - [Channel<9>: (datastore.googleapis.com:443)] Entering TRANSIENT_FAILURE state
  • Interpretación: Este registro es una señal de alerta importante que indica que el canal perdió la conexión. Una sola falla aislada podría ser solo una pequeña interrupción de la red. Sin embargo, si vemos estos mensajes con frecuencia o un canal se queda atascado en este estado, esto indica un problema subyacente importante.

Cómo resolver el problema

Investiga tu entorno de red. Verifica si hay problemas con firewalls, proxies, routers o inestabilidad general de la red entre la aplicación y datastore.googleapis.com.

Síntoma 3: Latencia alta con más de 20,000 solicitudes simultáneas por cliente

Este síntoma específico se aplica a las aplicaciones que se ejecutan a una escala muy alta, por lo general, cuando una sola instancia del cliente debe controlar más de 20,000 solicitudes simultáneas. La aplicación funciona bien en condiciones normales, pero, a medida que el tráfico aumenta a más de 20,000 solicitudes simultáneas por cliente, se observa una degradación repentina y pronunciada en el rendimiento. La latencia aumenta significativamente y se mantiene alta durante todo el período de tráfico pico. Esto ocurre porque el grupo de conexiones del cliente alcanzó su tamaño máximo y no puede escalar horizontalmente más.

Causa posible

El cliente sufre saturación del canal porque el grupo de canales alcanzó su maxChannelCount configurado. De forma predeterminada, el grupo se configura con un límite de 200 canales. Dado que cada canal de gRPC puede controlar hasta 100 solicitudes simultáneas, este límite solo se alcanza cuando una sola instancia del cliente procesa aproximadamente 20,000 solicitudes de forma simultánea.

Una vez que el grupo alcanza este límite, no puede crear más conexiones. Los 200 canales se sobrecargan y las solicitudes nuevas se ponen en cola del lado del cliente, lo que provoca el pico repentino de latencia.

Los siguientes registros pueden ayudarte a confirmar que se alcanzó el maxChannelCount.

Registros que debes buscar

El indicador clave es observar que el grupo de canales deja de expandirse justo en su límite configurado, incluso cuando continúa la carga.

  • Registros: Verás los registros anteriores de la expansión del grupo. Con la configuración predeterminada, el último registro de expansión que verás antes de los picos de latencia será aquel en el que el grupo alcance los 200 canales:
[pool-1-thread-1] DEBUG com.google.api.gax.grpc.ChannelPool - ... expanding channel pool size: 198 -> 200.
  • Indicador: Durante el período de alta latencia, no verás más registros de "expansión del tamaño del grupo de canales". La ausencia de estos registros, combinada con la alta latencia, es un indicador sólido de que se alcanzó el límite de maxChannelCount.

Cómo resolver el problema

El objetivo es garantizar que el grupo tenga capacidad suficiente para controlar la carga máxima sin poner en cola las solicitudes.

  • Aumenta maxChannelCount: La solución principal es aumentar el parámetro de configuración maxChannelCount a un valor que pueda admitir el tráfico máximo de la aplicación. Consulta la guía de configuración del grupo de conexiones para calcular la cantidad óptima de conexiones según las consultas por segundo (QPS) máximas y la latencia promedio de las solicitudes de la aplicación.

Apéndice

En las siguientes secciones, se proporciona información complementaria para ayudar a solucionar problemas.

Información sobre los estados del canal

Los siguientes estados del canal pueden aparecer en los registros y proporcionan estadísticas sobre el comportamiento de la conexión:

Estado Descripción
IDLE Se crea el canal, pero no tiene conexiones ni RPC activas. Está esperando el tráfico.
CONECTANDO El canal está intentando activamente establecer un nuevo transporte de red (conexión) al servidor de gRPC.
LISTO El canal tiene un transporte establecido y en buen estado, y está listo para enviar RPCs.
TRANSIENT_FAILURE El canal detectó una falla recuperable (p.ej., una interrupción de la red o la no disponibilidad temporal del servidor). Intentará volver a conectarse automáticamente.
SHUTDOWN El canal se cerró, ya sea de forma manual (p.ej., shutdown() llamada) o debido a un tiempo de espera de inactividad. No se pueden iniciar nuevas RPC.

Sugerencias

  • Si usas un framework de registro estructurado como SLF4J o Logback, debes configurar niveles de registro equivalentes en logback.xml o en otros archivos de configuración del registrador. La fachada de registro asignará los niveles de java.util.logging.