Tegenwoordig is het onmogelijk om een op Kubernetes gebaseerd project voor te stellen zonder de ELK-stack, die logs opslaat van zowel applicaties als systeemcomponenten van het cluster. In onze praktijk gebruiken we de EFK-stack met Fluentd in plaats van Logstash.
Fluentd is een moderne, universele logverzamelaar die steeds populairder wordt en zich heeft aangesloten bij de Cloud Native Computing Foundation. Daarom is de ontwikkelingsvector gericht op gebruik in combinatie met Kubernetes.
Het feit dat Fluentd wordt gebruikt in plaats van Logstash verandert niets aan de algemene essentie van het softwarepakket, maar Fluentd wordt gekenmerkt door zijn eigen specifieke nuances die voortvloeien uit zijn veelzijdigheid.
Toen we bijvoorbeeld EFK gingen gebruiken in een druk project met een hoge logintensiteit, werden we geconfronteerd met het feit dat in Kibana sommige berichten meerdere keren herhaaldelijk werden weergegeven. In dit artikel zullen we u vertellen waarom dit fenomeen optreedt en hoe u het probleem kunt oplossen.
Het probleem van het dupliceren van documenten
In onze projecten wordt Fluentd ingezet als een DaemonSet (automatisch in één instantie gelanceerd op elk knooppunt van het Kubernetes-cluster) en bewaakt het stdout-containerlogboeken in /var/log/containers. Na het verzamelen en verwerken worden de logs in de vorm van JSON-documenten naar ElasticSearch gestuurd, in cluster- of stand-alone vorm, afhankelijk van de schaal van het project en de eisen aan performance en fouttolerantie. Kibana wordt gebruikt als grafische interface.
Bij het gebruik van Fluentd met een plug-in voor uitvoerbuffer kwamen we een situatie tegen waarbij sommige documenten in ElasticSearch exact dezelfde inhoud hadden en alleen verschilden in de ID. U kunt verifiëren dat dit een berichtherhaling is door het Nginx-logboek als voorbeeld te gebruiken. In het logbestand staat dit bericht in één kopie:
127.0.0.1 192.168.0.1 - [28/Feb/2013:12:00:00 +0900] "GET / HTTP/1.1" 200 777 "-" "Opera/12.0" -Er zijn echter verschillende documenten in ElasticSearch die dit bericht bevatten:
{
"_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"
}
}Bovendien kunnen er meer dan twee herhalingen zijn.
Terwijl u dit probleem oplost in de Fluentd-logboeken, kunt u een groot aantal waarschuwingen zien met de volgende inhoud:
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"Deze waarschuwingen treden op wanneer ElasticSearch geen antwoord op een verzoek kan retourneren binnen de tijd die is opgegeven door de parameter request_timeout. Daarom kan het doorgestuurde bufferfragment niet worden gewist. Hierna probeert Fluentd het bufferfragment opnieuw naar ElasticSearch te sturen en na een willekeurig aantal pogingen wordt de bewerking met succes voltooid:
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"ElasticSearch behandelt elk van de overgedragen bufferfragmenten echter als uniek en wijst ze tijdens het indexeren unieke _id-veldwaarden toe. Dit is hoe kopieën van berichten verschijnen.
In Kibana ziet het er als volgt uit:
Probleemoplossend
Er zijn verschillende opties om dit probleem op te lossen. Eén daarvan is het mechanisme dat is ingebouwd in de vloeiende plug-in-elasticsearch-plug-in voor het genereren van een unieke hash voor elk document. Als u dit mechanisme gebruikt, herkent ElasticSearch herhalingen in de doorstuurfase en voorkomt dubbele documenten. Maar we moeten er rekening mee houden dat deze methode om het probleem op te lossen moeite heeft met het onderzoek en de fout niet elimineert met een gebrek aan time-out, dus hebben we het gebruik ervan opgegeven.
We gebruiken een bufferplug-in op de Fluentd-uitvoer om logverlies te voorkomen in het geval van kortetermijnnetwerkproblemen of verhoogde logintensiteit. Als ElasticSearch om de een of andere reden niet in staat is om onmiddellijk een document naar de index te schrijven, wordt het document in de wachtrij geplaatst en op schijf opgeslagen. Daarom is het in ons geval, om de bron van het probleem dat tot de hierboven beschreven fout leidt, te elimineren, noodzakelijk om de juiste waarden voor de bufferparameters in te stellen, waarbij de Fluentd-uitvoerbuffer voldoende groot zal zijn en tegelijkertijd erin slagen om binnen de toegewezen tijd te worden gewist.
Het is vermeldenswaard dat de waarden van de hieronder besproken parameters individueel zijn in elk specifiek geval van het gebruik van buffering in uitvoerplug-ins, omdat ze van veel factoren afhankelijk zijn: de intensiteit van het schrijven van berichten naar het logboek door services, schijfsysteemprestaties, netwerk kanaalbelasting en de bandbreedte ervan. Om bufferinstellingen te verkrijgen die geschikt zijn voor elk individueel geval, maar niet overbodig, en langdurig zoeken blindelings te vermijden, kunt u daarom de foutopsporingsinformatie gebruiken die Fluentd tijdens het gebruik naar zijn log schrijft en relatief snel de juiste waarden verkrijgen.
Op het moment dat het probleem werd geregistreerd, zag de configuratie er als volgt uit:
<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>Bij het oplossen van het probleem werden de waarden van de volgende parameters handmatig geselecteerd:
chunk_limit_size — de grootte van de chunks waarin berichten in de buffer zijn verdeeld.
- flush_interval — tijdsinterval waarna de buffer wordt leeggemaakt.
- wachtrij_limiet_lengte — het maximale aantal chunks in de wachtrij.
- request_timeout is de tijd waarvoor de verbinding tussen Fluentd en ElasticSearch tot stand is gebracht.
De totale buffergrootte kan worden berekend door de parameters wachtrij_limit_length en chunk_limit_size te vermenigvuldigen, wat kan worden geïnterpreteerd als “het maximale aantal chunks in de wachtrij, die elk een bepaalde grootte hebben.” Als de buffergrootte onvoldoende is, verschijnt de volgende waarschuwing in de logbestanden:
2020-01-21 10:22:57 +0000 [warn]: [test-prod] failed to write data into buffer by buffer overflow action=:blockHet betekent dat de buffer geen tijd heeft om binnen de toegewezen tijd te worden gewist en dat de gegevens die de volledige buffer binnenkomen, worden geblokkeerd, wat zal leiden tot het verlies van een deel van de logs.
Je kunt de buffer op twee manieren vergroten: door de grootte van elk blok in de wachtrij te vergroten, of door het aantal blokken dat in de wachtrij kan staan te vergroten.
Als u de chunkgrootte chunk_limit_size instelt op meer dan 32 megabytes, zal ElasticSeacrh dit niet accepteren, omdat het binnenkomende pakket te groot zal zijn. Als u de buffer verder moet vergroten, is het daarom beter om de maximale wachtrijlengte wachtrij_limiet_lengte te vergroten.
Wanneer de buffer niet meer overloopt en alleen het bericht 'time-out onvoldoende' overblijft, kunt u beginnen met het verhogen van de parameter request_timeout. Als u de waarde echter instelt op meer dan 20 seconden, verschijnen de volgende waarschuwingen in de Fluentd-logboeken:
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" Dit bericht heeft op geen enkele manier invloed op de werking van het systeem en betekent dat de bufferspoeltijd langer duurde dan ingesteld door de parameter slow_flush_log_threshold. Dit is foutopsporingsinformatie en we gebruiken deze bij het kiezen van de waarde van de parameter request_timeout.
Het gegeneraliseerde selectiealgoritme is als volgt:
- Stel request_timeout in op een waarde die gegarandeerd groter is dan nodig (honderden seconden). Tijdens de installatie is het belangrijkste criterium voor de juiste instelling van deze parameter het verdwijnen van waarschuwingen vanwege een gebrek aan time-out.
- Wacht op berichten over het overschrijden van de drempelwaarde slow_flush_log_threshold. De waarschuwingstekst in het veld elapsed_time geeft de realtime tijd weer waarop de buffer werd gewist.
- Stel request_timeout in op een waarde die groter is dan de maximale verstreken_tijdwaarde die is verkregen tijdens de observatieperiode. We berekenen de request_timeout-waarde als verstreken_tijd + 50%.
- Als u waarschuwingen over lange bufferopruimingen uit het logboek wilt verwijderen, kunt u de waarde van slow_flush_log_threshold verhogen. We berekenen deze waarde als verstreken_tijd + 25%.
De uiteindelijke waarden van deze parameters worden, zoals eerder opgemerkt, voor elk geval afzonderlijk verkregen. Door het bovenstaande algoritme te volgen, elimineren we gegarandeerd de fout die tot herhaalde berichten leidt.
De onderstaande tabel laat zien hoe het aantal fouten per dag, leidend tot dubbele berichten, verandert tijdens het selecteren van de waarden van de hierboven beschreven parameters:
knooppunt-1
knooppunt-2
knooppunt-3
knooppunt-4
Voor na
Voor na
Voor na
Voor na
Het is niet gelukt de buffer door te spoelen
1749/2
694/2
47/0
1121/2
nieuwe poging gelukt
410/2
205/1
24/0
241/2
Het is bovendien de moeite waard om op te merken dat de resulterende instellingen hun relevantie kunnen verliezen naarmate het project groeit en dienovereenkomstig het aantal logs toeneemt. Het belangrijkste teken van onvoldoende time-out is het terugkeren van berichten over een lange bufferflush naar het Fluentd-logboek, dat wil zeggen het overschrijden van de drempelwaarde slow_flush_log_threshold. Vanaf dit punt is er nog steeds een kleine marge voordat de parameter request_timeout wordt overschreden, dus het is noodzakelijk om tijdig op deze berichten te reageren en het hierboven beschreven proces van het selecteren van de optimale instellingen te herhalen.
Conclusie
Het verfijnen van de Fluentd-uitvoerbuffer is een van de belangrijkste fasen van het configureren van de EFK-stack, het bepalen van de stabiliteit van de werking ervan en de juiste plaatsing van documenten in indexen. Op basis van het beschreven configuratie-algoritme kunt u er zeker van zijn dat alle logs in de juiste volgorde naar de ElasticSearch-index worden geschreven, zonder herhalingen of verliezen.
Lees ook andere artikelen op onze blog:
Bron: www.habr.com