fluentdのqueued_chunks_limit_size利用時の挙動の検証

fluentd

fluentdのv1.3.3 で queued_chunks_limit_size が設定可能になり、説明に以下のようにあったけどパッと理解できなかったので確認をしました。

  • If you set smaller flush_interval, e.g. 1s, there are lots of small queued chunks in buffer. This is not good with file buffer because it consumes lots of fd resources when output destination has a problem. This parameter mitigates such situations.

ref: https://docs.fluentd.org/v1.0/articles/buffer-section

結果としてはこの機能が入ると、queued 状態の buffer chunk の数を制限することができるようになることがわかりました。
ドキュメントを見ると、デフォルト値がnil (No limit)となっているけど、設定しないと flush_thread_count の値になるのでflush_thread_countを指定している場合は合わせて注意が必要です。
参考：https://github.com/fluent/fluentd/commit/a8d2bbb209c775742f589fe067a0ecac7773ed94#diff-7a3f304568ba6143aaf2b7e78011d044

疑問点

疑問点は、以下のような設定の場合 queued の buffer chunk ファイルは増えないけど staged の buffer chunk が増えて消費するfdの総数はあまり変わらないのでは。と勘違いしたことです。

    chunk_limit_size 3g
    flush_interval 30s
    flush_mode interval
    timekey     5m

前提知識

https://docs.fluentd.org/v1.0/articles/buffer-plugin-overview#the-lifecycle-of-chunks

buffer chunkでは、以下のようになファイルができると

  • buufer.bxxx になっていれば state が staged 状態

  • buufer.qxxx になっていれば queued 状態

    になっているとわかります。

-rw-r--r-- 1 td-agent td-agent 742  1月 31 01:09 /var/log/fluent/out_s3/development/buffer.b580b6af3642109b9c033a2a85ef6a4a7.log
-rw-r--r-- 1 td-agent td-agent 103  1月 31 01:09 /var/log/fluent/out_s3/development/buffer.b580b6af3642109b9c033a2a85ef6a4a7.log.meta
-rw-r--r-- 1 td-agent td-agent 736  1月 31 01:09 /var/log/fluent/out_s3/development/buffer.q580b6af1dce897186b95d5927ebb34ea.log
-rw-r--r-- 1 td-agent td-agent 100  1月 31 01:10 /var/log/fluent/out_s3/development/buffer.q580b6af1dce897186b95d5927ebb34ea.log.meta

上記のように、buffer.bxxxxx.log と buffer.qxxxx.log というファイル（と.metaファイル）ができます。

実験

buffer chunk が queued の状態と staged の状態でそれぞれfdの消費がどうなっているのか確認します。
fluentd に定常的にデータを送って、bufferにデータが溜まるような状況※を作り出して検証しています。

※存在しないS3のバケット名を指定して、エラーが発生するようにしました。

queued_chunks_limit_sizeが効かない場合

まずは、queued_chunks_limit_size のない td-agent 1.2.2 で確認します。 queuedのファイルが大量にでき、fdを消費してることがわかります。

[ec2-user@localhost ~]$ date; ls -lha /var/log/fluent/out_s3/development/buffer.q* |wc -l
2019年  1月 31日 木曜日 00:56:49 UTC
224
[ec2-user@localhost ~]$ date; ls -lha /var/log/fluent/out_s3/development/buffer.q* |wc -l
2019年  1月 31日 木曜日 00:57:23 UTC
256

fdを見ると以下のように消費していっていることがわかります。

[ec2-user@localhost ~]$ date; for i in $(ps aux | grep "[t]d-agent" | awk '{print $2}'); do  sudo ls /proc/$i/fd | wc -l; done
2019年  1月 31日 木曜日 00:56:59 UTC
14
272
[ec2-user@localhost ~]$ date; for i in $(ps aux | grep "[t]d-agent" | awk '{print $2}'); do  sudo ls /proc/$i/fd | wc -l; done
2019年  1月 31日 木曜日 00:57:57 UTC
14
336
queued_chunks_limit_sizeが効く場合

td-agent 1.3.3 で確認します。 td-agent 1.2.2のときと違いqueuedのファイルが増えていません。

[ec2-user@localhost ~]$ date; ls -lha [ec2-user@localhost ~]$ date; ls -lha /var/log/fluent/out_s3/development/buffer.q* |wc -l
2019年  1月 31日 木曜日 01:13:41 UTC
12
[ec2-user@localhost ~]$ date; ls -lha /var/log/fluent/out_s3/development/buffer.q* |wc -l
2019年  1月 31日 木曜日 01:17:33 UTC
12

buffer chunck の増え方をみていると flush_interval のタイミング でbuffer chunck が増えずに、timekeyのタイミングでファイルが増えていることがわかります。

[ec2-user@localhost ~]$ date; ls -lha /var/log/fluent/out_s3/development/buffer.b* |wc -l
2019年  1月 31日 木曜日 01:13:45 UTC
50
[ec2-user@localhost ~]$ date; ls -lha /var/log/fluent/out_s3/development/buffer.b* |wc -l
2019年  1月 31日 木曜日 01:17:01 UTC
82

queuedのファイルの一定数ですが、stagedのファイルが増えてfdを消費しているが、queued_chunks_limit_size が効かない場合と比べると fd の増え方が緩やかであることがわかります。

[ec2-user@localhost ~]$ date; for i in $(ps aux | grep "[t]d-agent" | awk '{print $2}'); do  sudo ls /proc/$i/fd | wc -l; done
2019年  1月 31日 木曜日 01:13:51 UTC
14
78
[ec2-user@localhost ~]$ date; for i in $(ps aux | grep "[t]d-agent" | awk '{print $2}'); do  sudo ls /proc/$i/fd | wc -l; done
2019年  1月 31日 木曜日 01:17:05 UTC
14
110

確認結果

buffer chunkファイルが新しく作られる条件は以下の３つのどれかになります。

  1. flush_interval毎にstateがqueuedになるので、新しいbuffer chunck（buffered）が作る。
  2. timekey分の時間がたつと新しいbuffer chunck（buffered）が作られる
  3. chunk_limit_size * chunk_full_thresholdに到達した。

queued_chunks_limit_size を指定すると、1. の条件で buffer chunkファイルが増えなくなるため結果として fd の使用を抑えることができるということのようです。

ただし、２と３の条件ではbuffer chunkファイルが増えていくのでこの点は注意していたほうがよさそうです。

また、Buffer chunkファイルの数が抑えられるので復旧時に処理するファイルも少なくて済みそうとう気がします。

補足. 検証時の設定

検証のときは以下のような設定で行っています。

<match *.*.development.tag>
  @type s3

  # IAM Instance attached
  <instance_profile_credentials>
    retry 5
  </instance_profile_credentials>

  s3_bucket 出力先のバケット
  s3_region ap-northeast-1
  check_bucket false # バケットが存在しないときに作成しないでエラーを発生させるため設定

  path fluent-plugin-s3/${tag[0]}/${tag[1]}/
  s3_object_key_format "%{path}%{time_slice}%{index}_#{Socket.gethostname}.%{file_extension}"
  time_slice_format year=%Y/month=%m/day=%d/hour=%H/%Y%m%d-%H_

  format json

  @id s3_${tag[0]}_${tag[1]}_development
  @log_level debug

  <buffer tag,time>
    @type file
    path /var/log/fluent/out_s3/development/
    chunk_limit_size 3g
    flush_interval 30s
    flush_mode interval
    flush_at_shutdown true
    retry_max_times 300
    retry_wait 5m
    retry_max_interval 10m
    timekey     5m
    flush_thread_count 3
    queued_chunks_limit_size 12
  </buffer>
</match>