V dnešnej dobe si už nie je možné predstaviť projekt založený na Kubernetes bez ELK stacku, ktorý ukladá logy aplikácií aj systémových komponentov klastra. V našej praxi používame EFK stack s Fluentd namiesto Logstash.
Fluentd je moderný univerzálny zberač logov, ktorý si získava čoraz väčšiu obľubu a pripojil sa k Cloud Native Computing Foundation, a preto je jeho vývojový vektor zameraný na použitie v spojení s Kubernetes.
Skutočnosť, že namiesto Logstashe sa používa Fluentd, nemení všeobecnú podstatu softvérového balíka, avšak Fluentd sa vyznačuje svojimi špecifickými nuansami vyplývajúcimi z jeho všestrannosti.
Keď sme napríklad začali používať EFK v nabitom projekte s vysokou intenzitou logovania, stretli sme sa s tým, že v Kibane sa niektoré správy zobrazovali opakovane aj niekoľkokrát. V tomto článku vám povieme, prečo k tomuto javu dochádza a ako problém vyriešiť.
Problém duplikácie dokumentov
V našich projektoch je Fluentd nasadený ako DaemonSet (automaticky spúšťaný v jednej inštancii na každom uzle klastra Kubernetes) a monitoruje protokoly kontajnerov stdout v /var/log/containers. Po zbere a spracovaní sa protokoly vo forme dokumentov JSON odošlú do ElasticSearch, vytvoria sa v klastrovej alebo samostatnej forme, v závislosti od rozsahu projektu a požiadaviek na výkon a odolnosť voči chybám. Ako grafické rozhranie sa používa Kibana.
Pri používaní Fluentdu s pluginom na vyrovnávanie výstupov sme sa stretli so situáciou, keď niektoré dokumenty v ElasticSearch mali úplne rovnaký obsah a líšili sa len identifikátorom. Pomocou denníka Nginx ako príkladu si môžete overiť, že ide o opakovanie správy. V protokolovom súbore existuje táto správa v jedinej kópii:
127.0.0.1 192.168.0.1 - [28/Feb/2013:12:00:00 +0900] "GET / HTTP/1.1" 200 777 "-" "Opera/12.0" -V ElasticSearch však existuje niekoľko dokumentov, ktoré obsahujú túto správu:
{
"_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"
}
}Okrem toho môžu byť opakovania viac ako dve.
Pri odstraňovaní tohto problému v protokoloch Fluentd môžete vidieť veľké množstvo upozornení s nasledujúcim obsahom:
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"Tieto varovania sa vyskytujú, keď ElasticSearch nemôže vrátiť odpoveď na požiadavku v rámci času určeného parametrom request_timeout, čo je dôvod, prečo nie je možné vymazať preposlaný fragment vyrovnávacej pamäte. Potom sa Fluentd pokúsi znova odoslať fragment vyrovnávacej pamäte do ElasticSearch a po ľubovoľnom počte pokusov sa operácia úspešne dokončí:
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 však považuje každý z prenesených fragmentov vyrovnávacej pamäte za jedinečný a počas indexovania im priraďuje jedinečné hodnoty poľa _id. Takto sa zobrazujú kópie správ.
V Kibane to vyzerá takto:
Riešenie
Existuje niekoľko možností, ako tento problém vyriešiť. Jedným z nich je mechanizmus zabudovaný do doplnku fluent-plugin-elasticsearch na generovanie jedinečného hashu pre každý dokument. Ak použijete tento mechanizmus, ElasticSearch rozpozná opakovania vo fáze preposielania a zabráni duplicitným dokumentom. Musíme však vziať do úvahy, že tento spôsob riešenia problému zápasí s vyšetrovaním a neodstraňuje chybu s nedostatkom timeoutu, preto sme od jeho používania upustili.
Na výstupe Fluentd používame plugin na vyrovnávanie pamäte, aby sme zabránili strate protokolu v prípade krátkodobých problémov so sieťou alebo zvýšenej intenzity protokolovania. Ak z nejakého dôvodu ElasticSearch nedokáže okamžite zapísať dokument do indexu, dokument sa zaradí do frontu a uloží sa na disk. Preto je v našom prípade potrebné na odstránenie zdroja problému, ktorý vedie k vyššie opísanej chybe, nastaviť správne hodnoty parametrov vyrovnávacej pamäte, pri ktorých bude mať výstupná vyrovnávacia pamäť Fluentd dostatočnú veľkosť a zároveň stihnúť vyčistiť v určenom čase.
Stojí za zmienku, že hodnoty parametrov diskutovaných nižšie sú individuálne v každom konkrétnom prípade použitia vyrovnávacej pamäte vo výstupných zásuvných moduloch, pretože závisia od mnohých faktorov: intenzita zapisovania správ do denníka podľa služieb, výkon diskového systému, sieť. zaťaženie kanála a jeho šírka pásma. Preto, aby ste získali nastavenia vyrovnávacej pamäte, ktoré sú vhodné pre každý jednotlivý prípad, ale nie sú nadbytočné, čím sa vyhnete zdĺhavému hľadaniu naslepo, môžete použiť informácie o ladení, ktoré si Fluentd počas prevádzky zapisuje do svojho denníka a pomerne rýchlo získať správne hodnoty.
V čase zaznamenania problému vyzerala konfigurácia takto:
<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>Pri riešení problému boli manuálne vybrané hodnoty nasledujúcich parametrov:
chunk_limit_size — veľkosť častí, na ktoré sú rozdelené správy vo vyrovnávacej pamäti.
- flush_interval — časový interval, po ktorom sa vyrovnávacia pamäť vymaže.
- queue_limit_length — maximálny počet blokov vo fronte.
- request_timeout je čas, na ktorý sa vytvorí spojenie medzi Fluentd a ElasticSearch.
Celková veľkosť vyrovnávacej pamäte sa dá vypočítať vynásobením parametrov queue_limit_length a chunk_limit_size, ktoré možno interpretovať ako „maximálny počet častí vo fronte, z ktorých každý má danú veľkosť“. Ak je veľkosť vyrovnávacej pamäte nedostatočná, v protokoloch sa zobrazí nasledujúce upozornenie:
2020-01-21 10:22:57 +0000 [warn]: [test-prod] failed to write data into buffer by buffer overflow action=:blockZnamená to, že vyrovnávacia pamäť sa nestihne vymazať v určenom čase a údaje, ktoré vstupujú do plnej vyrovnávacej pamäte, sú zablokované, čo povedie k strate časti protokolov.
Vyrovnávaciu pamäť môžete zväčšiť dvoma spôsobmi: buď zvýšením veľkosti každého bloku vo fronte, alebo zvýšením počtu blokov, ktoré môžu byť vo fronte.
Ak nastavíte veľkosť časti chunk_limit_size na viac ako 32 megabajtov, ElasticSeacrh to neprijme, pretože prichádzajúci paket bude príliš veľký. Preto, ak potrebujete ďalej zvýšiť vyrovnávaciu pamäť, je lepšie zvýšiť maximálnu dĺžku frontu queue_limit_length.
Keď sa vyrovnávacia pamäť prestane prepĺňať a zostane len hlásenie nedostatočný časový limit, môžete začať zvyšovať parameter request_timeout. Ak však nastavíte hodnotu na viac ako 20 sekúnd, v protokoloch Fluentd sa začnú objavovať nasledujúce upozornenia:
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" Táto správa žiadnym spôsobom neovplyvňuje činnosť systému a znamená, že čas vyprázdnenia vyrovnávacej pamäte trval dlhšie, ako je nastavené parametrom slow_flush_log_threshold. Ide o ladiace informácie a používame ich pri výbere hodnoty parametra request_timeout.
Algoritmus všeobecného výberu je nasledujúci:
- Nastavte request_timeout na hodnotu, ktorá bude zaručene väčšia, než je potrebné (stovky sekúnd). Počas nastavovania bude hlavným kritériom pre správne nastavenie tohto parametra zmiznutie upozornení na nedostatok časového limitu.
- Počkajte na správy o prekročení limitu slow_flush_log_threshold. Varovný text v poli elapsed_time zobrazí skutočný čas vymazania vyrovnávacej pamäte.
- Nastavte request_timeout na hodnotu väčšiu ako maximálna hodnota elapsed_time získaná počas obdobia pozorovania. Hodnotu request_timeout vypočítame ako elapsed_time + 50 %.
- Ak chcete z protokolu odstrániť varovania o dlhých vyprázdneniach vyrovnávacej pamäte, môžete zvýšiť hodnotu slow_flush_log_threshold. Túto hodnotu vypočítame ako elapsed_time + 25 %.
Konečné hodnoty týchto parametrov, ako bolo uvedené vyššie, sa získavajú individuálne pre každý prípad. Dodržaním vyššie uvedeného algoritmu zaručene odstránime chybu, ktorá vedie k opakovaným správam.
Nižšie uvedená tabuľka ukazuje, ako sa počet chýb za deň, ktoré vedú k duplikácii správ, mení v procese výberu hodnôt parametrov opísaných vyššie:
uzol-1
uzol-2
uzol-3
uzol-4
Predtým potom
Predtým potom
Predtým potom
Predtým potom
nepodarilo sa prepláchnuť vyrovnávaciu pamäť
1749/2
694/2
47/0
1121/2
opätovný pokus bol úspešný
410/2
205/1
24/0
241/2
Okrem toho je potrebné poznamenať, že výsledné nastavenia môžu stratiť svoj význam, keď projekt rastie, a preto sa zvyšuje počet protokolov. Primárnym znakom nedostatočného časového limitu je návrat správ o dlhom vyprázdnení vyrovnávacej pamäte do protokolu Fluentd, teda prekročení prahu slow_flush_log_threshold. Od tohto momentu je ešte malá rezerva pred prekročením parametra request_timeout, preto je potrebné na tieto správy včas reagovať a zopakovať vyššie popísaný proces výberu optimálnych nastavení.
Záver
Jemné doladenie výstupnej vyrovnávacej pamäte Fluentd je jednou z hlavných fáz konfigurácie zásobníka EFK, určenia stability jeho prevádzky a správneho umiestnenia dokumentov v indexoch. Na základe opísaného konfiguračného algoritmu si môžete byť istí, že všetky protokoly budú zapísané do indexu ElasticSearch v správnom poradí, bez opakovaní alebo strát.
Prečítajte si aj ďalšie články na našom blogu:
Zdroj: hab.com