I dag er det umuligt at forestille sig et Kubernetes-baseret projekt uden ELK-stakken, som gemmer logfiler af både applikationer og systemkomponenter i klyngen. I vores praksis bruger vi EFK-stakken med Fluentd i stedet for Logstash.
Fluentd er en moderne, universel log-samler, der vinder mere og mere popularitet og har tilsluttet sig Cloud Native Computing Foundation, hvorfor dens udviklingsvektor er fokuseret på brug i forbindelse med Kubernetes.
Det faktum at bruge Fluentd i stedet for Logstash ændrer ikke den generelle essens af softwarepakken, men Fluentd er karakteriseret ved sine egne specifikke nuancer som følge af dens alsidighed.
For eksempel, da vi begyndte at bruge EFK i et travlt projekt med høj logningsintensitet, stod vi over for, at der i Kibana blev vist nogle beskeder gentagne gange flere gange. I denne artikel vil vi fortælle dig, hvorfor dette fænomen opstår, og hvordan du løser problemet.
Problemet med duplikering af dokumenter
I vores projekter er Fluentd implementeret som et DaemonSet (startes automatisk i én instans på hver node i Kubernetes-klyngen) og overvåger stdout-beholderlogfiler i /var/log/containers. Efter indsamling og behandling sendes loggene i form af JSON-dokumenter til ElasticSearch, rejst i klynge eller selvstændig form, afhængigt af projektets omfang og kravene til ydeevne og fejltolerance. Kibana bruges som den grafiske grænseflade.
Da vi brugte Fluentd med et outputbufferplugin, stødte vi på en situation, hvor nogle dokumenter i ElasticSearch havde nøjagtig det samme indhold og kun adskilte sig i identifikatoren. Du kan bekræfte, at dette er en beskedgentagelse ved at bruge Nginx-loggen som eksempel. I logfilen findes denne meddelelse i en enkelt kopi:
127.0.0.1 192.168.0.1 - [28/Feb/2013:12:00:00 +0900] "GET / HTTP/1.1" 200 777 "-" "Opera/12.0" -Der er dog flere dokumenter i ElasticSearch, der indeholder denne besked:
{
"_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"
}
}Desuden kan der være mere end to gentagelser.
Mens du løser dette problem i Fluentd-logfilerne, kan du se et stort antal advarsler med følgende indhold:
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"Disse advarsler opstår, når ElasticSearch ikke kan returnere et svar på en anmodning inden for den tid, der er angivet af parameteren request_timeout, hvorfor det videresendte bufferfragment ikke kan ryddes. Efter dette forsøger Fluentd at sende bufferfragmentet til ElasticSearch igen, og efter et vilkårligt antal forsøg fuldføres operationen med succes:
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 behandler dog hvert af de overførte bufferfragmenter som unikke og tildeler dem unikke _id-feltværdier under indeksering. Sådan vises kopier af beskeder.
I Kibana ser det sådan ud:
Løsning
Der er flere muligheder for at løse dette problem. En af dem er mekanismen indbygget i fluent-plugin-elasticsearch-plugin'et til at generere en unik hash for hvert dokument. Hvis du bruger denne mekanisme, vil ElasticSearch genkende gentagelser på videresendelsesstadiet og forhindre duplikerede dokumenter. Men vi skal tage højde for, at denne metode til at løse problemet kæmper med undersøgelsen og ikke eliminerer fejlen med manglende timeout, så vi opgav brugen af den.
Vi bruger et buffer-plugin på Fluentd-output for at forhindre logtab i tilfælde af kortvarige netværksproblemer eller øget logningsintensitet. Hvis ElasticSearch af en eller anden grund ikke er i stand til øjeblikkeligt at skrive et dokument til indekset, sættes dokumentet i kø og gemmes på disken. Derfor, i vores tilfælde, for at eliminere kilden til problemet, der fører til fejlen beskrevet ovenfor, er det nødvendigt at indstille de korrekte værdier for bufferparametrene, hvor Fluentd-outputbufferen vil være af tilstrækkelig størrelse og samtidig nå at blive ryddet i den afsatte tid.
Det er værd at bemærke, at værdierne af parametrene diskuteret nedenfor er individuelle i hvert enkelt tilfælde af brug af buffering i output-plugins, da de afhænger af mange faktorer: intensiteten af at skrive beskeder til loggen efter tjenester, disksystemydeevne, netværk kanalbelastning og dens båndbredde. For at opnå bufferindstillinger, der er egnede til hvert enkelt tilfælde, men ikke overflødige, og undgå lange søgninger blindt, kan du bruge de fejlfindingsoplysninger, som Fluentd skriver til sin log under drift, og relativt hurtigt få de korrekte værdier.
På det tidspunkt, hvor problemet blev registreret, så konfigurationen sådan ud:
<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>Ved løsning af problemet blev værdierne for følgende parametre valgt manuelt:
chunk_limit_size — størrelsen af de bidder, som meddelelser i bufferen er opdelt i.
- flush_interval — tidsinterval, hvorefter bufferen ryddes.
- queue_limit_length — det maksimale antal bidder i køen.
- request_timeout er den tid, hvor forbindelsen mellem Fluentd og ElasticSearch er etableret.
Den samlede bufferstørrelse kan beregnes ved at gange parametrene queue_limit_length og chunk_limit_size, hvilket kan fortolkes som "det maksimale antal bidder i køen, som hver har en given størrelse." Hvis bufferstørrelsen er utilstrækkelig, vises følgende advarsel i loggene:
2020-01-21 10:22:57 +0000 [warn]: [test-prod] failed to write data into buffer by buffer overflow action=:blockDet betyder, at bufferen ikke når at blive ryddet i den tildelte tid, og de data, der kommer ind i den fulde buffer, er blokeret, hvilket vil føre til tab af en del af logfilerne.
Du kan øge bufferen på to måder: ved at øge enten størrelsen af hver del i køen eller antallet af bidder, der kan være i køen.
Hvis du indstiller chunk size chunk_limit_size til mere end 32 megabyte, så vil ElasticSeacrh ikke acceptere det, da den indgående pakke vil være for stor. Derfor, hvis du har brug for at øge bufferen yderligere, er det bedre at øge den maksimale kølængde queue_limit_length.
Når bufferen holder op med at løbe over, og kun meddelelsen om timeout utilstrækkelig er tilbage, kan du begynde at øge parameteren request_timeout. Men hvis du indstiller værdien til mere end 20 sekunder, vil følgende advarsler begynde at blive vist i Fluentd-loggene:
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" Denne meddelelse påvirker ikke systemets drift på nogen måde og betyder, at bufferskylletiden tog længere tid end indstillet af parameteren slow_flush_log_threshold. Dette er fejlfindingsoplysninger, og vi bruger dem, når vi vælger værdien af parameteren request_timeout.
Den generaliserede udvælgelsesalgoritme er som følger:
- Indstil request_timeout til en værdi, der er garanteret større end nødvendigt (hundredevis af sekunder). Under opsætningen vil hovedkriteriet for den korrekte indstilling af denne parameter være forsvinden af advarsler på grund af manglende timeout.
- Vent på beskeder om overskridelse af slow_flush_log_threshold-tærsklen. Advarselsteksten i feltet elapsed_time vil vise den realtid, hvor bufferen blev ryddet.
- Indstil request_timeout til en værdi, der er større end den maksimale elapsed_time værdi opnået i observationsperioden. Vi beregner request_timeout værdien som elapsed_time + 50 %.
- For at fjerne advarsler om lange buffertømninger fra loggen, kan du hæve værdien af slow_flush_log_threshold. Vi beregner denne værdi som forløbet_tid + 25 %.
De endelige værdier af disse parametre, som nævnt tidligere, opnås individuelt for hvert tilfælde. Ved at følge ovenstående algoritme er vi garanteret at eliminere fejlen, der fører til gentagne beskeder.
Tabellen nedenfor viser, hvordan antallet af fejl pr. dag, der fører til duplikering af meddelelser, ændringer i processen med at vælge værdierne for de ovenfor beskrevne parametre:
node-1
node-2
node-3
node-4
Før efter
Før efter
Før efter
Før efter
undlod at skylle bufferen
1749/2
694/2
47/0
1121/2
forsøg igen lykkedes
410/2
205/1
24/0
241/2
Det er desuden værd at bemærke, at de resulterende indstillinger kan miste deres relevans, efterhånden som projektet vokser, og derfor stiger antallet af logfiler. Det primære tegn på utilstrækkelig timeout er returnering af meddelelser om en lang bufferflush til Fluentd-loggen, det vil sige overskridelse af slow_flush_log_threshold-tærsklen. Fra dette tidspunkt er der stadig en lille margin, før parameteren request_timeout overskrides, så det er nødvendigt at svare på disse meddelelser rettidigt og gentage processen med at vælge de optimale indstillinger beskrevet ovenfor.
Konklusion
Finjustering af Fluentd-outputbufferen er et af hovedstadierne i konfigurationen af EFK-stakken, der bestemmer stabiliteten af dens drift og den korrekte placering af dokumenter i indekser. Baseret på den beskrevne konfigurationsalgoritme kan du være sikker på, at alle logfiler bliver skrevet til ElasticSearch-indekset i den rigtige rækkefølge, uden gentagelser eller tab.
Læs også andre artikler på vores blog:
Kilde: www.habr.com