Solucionar problemas de latencia en la biblioteca de cliente de Java

Introducción

Si tu aplicación experimenta una latencia superior a la habitual, un rendimiento deficiente o tiempos de espera con el cliente Java Datastore, el problema puede deberse a la configuración de gRPC del lado del cliente en lugar de al backend de Firestore o Datastore. Esta guía te ayudará a diagnosticar y resolver problemas habituales de limitación del lado del cliente, ajustes incorrectos del grupo de canales y rotación excesiva de canales.

Diagnóstico

Cuando se usan clientes Java, es fundamental habilitar el registro detallado de gRPC y gax-java para monitorizar 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.

Habilitar el registro de clientes Java

Para habilitar el registro detallado, modifique 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 registrar estos eventos:


# 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 de dos formas:

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

Añade este argumento al iniciar la aplicación Java:

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

2. Cargar de forma programática

Este método es útil para pruebas de integración o aplicaciones en las que la configuración de registro se gestiona en el 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 han provocado que se amplíe el 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 aprovisionados en exceso que han provocado que se reduzca el 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. Monitorizar las decisiones de cambio de tamaño de los canales
  2. Identificar la reutilización de canales. Churn
  3. Detectar problemas de conectividad de transporte

Interpretar los registros para diagnosticar los síntomas

Cuando tengas que solucionar problemas de rendimiento, como una latencia alta o errores, empieza habilitando el registro de com.google.api.gax.grpc.ChannelPool y io.grpc.ChannelLogger. Después, compara los síntomas que observes con las situaciones habituales que se describen en esta guía para interpretar los registros y encontrar una solución.

Síntoma 1: Latencia alta al inicio o durante picos de tráfico

Puede que observes que las primeras solicitudes después de que se inicie tu aplicación son lentas o que la latencia aumenta considerablemente cuando el tráfico aumenta de repente.

Causa posible

Esta latencia suele producirse cuando tu grupo de canales no tiene suficientes recursos. Cada canal gRPC puede gestionar un número limitado de solicitudes simultáneas (100, limitado por el middleware de Google). Una vez que se alcance este límite, las nuevas RPCs se pondrán en cola en el lado del cliente y esperarán a que haya un espacio disponible. Esta cola es la principal fuente de latencia.

Aunque 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 amplía gradualmente (de forma predeterminada, añadiendo como máximo 2 canales a la vez). Por lo tanto, hay un retraso inherente entre el pico de tráfico inicial y la ampliación del grupo. La latencia se producirá durante este periodo, mientras las nuevas solicitudes esperan a que se liberen los canales saturados o a que el grupo añada nuevos canales 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á ampliando. Esta es la prueba principal de que el cliente está reaccionando a un pico de tráfico que ha superado su capacidad actual.

Registro de ampliació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 ha detectado un pico de tráfico y está abriendo nuevas conexiones para gestionar el aumento de la carga. Una expansión frecuente, sobre todo al principio, es una señal clara de que la configuración inicial no es suficiente para tu carga de trabajo habitual.

Cómo solucionarlo

El objetivo es tener suficientes canales listos antes de que llegue el tráfico para que el cliente no tenga que crearlos con prisas.

Aumentar initialChannelCount (alta latencia al inicio):

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

Para encontrar el valor adecuado para 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 pico de 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 estos:
[pool-1-thread-1] DEBUG com.google.api.gax.grpc.ChannelPool - Detected throughput peak of 80, expanding channel pool size: 4 -> 6.

y, un minuto después, ves 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 ampliado se estabiliza en 8 canales y no se encuentran más registros de ampliación, significa que tu aplicación necesitaba 8 canales para gestionar su carga de trabajo. Un buen punto de partida sería establecer el initialChannelCount en 8. De esta forma, las conexiones se establecen por adelantado, lo que reduce o elimina la latencia causada por el escalado sobre la marcha.

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

Aumento minChannelCount (picos de tráfico):

Si experimentas una latencia alta, sobre todo al principio de los picos de tráfico, significa que el tráfico está aumentando más rápido de lo que el grupo de canales puede crear nuevas conexiones de forma reactiva. Es habitual en aplicaciones con picos de tráfico repentinos y predecibles.

El grupo se estabiliza con un número reducido de canales durante el tráfico normal y añade más de forma proactiva a medida que aumenta el tráfico para evitar la saturación. Este proceso de escalado lleva tiempo, lo que provoca que las solicitudes iniciales de una ráfaga se pongan en cola, lo que da lugar a una latencia alta.

Si aumentas el valor de minChannelCount, se establecerá un valor de referencia más alto de canales abiertos permanentemente. De esta forma, se asegura que ya haya capacidad suficiente para gestionar el pico inicial, lo que elimina el retraso en el escalado y el aumento de la latencia asociado.

Aumento maxChannelCount (picos de tráfico):

Si observas una latencia alta durante los picos de tráfico y tus registros muestran que el grupo de canales está constantemente en su tamaño máximo (maxChannelCount), es probable que el límite actual sea demasiado bajo para tu pico de tráfico. De forma predeterminada, maxChannelCount tiene el valor 200. Para determinar un valor mejor, consulta la guía de configuración del pool de conexiones para calcular el número óptimo de conexiones en función de las consultas por segundo (QPS) máximas y la latencia media de las solicitudes de tu aplicación.

Síntoma 2: Tiempos de espera agotados o errores de RPC intermitentes

A veces, la aplicación funciona correctamente la mayor parte del tiempo, pero ocasionalmente sufre tiempos de espera intermitentes o errores de RPC, incluso durante periodos de tráfico normal.

Causa posible: inestabilidad de la red

Se están interrumpiendo las conexiones entre el cliente y el servicio Datastore. El cliente de gRPC intentará volver a conectarse automáticamente, pero este proceso puede provocar errores temporales y latencia.

Registros que debes buscar

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

  • Registro de errores transitorios:
[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 ha perdido la conexión. Un fallo aislado podría ser solo un pequeño problema de la red. Sin embargo, si vemos estos mensajes con frecuencia o un canal se queda bloqueado en este estado, significa que hay un problema subyacente importante.

Cómo solucionarlo

Investiga tu entorno de red. Comprueba si hay problemas con cortafuegos, 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 concreto se aplica a las aplicaciones que se ejecutan a una escala muy alta, normalmente cuando una sola instancia de cliente debe gestionar más de 20.000 solicitudes simultáneas. La aplicación funciona bien en condiciones normales, pero,cuando el tráfico aumenta a más de 20.000 solicitudes simultáneas por cliente, se observa una degradación brusca y repentina del rendimiento. La latencia aumenta significativamente y se mantiene alta durante todo el periodo de tráfico máximo. Esto ocurre porque el grupo de conexiones del cliente ha alcanzado su tamaño máximo y no puede ampliarse más.

Causa posible

El cliente sufre una saturación de canales porque el grupo de canales ha alcanzado el maxChannelCount configurado. De forma predeterminada, el grupo se configura con un límite de 200 canales. Como cada canal gRPC puede gestionar hasta 100 solicitudes simultáneas, este límite solo se alcanza cuando una sola instancia de cliente procesa aproximadamente 20.000 solicitudes simultáneamente.

Una vez que el grupo alcance este límite, no podrá crear más conexiones. Los 200 canales se sobrecargan y las nuevas solicitudes se ponen en cola en el lado del cliente, lo que provoca un fuerte aumento de la latencia.

Los siguientes registros pueden ayudarte a confirmar que se ha contactado con maxChannelCount.

Registros que debes buscar

El indicador clave es observar que el grupo de canales deja de ampliarse justo en el límite configurado, aunque la carga continúe.

  • Registros: verás los registros anteriores de la ampliación del grupo. Con la configuración predeterminada, el último registro de expansión que verás antes de que se produzcan 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 periodo de latencia alta, no verás más registros de "aumento del tamaño del grupo de canales". La ausencia de estos registros, combinada con la alta latencia, es un indicador claro de que se ha alcanzado el límite de maxChannelCount.

Cómo solucionarlo

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

  • Aumentar maxChannelCount: la solución principal es aumentar el valor de maxChannelCount a un valor que pueda admitir el pico de tráfico de la aplicación. Consulta la guía de configuración del pool de conexiones para calcular el número óptimo de conexiones en función del pico de consultas por segundo (QPS) y la latencia media de las solicitudes de la aplicación.

Apéndice

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

Información sobre los estados de los canales

En los registros pueden aparecer los siguientes estados de los canales, que proporcionan información valiosa sobre el comportamiento de las conexiones:

Estado Descripción
IDLE El canal se crea, pero no tiene conexiones ni RPCs activas. Está esperando el tráfico.
CONECTANDO El canal está intentando establecer un nuevo transporte de red (conexión) con el servidor gRPC.
PREPARADOS El canal tiene un transporte establecido y correcto, y está listo para enviar RPCs.
TRANSIENT_FAILURE El canal ha detectado un fallo recuperable (por ejemplo, un problema de red o que el servidor no esté disponible temporalmente). Intentará volver a conectarse automáticamente.
SHUTDOWN El canal se ha cerrado, ya sea manualmente (por ejemplo, shutdown() llamada) o debido a un tiempo de espera por inactividad. No se pueden iniciar nuevas llamadas a procedimientos remotos.

Consejos

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