🥇Fluentd: mengapa penting untuk mengkonfigurasi buffer keluaran

Saat ini, mustahil membayangkan proyek berbasis Kubernetes tanpa tumpukan ELK, yang menyimpan log aplikasi dan komponen sistem cluster. Dalam praktik kami, kami menggunakan tumpukan EFK dengan Fluentd, bukan Logstash.

Fluentd adalah pengumpul log modern dan universal yang semakin populer dan telah bergabung dengan Cloud Native Computing Foundation, itulah sebabnya vektor pengembangannya difokuskan untuk digunakan bersama dengan Kubernetes.

Fakta penggunaan Fluentd dan bukan Logstash tidak mengubah esensi umum dari paket perangkat lunak, namun Fluentd memiliki ciri khas tersendiri karena keserbagunaannya.

Misalnya, ketika kami mulai menggunakan EFK dalam proyek yang sibuk dengan intensitas logging yang tinggi, kami dihadapkan pada kenyataan bahwa di Kibana beberapa pesan ditampilkan berulang kali. Pada artikel ini kami akan memberi tahu Anda mengapa fenomena ini terjadi dan bagaimana mengatasi masalah tersebut.

Masalah duplikasi dokumen

Dalam proyek kami, Fluentd diterapkan sebagai DaemonSet (secara otomatis diluncurkan dalam satu instance di setiap node cluster Kubernetes) dan memantau log container stdout di /var/log/containers. Setelah pengumpulan dan pemrosesan, log dalam bentuk dokumen JSON dikirim ke ElasticSearch, dimunculkan dalam bentuk cluster atau mandiri, bergantung pada skala proyek dan persyaratan kinerja serta toleransi kesalahan. Kibana digunakan sebagai antarmuka grafis.

Saat menggunakan Fluentd dengan plugin buffering keluaran, kami menghadapi situasi di mana beberapa dokumen di ElasticSearch memiliki konten yang persis sama dan hanya berbeda pada pengidentifikasinya. Anda dapat memverifikasi bahwa ini adalah pengulangan pesan menggunakan log Nginx sebagai contoh. Di file log, pesan ini ada dalam satu salinan:

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

Namun, ada beberapa dokumen di ElasticSearch yang berisi pesan ini:

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

Apalagi pengulangannya bisa lebih dari dua kali.

Saat memperbaiki masalah ini di log Fluentd, Anda dapat melihat banyak peringatan dengan konten berikut:

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"

Peringatan ini terjadi ketika ElasticSearch tidak dapat mengembalikan respons terhadap permintaan dalam waktu yang ditentukan oleh parameter request_timeout, itulah sebabnya fragmen buffer yang diteruskan tidak dapat dihapus. Setelah ini, Fluentd mencoba mengirim fragmen buffer ke ElasticSearch lagi dan setelah beberapa kali percobaan, operasi berhasil diselesaikan:

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"

Namun, ElasticSearch memperlakukan setiap fragmen buffer yang ditransfer sebagai unik dan memberinya nilai bidang _id unik selama pengindeksan. Beginilah tampilan salinan pesan.

Di Kibana tampilannya seperti ini:

Solusinya

Ada beberapa opsi untuk mengatasi masalah ini. Salah satunya adalah mekanisme yang dibangun pada plugin fluent-plugin-elasticsearch untuk menghasilkan hash unik untuk setiap dokumen. Jika Anda menggunakan mekanisme ini, ElasticSearch akan mengenali pengulangan pada tahap penerusan dan mencegah duplikat dokumen. Namun kita harus memperhitungkan bahwa metode penyelesaian masalah ini bertentangan dengan penyelidikan dan tidak menghilangkan kesalahan dengan kurangnya waktu tunggu, jadi kami mengabaikan penggunaannya.

Kami menggunakan plugin buffering pada output Fluentd untuk mencegah hilangnya log jika terjadi masalah jaringan jangka pendek atau peningkatan intensitas logging. Jika karena alasan tertentu ElasticSearch tidak dapat langsung menulis dokumen ke indeks, dokumen tersebut dimasukkan ke dalam antrean dan disimpan di disk. Oleh karena itu, dalam kasus kami, untuk menghilangkan sumber masalah yang menyebabkan kesalahan yang dijelaskan di atas, perlu untuk menetapkan nilai yang benar untuk parameter buffering, di mana buffer output Fluentd akan memiliki ukuran yang cukup dan pada saat yang sama berhasil diselesaikan dalam waktu yang ditentukan.

Perlu dicatat bahwa nilai parameter yang dibahas di bawah ini bersifat individual dalam setiap kasus penggunaan buffering di plugin keluaran, karena bergantung pada banyak faktor: intensitas penulisan pesan ke log oleh layanan, kinerja sistem disk, jaringan beban saluran dan bandwidthnya. Oleh karena itu, untuk mendapatkan pengaturan buffer yang sesuai untuk setiap kasus, tetapi tidak berlebihan, menghindari pencarian yang panjang secara membabi buta, Anda dapat menggunakan informasi debug yang ditulis Fluentd ke lognya selama pengoperasian dan mendapatkan nilai yang benar dengan relatif cepat.

Pada saat masalah dicatat, konfigurasinya tampak seperti ini:

 <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>

Saat memecahkan masalah, nilai parameter berikut dipilih secara manual:
chunk_limit_size — ukuran potongan pesan dalam buffer yang dibagi.

flush_interval — interval waktu setelah buffer dibersihkan.
queue_limit_length — jumlah maksimum potongan dalam antrian.
request_timeout adalah waktu pembuatan koneksi antara Fluentd dan ElasticSearch.

Total ukuran buffer dapat dihitung dengan mengalikan parameter queue_limit_length dan chunk_limit_size, yang dapat diartikan sebagai “jumlah maksimum potongan dalam antrian, yang masing-masing memiliki ukuran tertentu.” Jika ukuran buffer tidak mencukupi, peringatan berikut akan muncul di log:

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

Artinya buffer tidak punya waktu untuk dibersihkan dalam waktu yang ditentukan dan data yang masuk ke buffer penuh diblokir, yang akan menyebabkan hilangnya sebagian log.

Anda dapat meningkatkan buffer dengan dua cara: dengan meningkatkan ukuran setiap bongkahan dalam antrean, atau dengan jumlah bongkahan yang dapat berada dalam antrean.

Jika Anda menyetel ukuran potongan chunk_limit_size menjadi lebih dari 32 megabyte, maka ElasticSeacrh tidak akan menerimanya, karena paket yang masuk akan terlalu besar. Oleh karena itu, jika Anda perlu menambah buffer lebih lanjut, lebih baik menambah panjang antrian maksimum queue_limit_length.

Ketika buffer berhenti meluap dan hanya pesan batas waktu tidak mencukupi yang tersisa, Anda dapat mulai meningkatkan parameter request_timeout. Namun, jika Anda mengatur nilainya menjadi lebih dari 20 detik, peringatan berikut akan mulai muncul di log 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"

Pesan ini tidak mempengaruhi pengoperasian sistem dengan cara apa pun dan berarti waktu buffer flush membutuhkan waktu lebih lama daripada yang ditetapkan oleh parameter slow_flush_log_threshold. Ini adalah informasi debug dan kami menggunakannya saat memilih nilai parameter request_timeout.

Algoritma seleksi umum adalah sebagai berikut:

Setel request_timeout ke nilai yang dijamin lebih besar dari yang diperlukan (ratusan detik). Selama pengaturan, kriteria utama untuk pengaturan yang benar dari parameter ini adalah hilangnya peringatan karena kurangnya waktu tunggu.
Tunggu pesan tentang melebihi ambang batas slow_flush_log_threshold. Teks peringatan di bidang elapsed_time akan menunjukkan waktu sebenarnya buffer dibersihkan.
Tetapkan request_timeout ke nilai yang lebih besar dari nilai elapsed_time maksimum yang diperoleh selama periode observasi. Kami menghitung nilai request_timeout sebagai elapsed_time + 50%.
Untuk menghilangkan peringatan tentang buffer flush yang panjang dari log, Anda dapat menaikkan nilai slow_flush_log_threshold. Kami menghitung nilai ini sebagai elapsed_time + 25%.

Nilai akhir dari parameter ini, seperti disebutkan sebelumnya, diperoleh secara individual untuk setiap kasus. Dengan mengikuti algoritma di atas, kami dijamin dapat menghilangkan kesalahan yang menyebabkan pesan berulang.

Tabel di bawah ini menunjukkan bagaimana jumlah kesalahan per hari, yang menyebabkan duplikasi pesan, berubah dalam proses pemilihan nilai parameter yang dijelaskan di atas:

simpul-1
simpul-2
simpul-3
simpul-4

Sebelum setelah
Sebelum setelah
Sebelum setelah
Sebelum setelah

gagal membersihkan buffer
1749/2
694/2
47/0
1121/2

coba lagi berhasil
410/2
205/1
24/0
241/2

Perlu juga dicatat bahwa pengaturan yang dihasilkan mungkin kehilangan relevansinya seiring dengan pertumbuhan proyek dan, oleh karena itu, jumlah log meningkat. Tanda utama dari waktu tunggu yang tidak mencukupi adalah kembalinya pesan tentang buffer flush yang lama ke log Fluentd, yaitu melebihi ambang batas slow_flush_log_threshold. Mulai saat ini, masih ada margin kecil sebelum parameter request_timeout terlampaui, sehingga pesan-pesan ini perlu ditanggapi secara tepat waktu dan ulangi proses pemilihan pengaturan optimal yang dijelaskan di atas.

Kesimpulan

Menyempurnakan buffer keluaran Fluentd adalah salah satu tahapan utama dalam mengonfigurasi tumpukan EFK, menentukan stabilitas operasinya, dan penempatan dokumen yang benar dalam indeks. Berdasarkan algoritma konfigurasi yang dijelaskan, Anda dapat yakin bahwa semua log akan ditulis ke indeks ElasticSearch dalam urutan yang benar, tanpa pengulangan atau kehilangan.

Fluentd: Mengapa penting untuk mengonfigurasi buffer keluaran

Masalah duplikasi dokumen

Solusinya

Kesimpulan

Baca juga artikel lainnya di blog kami:

Tambah komentar Membatalkan balasan