Fluentd: por qué es importante ajustar el búfer de salida

Fluentd: por qué es importante ajustar el búfer de salida

Hoy en día, es imposible imaginar un proyecto basado en Kubernetes sin una pila ELK, con la ayuda de la cual se almacenan los registros de las aplicaciones y los componentes del sistema del clúster. En nuestra práctica, usamos la pila EFK con Fluentd en lugar de Logstash.

Fluentd es un recolector de registros moderno y de uso general que está ganando cada vez más popularidad y se ha unido a Cloud Native Computing Foundation, por lo que su vector de desarrollo se centra en el uso con Kubernetes.

El hecho de usar Fluentd en lugar de Logstash no cambia la esencia general del paquete de software, sin embargo, Fluentd tiene sus propios matices específicos derivados de su versatilidad.

Por ejemplo, cuando comenzamos a usar EFK en un proyecto ocupado con una alta intensidad de registro, nos enfrentamos al hecho de que en Kibana algunos mensajes se muestran repetidamente varias veces. En este artículo, le diremos por qué ocurre este fenómeno y cómo resolver el problema.

El problema de la duplicación de documentos

En nuestros proyectos, Fluentd se implementa como un DaemonSet (se ejecuta automáticamente en una instancia en cada nodo del clúster de Kubernetes) y monitorea los registros de salida estándar del contenedor en /var/log/containers. Después de la recopilación y el procesamiento, los registros en forma de documentos JSON se envían a ElasticSearch, generados en forma de clúster o independiente, según la escala del proyecto y los requisitos de rendimiento y tolerancia a fallas. Kibana se utiliza como interfaz gráfica.

Al usar Fluentd con un complemento de almacenamiento en búfer de salida, nos encontramos con una situación en la que algunos documentos en ElasticSearch tienen exactamente el mismo contenido y difieren solo en la ID. Puede asegurarse de que se trata de una repetición del mensaje utilizando el ejemplo del registro de Nginx. En el archivo de registro, este mensaje existe en una sola instancia:

127.0.0.1 192.168.0.1 - [28/Feb/2013:12:00:00 +0900] "GET / HTTP/1.1" 200 777 "-" "Opera/12.0" -

Sin embargo, hay varios documentos en ElasticSearch que contienen este mensaje:

{
  "_index": "test-custom-prod-example-2020.01.02",
  "_type": "_doc",
  "_id": "HgGl_nIBR8C-2_33RlQV",
  "_version": 1,
  "_score": 0,
  "_source": {
    "service": "test-custom-prod-example",
    "container_name": "nginx",
    "namespace": "test-prod",
    "@timestamp": "2020-01-14T05:29:47.599052886 00:00",
    "log": "127.0.0.1 192.168.0.1 - [28/Feb/2013:12:00:00  0900] "GET / HTTP/1.1" 200 777 "-" "Opera/12.0" -",
    "tag": "custom-log"
  }
}

{
  "_index": "test-custom-prod-example-2020.01.02",
  "_type": "_doc",
  "_id": "IgGm_nIBR8C-2_33e2ST",
  "_version": 1,
  "_score": 0,
  "_source": {
    "service": "test-custom-prod-example",
    "container_name": "nginx",
    "namespace": "test-prod",
    "@timestamp": "2020-01-14T05:29:47.599052886 00:00",
    "log": "127.0.0.1 192.168.0.1 - [28/Feb/2013:12:00:00  0900] "GET / HTTP/1.1" 200 777 "-" "Opera/12.0" -",
    "tag": "custom-log"
  }
}

Además, puede haber más de dos repeticiones.

Durante la solución de este problema, se puede observar una gran cantidad de advertencias en los registros de Fluentd del siguiente contenido:

2020-01-16 01:46:46 +0000 [warn]: [test-prod] failed to flush the buffer. retry_time=4 next_retry_seconds=2020-01-16 01:46:53 +0000 chunk="59c37fc3fb320608692c352802b973ce" error_class=Fluent::Plugin::ElasticsearchOutput::RecoverableRequestFailure error="could not push logs to Elasticsearch cluster ({:host=>"elasticsearch", :port=>9200, :scheme=>"http", :user=>"elastic", :password=>"obfuscated"}): read timeout reached"

Estas advertencias ocurren cuando ElasticSearch no puede devolver una respuesta a una solicitud dentro del tiempo establecido por el parámetro request_timeout, por lo que el fragmento de búfer reenviado no se puede borrar. Después de eso, Fluentd intenta enviar de nuevo el fragmento de búfer a ElasticSearch y, después de un número arbitrario de reintentos, la operación tiene éxito:

2020-01-16 01:47:05 +0000 [warn]: [test-prod] retry succeeded. chunk_id="59c37fc3fb320608692c352802b973ce" 
2020-01-16 01:47:05 +0000 [warn]: [test-prod] retry succeeded. chunk_id="59c37fad241ab300518b936e27200747" 
2020-01-16 01:47:05 +0000 [warn]: [test-dev] retry succeeded. chunk_id="59c37fc11f7ab707ca5de72a88321cc2" 
2020-01-16 01:47:05 +0000 [warn]: [test-dev] retry succeeded. chunk_id="59c37fb5adb70c06e649d8c108318c9b" 
2020-01-16 01:47:15 +0000 [warn]: [kube-system] retry succeeded. chunk_id="59c37f63a9046e6dff7e9987729be66f"

Sin embargo, ElasticSearch trata cada uno de los fragmentos de búfer reenviados como únicos y les asigna valores de campo _id únicos al indexar. Así, aparecen copias de los mensajes.

En Kibana se ve así:

Fluentd: por qué es importante ajustar el búfer de salida

La solución

Hay varias soluciones a este problema. Uno de ellos es el mecanismo integrado en el complemento fluent-plugin-elasticsearch para generar un hash único para cada documento. Si usa este mecanismo, ElasticSearch reconocerá los duplicados en la etapa de reenvío y evitará los documentos duplicados. Pero no se puede ignorar que este método de resolución del problema combate la investigación y no elimina el error por falta de tiempo de espera, por lo que abandonamos su uso.

Usamos un complemento de almacenamiento en búfer en la salida de Fluentd para evitar la pérdida de registros en caso de interrupciones breves de la red o un aumento del registro. Si, por alguna razón, ElasticSearch no puede escribir inmediatamente el documento en el índice, el documento se coloca en una cola que se almacena en el disco. Por lo tanto, en nuestro caso, para eliminar la fuente del problema que conduce al error descrito anteriormente, es necesario establecer los valores correctos de los parámetros de almacenamiento en búfer, en los que el búfer de salida de Fluentd será suficiente. tamaño y al mismo tiempo tener tiempo para despejar en el tiempo asignado.

Cabe señalar que los valores de los parámetros, que se discutirán a continuación, son individuales en cada caso específico de uso de almacenamiento en búfer en complementos de salida, ya que dependen de muchos factores: la intensidad de registro de mensajes por servicios, el rendimiento de el sistema de disco, la carga del canal de red y su ancho de banda. Por lo tanto, con el fin de obtener la configuración de búfer adecuada para cada caso individual, pero no redundante, evitando una búsqueda ciega prolongada, puede usar la información de depuración que Fluentd escribe en su registro durante la operación y obtener los valores correctos con relativa rapidez.

En el momento de solucionar el problema, la configuración se veía así:

 <buffer>
        @type file
        path /var/log/fluentd-buffers/kubernetes.test.buffer
        flush_mode interval
        retry_type exponential_backoff
        flush_thread_count 2
        flush_interval 5s
        retry_forever
        retry_max_interval 30
        chunk_limit_size 8M
        queue_limit_length 8
        overflow_action block
      </buffer>

En el curso de la resolución del problema, los valores de los siguientes parámetros se seleccionaron manualmente:
chunk_limit_size: el tamaño de los fragmentos en los que se dividen los mensajes en el búfer.

  • flush_interval: el intervalo de tiempo después del cual se borra el búfer.
  • queue_limit_length: el número máximo de fragmentos en la cola.
  • request_timeout es el tiempo durante el cual se establece una conexión entre Fluentd y ElasticSearch.

El tamaño total del búfer se puede calcular multiplicando los parámetros queue_limit_length y chunk_limit_size, que se pueden interpretar como "el número máximo de fragmentos en la cola, cada uno de los cuales tiene un tamaño determinado". Si el tamaño del búfer es insuficiente, aparecerá la siguiente advertencia en los registros:

2020-01-21 10:22:57 +0000 [warn]: [test-prod] failed to write data into buffer by buffer overflow action=:block

Significa que el búfer no tiene tiempo para borrarse en el tiempo asignado y los datos que ingresan al búfer completo están bloqueados, lo que conducirá a la pérdida de parte de los registros.

Puede aumentar el búfer de dos maneras: aumentando el tamaño de cada fragmento en la cola o aumentando la cantidad de fragmentos que pueden estar en la cola.

Si establece el tamaño del fragmento chunk_limit_size en más de 32 megabytes, ElasticSeacrh no lo aceptará, ya que el paquete entrante será demasiado grande. Por lo tanto, si necesita aumentar aún más el búfer, es mejor aumentar la longitud máxima de queue_limit_length.

Cuando el búfer deja de desbordarse y solo queda el mensaje sobre la falta de tiempo de espera, puede comenzar a aumentar el parámetro request_timeout. Sin embargo, configurarlo en más de 20 segundos hará que aparezcan las siguientes advertencias en los registros de Fluentd:

2020-01-21 09:55:33 +0000 [warn]: [test-dev] buffer flush took longer time than slow_flush_log_threshold: elapsed_time=20.85753920301795 slow_flush_log_threshold=20.0 plugin_id="postgresql-dev" 

Este mensaje no afecta al sistema de ninguna manera y significa que el tiempo para vaciar el búfer tomó más tiempo que el establecido por el parámetro slow_flush_log_threshold. Esta es información de depuración y la usamos cuando elegimos el valor del parámetro request_timeout.

El algoritmo de selección generalizado es el siguiente:

  1. Establezca el valor de request_timeout para garantizar que sea mayor de lo necesario (cientos de segundos). En el momento de la configuración, el criterio principal para la correcta configuración de este parámetro será la desaparición de los avisos por falta de tiempo de espera.
  2. Espere los mensajes sobre la superación del umbral de slow_flush_log_threshold. En el texto de la advertencia, el campo elapsed_time contendrá el tiempo real de limpieza del búfer.
  3. Establezca el valor de request_timeout para que sea mayor que el valor máximo de tiempo transcurrido recibido durante el período de supervisión. Calculamos el valor de request_timeout como elapsed_time + 50%.
  4. Para eliminar las advertencias sobre un vaciado de búfer largo del registro, puede aumentar el valor de slow_flush_log_threshold. Calculamos este valor como elapsed_time + 25%.

Los valores finales de estos parámetros, como se señaló anteriormente, se obtienen individualmente para cada caso. Siguiendo el algoritmo anterior, tenemos la garantía de eliminar el error que conduce a mensajes repetidos.

La siguiente tabla muestra cómo la cantidad de errores por día, que conducen a mensajes duplicados, cambia en el proceso de selección de los valores de los parámetros descritos anteriormente:

nodo-1
nodo-2
nodo-3
nodo-4

Antes después
Antes después
Antes después
Antes después

no se pudo vaciar el búfer
1749/2
694/2
47/0
1121/2

reintentar con éxito
410/2
205/1
24/0
241/2

Además, se debe tener en cuenta que las configuraciones recibidas pueden perder su relevancia en el proceso de crecimiento del proyecto y, en consecuencia, un aumento en la cantidad de registros. La indicación principal de que no se está configurando un tiempo de espera es la devolución de mensajes largos de vaciado de búfer al registro de Fluentd, es decir, se ha excedido el umbral de slow_flush_log_threshold. A partir de este punto, todavía hay un pequeño margen antes de que se exceda el parámetro request_timeout, por lo que es necesario responder a estos mensajes de manera oportuna y repetir el proceso de selección de la configuración óptima descrito anteriormente.

Conclusión

El ajuste fino del búfer de salida de Fluentd es uno de los pasos principales para ajustar la pila EFK, determinando la estabilidad de su funcionamiento y la ubicación correcta de los documentos en los índices. Centrándose en el algoritmo de configuración descrito, puede estar seguro de que todos los registros se escribirán en el índice de ElasticSearch en el orden correcto, sin repeticiones ni pérdidas.

Lea también otros artículos en nuestro blog:

Fuente: habr.com

Añadir un comentario