Fluentd: Per què és important configurar el buffer de sortida

Fluentd: Per què és important configurar el buffer de sortida

Avui en dia, és impossible imaginar un projecte basat en Kubernetes sense la pila ELK, que desa els registres tant de les aplicacions com dels components del sistema del clúster. A la nostra pràctica, utilitzem la pila EFK amb Fluentd en comptes de Logstash.

Fluentd és un col·lector de registres modern i universal que està guanyant cada cop més popularitat i s'ha unit a la Cloud Native Computing Foundation, per això el seu vector de desenvolupament se centra en l'ús conjuntament amb Kubernetes.

El fet d'utilitzar Fluentd en comptes de Logstash no canvia l'essència general del paquet de programari, però, Fluentd es caracteritza pels seus propis matisos específics derivats de la seva versatilitat.

Per exemple, quan vam començar a utilitzar EFK en un projecte ocupat amb una alta intensitat de registre, ens vam trobar amb el fet que a Kibana alguns missatges es mostraven repetidament diverses vegades. En aquest article us explicarem per què es produeix aquest fenomen i com resoldre el problema.

El problema de la duplicació de documents

En els nostres projectes, Fluentd es desplega com a DaemonSet (llançat automàticament en una instància a cada node del clúster Kubernetes) i supervisa els registres de contenidors stdout a /var/log/containers. Després de la recollida i el processament, els registres en forma de documents JSON s'envien a ElasticSearch, generats en clúster o en forma independent, depenent de l'escala del projecte i dels requisits de rendiment i tolerància a errors. Kibana s'utilitza com a interfície gràfica.

Quan s'utilitzava Fluentd amb un connector de memòria intermèdia de sortida, ens vam trobar amb una situació en què alguns documents a ElasticSearch tenien exactament el mateix contingut i només es diferenciaven en l'identificador. Podeu verificar que es tracta d'una repetició de missatges utilitzant el registre de Nginx com a exemple. Al fitxer de registre, aquest missatge existeix en una única còpia:

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

Tanmateix, hi ha diversos documents a ElasticSearch que contenen aquest missatge:

{
  "_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"
  }
}

A més, hi pot haver més de dues repeticions.

Mentre solucioneu aquest problema als registres de Fluentd, podeu veure un gran nombre d'avisos amb el contingut següent:

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"

Aquests avisos es produeixen quan ElasticSearch no pot retornar una resposta a una sol·licitud dins del temps especificat pel paràmetre request_timeout, motiu pel qual el fragment de memòria intermèdia reenviat no es pot esborrar. Després d'això, Fluentd intenta tornar a enviar el fragment de memòria intermèdia a ElasticSearch i després d'un nombre arbitrari d'intents, l'operació es completa correctament:

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"

Tanmateix, ElasticSearch tracta cadascun dels fragments de memòria intermèdia transferits com a únics i els assigna valors de camp _id únics durant la indexació. Així apareixen les còpies dels missatges.

A Kibana es veu així:

Fluentd: Per què és important configurar el buffer de sortida

La solució

Hi ha diverses opcions per resoldre aquest problema. Un d'ells és el mecanisme integrat al connector fluent-plugin-elasticsearch per generar un hash únic per a cada document. Si utilitzeu aquest mecanisme, ElasticSearch reconeixerà les repeticions en l'etapa de reenviament i evitarà la duplicació de documents. Però hem de tenir en compte que aquest mètode de resolució del problema lluita amb la investigació i no elimina l'error amb la manca de temps d'espera, per la qual cosa vam abandonar el seu ús.

Utilitzem un connector de memòria intermèdia a la sortida de Fluentd per evitar la pèrdua de registre en cas de problemes de xarxa a curt termini o d'augment de la intensitat de registre. Si per algun motiu ElasticSearch no pot escriure un document a l'índex de manera instantània, el document es posa a la cua i s'emmagatzema al disc. Per tant, en el nostre cas, per eliminar l'origen del problema que condueix a l'error descrit anteriorment, cal establir els valors correctes per als paràmetres de memòria intermèdia, en què la memòria intermèdia de sortida Fluentd serà de mida suficient i al mateix temps aconsegueixen ser netejats en el temps assignat.

Val la pena assenyalar que els valors dels paràmetres que es comenten a continuació són individuals en cada cas concret d'ús de la memòria intermèdia en els connectors de sortida, ja que depenen de molts factors: la intensitat d'escriptura de missatges al registre per serveis, el rendiment del sistema de disc, la xarxa. càrrega del canal i el seu ample de banda. Per tant, per obtenir una configuració de memòria intermèdia adequada per a cada cas individual, però no redundant, evitant cerques llargues a cegues, podeu utilitzar la informació de depuració que Fluentd escriu al seu registre durant el funcionament i obtenir els valors correctes amb relativa rapidesa.

En el moment en què es va registrar el problema, la configuració era així:

 <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 resoldre el problema, es van seleccionar manualment els valors dels paràmetres següents:
chunk_limit_size — la mida dels trossos en què es divideixen els missatges de la memòria intermèdia.

  • flush_interval — interval de temps després del qual s'esborra la memòria intermèdia.
  • queue_limit_length — el nombre màxim de fragments a la cua.
  • request_timeout és el temps durant el qual s'estableix la connexió entre Fluentd i ElasticSearch.

La mida total del buffer es pot calcular multiplicant els paràmetres queue_limit_length i chunk_limit_size, que es poden interpretar com "el nombre màxim de trossos a la cua, cadascun dels quals té una mida determinada". Si la mida de la memòria intermèdia és insuficient, apareixerà l'advertència següent als registres:

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

Vol dir que el buffer no té temps d'esborrar en el temps assignat i les dades que entren al buffer complet estan bloquejades, la qual cosa comportarà la pèrdua d'una part dels registres.

Podeu augmentar la memòria intermèdia de dues maneres: augmentant la mida de cada tros de la cua o el nombre de trossos que hi poden haver.

Si configureu la mida del fragment chunk_limit_size a més de 32 megabytes, ElasticSeacrh no l'acceptarà, ja que el paquet entrant serà massa gran. Per tant, si necessiteu augmentar encara més la memòria intermèdia, és millor augmentar la longitud màxima de la cua queue_limit_length.

Quan la memòria intermèdia deixi de desbordar-se i només queda el missatge de temps d'espera insuficient, podeu començar a augmentar el paràmetre request_timeout. Tanmateix, si configureu el valor en més de 20 segons, els advertiments següents començaran a aparèixer als registres 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" 

Aquest missatge no afecta de cap manera el funcionament del sistema i significa que el temps d'aprofitament de la memòria intermèdia va trigar més del que ha establert el paràmetre slow_flush_log_threshold. Aquesta és informació de depuració i la fem servir quan escollim el valor del paràmetre request_timeout.

L'algorisme de selecció generalitzat és el següent:

  1. Estableix request_timeout en un valor garantit que serà superior al necessari (centers de segons). Durant la configuració, el criteri principal per a la configuració correcta d'aquest paràmetre serà la desaparició dels avisos per falta de temps d'espera.
  2. Espereu missatges sobre la superació del llindar slow_flush_log_threshold. El text d'advertència al camp elapsed_time mostrarà el temps real en què s'ha esborrat la memòria intermèdia.
  3. Estableix request_timeout en un valor superior al valor màxim elapsed_time obtingut durant el període d'observació. Calculem el valor request_timeout com a elapsed_time + 50%.
  4. Per eliminar els avisos sobre buffers llargs del registre, podeu augmentar el valor de slow_flush_log_threshold. Calculem aquest valor com a elapsed_time + 25%.

Els valors finals d'aquests paràmetres, com s'ha assenyalat anteriorment, s'obtenen individualment per a cada cas. Seguint l'algorisme anterior, tenim la garantia d'eliminar l'error que condueix a missatges repetits.

La taula següent mostra com el nombre d'errors per dia, que condueix a la duplicació de missatges, canvia en el procés de selecció dels valors dels paràmetres descrits anteriorment:

node-1
node-2
node-3
node-4

Abans després
Abans després
Abans després
Abans després

no s'ha pogut esborrar la memòria intermèdia
1749/2
694/2
47/0
1121/2

torna a intentar-ho
410/2
205/1
24/0
241/2

A més, val la pena assenyalar que la configuració resultant pot perdre la seva rellevància a mesura que el projecte creix i, en conseqüència, augmenta el nombre de registres. El signe principal de temps d'espera insuficient és el retorn de missatges sobre un buffer llarg al registre de Fluentd, és a dir, que superen el llindar slow_flush_log_threshold. A partir d'aquest moment, encara queda un petit marge abans de superar el paràmetre request_timeout, per la qual cosa cal respondre a aquests missatges de manera oportuna i repetir el procés de selecció de la configuració òptima descrita anteriorment.

Conclusió

L'ajustament del buffer de sortida Fluentd és una de les etapes principals de la configuració de la pila EFK, determinant l'estabilitat del seu funcionament i la correcta col·locació dels documents als índexs. D'acord amb l'algorisme de configuració descrit, podeu estar segur que tots els registres s'escriuran a l'índex ElasticSearch en l'ordre correcte, sense repeticions ni pèrdues.

Llegiu també altres articles al nostre blog:

Font: www.habr.com

Afegeix comentari