Ma már elképzelhetetlen egy Kubernetes-alapú projekt az ELK verem nélkül, amely mind az alkalmazások, mind a fürt rendszerelemeinek naplóit menti. Gyakorlatunkban a Logstash helyett az EFK stacket használjuk Fluentd-vel.
A Fluentd egy modern, univerzális naplógyűjtő, amely egyre nagyobb népszerűségnek örvend, és csatlakozott a Cloud Native Computing Foundation-hez, ezért fejlesztési vektora a Kubernetes-szel való együttműködésre összpontosít.
Az a tény, hogy Logstash helyett Fluentd-t használunk, nem változtat a szoftvercsomag általános lényegén, azonban a Fluentd-re a sokoldalúságából fakadó sajátos árnyalatok jellemzőek.
Például amikor elkezdtük használni az EFK-t egy forgalmas projektben, nagy intenzitású naplózással, szembesültünk azzal a ténnyel, hogy Kibanán néhány üzenet többször is megjelent. Ebben a cikkben elmondjuk, miért fordul elő ez a jelenség, és hogyan lehet megoldani a problémát.
A dokumentumok sokszorosításának problémája
Projektjeinkben a Fluentd DaemonSet-ként van üzembe helyezve (a Kubernetes-fürt minden csomópontján egy példányban automatikusan elindul), és figyeli a /var/log/containers könyvtárban található szokásos tárolónaplókat. Az összegyűjtés és a feldolgozás után a JSON-dokumentumok formájú naplók elküldésre kerülnek az ElasticSearch-nek, fürtben vagy önálló formában, a projekt méretétől, valamint a teljesítmény- és hibatűrési követelményektől függően. A Kibana grafikus felületként szolgál.
Amikor a Fluentd-t egy kimeneti pufferelő beépülő modullal használjuk, olyan helyzetbe ütköztünk, hogy az ElasticSearch egyes dokumentumai pontosan ugyanazt a tartalmat tartalmazták, és csak az azonosítóban tértek el. Példaként az Nginx napló segítségével ellenőrizheti, hogy ez egy üzenet ismétlődése. A naplófájlban ez az üzenet egyetlen példányban létezik:
127.0.0.1 192.168.0.1 - [28/Feb/2013:12:00:00 +0900] "GET / HTTP/1.1" 200 777 "-" "Opera/12.0" -Az ElasticSearch-ben azonban számos olyan dokumentum található, amelyek ezt az üzenetet tartalmazzák:
{
"_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"
}
}Sőt, kettőnél több ismétlés is lehet.
A probléma Fluentd naplóiban történő kijavítása közben számos figyelmeztetést láthat a következő tartalommal:
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"Ezek a figyelmeztetések akkor fordulnak elő, ha az ElasticSearch nem tud választ adni egy kérésre a request_timeout paraméterben megadott időn belül, ezért a továbbított pufferrészlet nem törölhető. Ezután a Fluentd újra megpróbálja elküldeni a pufferrészletet az ElasticSearch-nek, és tetszőleges számú próbálkozás után a művelet sikeresen befejeződik:
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"Az ElasticSearch azonban minden egyes átvitt pufferrészletet egyediként kezel, és egyedi _id mezőértékeket rendel hozzájuk az indexelés során. Így jelennek meg az üzenetek másolatai.
Kibanában így néz ki:
Az oldat
A probléma megoldására több lehetőség is kínálkozik. Az egyik a fluent-plugin-elasticsearch beépülő modulba épített mechanizmus, amely minden dokumentumhoz egyedi hash-t generál. Ha ezt a mechanizmust használja, az ElasticSearch felismeri az ismétlődéseket a továbbítási szakaszban, és megakadályozza a dokumentumok ismétlődését. Figyelembe kell azonban venni, hogy ez a problémamegoldási módszer nehezen megy a nyomozásba, és nem szünteti meg a hibát időkorlátozás hiányában, ezért az alkalmazását elhagytuk.
A Fluentd kimeneten pufferelő beépülő modult használunk, amely megakadályozza a naplózás elvesztését rövid távú hálózati problémák vagy megnövekedett naplózási intenzitás esetén. Ha valamilyen oknál fogva az ElasticSearch nem tud azonnal dokumentumot írni az indexbe, a dokumentum sorba kerül, és a lemezen tárolódik. Ezért esetünkben a fent leírt hibához vezető probléma forrásának kiküszöbölése érdekében be kell állítani a megfelelő pufferelési paramétereket, amelyeknél a Fluentd kimeneti puffer megfelelő méretű lesz és ugyanakkor sikerül kitisztítani a megadott időn belül.
Érdemes megjegyezni, hogy az alábbiakban tárgyalt paraméterek értékei egyediek a kimeneti bővítmények pufferelésének minden egyes esetben, mivel számos tényezőtől függenek: a szolgáltatások által a naplóba írt üzenetek intenzitása, a lemezrendszer teljesítménye, a hálózat csatorna terhelése és sávszélessége. Ezért annak érdekében, hogy minden egyedi esetnek megfelelő, de nem redundáns pufferbeállításokat kapjon, vakon elkerülve a hosszadalmas kereséseket, felhasználhatja azokat a hibakeresési információkat, amelyeket a Fluentd működés közben a naplójába ír, és viszonylag gyorsan megkapja a helyes értékeket.
A probléma rögzítésekor a konfiguráció így nézett ki:
<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>A probléma megoldása során a következő paraméterek értékeit manuálisan választottuk ki:
chunk_limit_size – azon csonkok mérete, amelyekre a pufferben lévő üzenetek fel vannak osztva.
- flush_interval – időintervallum, amely után a puffer törlődik.
- queue_limit_length — a sorban lévő darabok maximális száma.
- A request_timeout az az idő, ameddig a kapcsolat létrejön a Fluentd és az ElasticSearch között.
A teljes pufferméret kiszámítható a queue_limit_length és a chunk_limit_size paraméterek megszorzásával, amely úgy értelmezhető, mint „a sorban lévő darabok maximális száma, amelyek mindegyikének adott mérete van”. Ha a puffer mérete nem elegendő, a következő figyelmeztetés jelenik meg a naplókban:
2020-01-21 10:22:57 +0000 [warn]: [test-prod] failed to write data into buffer by buffer overflow action=:blockEz azt jelenti, hogy a puffernek nincs ideje a megadott időn belül törlésre, és a teljes pufferbe belépő adatok blokkolva vannak, ami a naplók egy részének elvesztéséhez vezet.
A puffert kétféleképpen növelheti: a sorban lévő egyes darabok méretének vagy a sorban lévő darabok számának növelésével.
Ha a chunk_limit_size darabméretet 32 megabájtnál nagyobbra állítja, akkor az ElasticSeacrh nem fogadja el, mivel a bejövő csomag túl nagy lesz. Ezért, ha tovább kell növelnie a puffert, jobb, ha növeli a maximális sorhosszt queue_limit_length.
Amikor a puffer túlcsordul, és csak az elégtelen időtúllépés üzenet marad, elkezdheti növelni a request_timeout paramétert. Ha azonban az értéket 20 másodpercnél hosszabbra állítja, a következő figyelmeztetések jelennek meg a Fluentd naplókban:
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" Ez az üzenet semmilyen módon nem befolyásolja a rendszer működését, és azt jelenti, hogy a puffer öblítési ideje tovább tartott, mint amit a slow_flush_log_threshold paraméter beállított. Ez hibakeresési információ, és ezt használjuk a request_timeout paraméter értékének kiválasztásakor.
Az általánosított kiválasztási algoritmus a következő:
- Állítsa be a request_timeout értéket a szükségesnél garantáltan nagyobb értékre (több száz másodperc). A beállítás során a paraméter helyes beállításának fő feltétele az időtúllépés hiányára vonatkozó figyelmeztetések eltűnése.
- Várja meg a slow_flush_log_threshold küszöbérték túllépéséről szóló üzeneteket. Az eltelt_idő mezőben lévő figyelmeztető szöveg a puffer törlésének valós idejét mutatja.
- Állítsa a request_timeout értéket nagyobb értékre, mint a megfigyelési időszak során kapott maximális eltelt_idő érték. A request_timeout értékét az eltelt_idő + 50% értékre számítjuk.
- Ha el szeretné távolítani a naplóból a hosszú pufferürítésekre vonatkozó figyelmeztetéseket, növelje a slow_flush_log_threshold értékét. Ezt az értéket a következőképpen számítjuk ki: eltelt_idő + 25%.
Ezeknek a paramétereknek a végső értékeit, amint azt korábban megjegyeztük, minden esetben egyedileg kapjuk meg. A fenti algoritmus követésével garantáltan kiküszöböljük az ismétlődő üzenetekhez vezető hibát.
Az alábbi táblázat bemutatja, hogy a napi hibák száma, amelyek az üzenetek megkettőzéséhez vezetnek, hogyan változik a fent leírt paraméterek értékeinek kiválasztásának folyamatában:
csomópont-1
csomópont-2
csomópont-3
csomópont-4
Előtte utána
Előtte utána
Előtte utána
Előtte utána
nem sikerült kiüríteni a puffert
1749/2
694/2
47/0
1121/2
újrapróbálkozás sikerült
410/2
205/1
24/0
241/2
Érdemes megjegyezni, hogy a kapott beállítások elveszíthetik relevanciájukat a projekt növekedésével, és ennek megfelelően a naplók száma növekszik. Az elégtelen időtúllépés elsődleges jele a hosszú pufferürítésről szóló üzenetek visszatérése a Fluentd naplóba, vagyis a slow_flush_log_threshold küszöbérték túllépése. Ettől kezdve még mindig van egy kis tartalék a request_timeout paraméter túllépése előtt, ezért kell ezekre az üzenetekre időben válaszolni, és meg kell ismételni a fent leírt optimális beállítások kiválasztásának folyamatát.
Következtetés
A Fluentd kimeneti puffer finomhangolása az EFK verem konfigurálásának egyik fő lépése, amely meghatározza működésének stabilitását és a dokumentumok indexekben való helyes elhelyezését. A leírt konfigurációs algoritmus alapján biztos lehet benne, hogy minden napló a megfelelő sorrendben, ismétlődések és veszteségek nélkül kerül az ElasticSearch indexbe.
Olvassa el blogunk további cikkeit is:
Forrás: will.com