概要
先日、以下の記事で紹介したように、fluent-bitを利用して
アプリケーションログをCloudwatch Logsに吐かせる設定を行いました。
しかし、時折Cloudwatch Logsへ異常なほど多いログが吐かれる事態が発生し、コストの上昇を招いてしまいました。
今回は、解決方法と根本原因について説明します。
何が起こったか
fluent-bitからCloudwatch Logsへ送信されるアプリケーションログが
2024-04-29 21:03:48から2024-04-30 00:58:48の間急増しました。
fluent-bitのログを確認すると、requires a larger buffer size, lines are too long. Skipping fileが約1分毎に発生していることが分かりました。
また、CloudWatch Logs Insightsにて1時間ごとのログ件数を調べると、該当期間のログが数万から10万倍になっていました。
原因と思われるエラー
4月 29 21:01:44 appname-01 fluent-bit[9578]: [2024/04/29 21:01:44] [error] [input:tail:tail.0] file=/var/log/hogehoge/stdout.log requires a larger buffer size, lines are too long. Skipping file.
最終的な対応
該当アプリケーション用のfluent-bit設定ファイルに、以下4つの設定を追加しました。
各設定については後述します。
- confファイル
[INPUT]
Name tail
Path /var/log/hogehoge/stdout.log
Tag hogehoge.log
Buffer_Chunk_Size 2M // 追加
Buffer_Max_Size 2M // 追加
Skip_Long_Lines On // 追加
[OUTPUT]
name cloudwatch_logs
match hogehoge.log
region ap-northeast-1
log_group_name /aws/ec2/hogehoge
log_stream_name ${EC2_TAG_NAME}-${DEPLOY_DATETIME}
auto_create_group true
workers 1
log_retention_days 3
log_key log
retry_limit 5 // 追加
対応の根拠と根本原因
原因は、以下の２点です。
- [error] [input:tail:tail.0] file=/var/log/hogehoge/stdout.log requires a larger buffer size, lines are too long. Skipping file.が発生したこと
- 1のエラーが発生した時、ログファイル全体がcloudwatch logsに再送されていること
2が怖すぎますね...
例えば、ログファイルに100万行のログがある状態で1のエラーが発生すると、100万行が全てCloudwatch logsに再送されてしまいます。
1の解決策
Buffer_Chunk_Size、Buffer_Max_Size
このエラーは、ログの1行あたりのbyteが大きすぎると発生します。
関連する設定はBuffer_Chunk_Size、Buffer_Max_Sizeで、これらはデフォルト値である32kbが使用されていました。
| Key | Description | Default |
|---|---|---|
| Buffer_Chunk_Size | ファイルデータを読み込むための初期バッファサイズを設定する。この値はバッファサイズを大きくするために使用される。この値は、https://docs.fluentbit.io/manual/v/dev-2.2/administration/configuring-fluent-bit/unit-sizes の指定に従わなければならない。 | 32k |
| Buffer_Max_Size | 監視ファイルごとのバッファサイズの上限を設定する。バッファを増やす必要がある場合（非常に長い行など）、この値を使用してメモリ・バッファの増加量を制限します。ファイルの読み込みがこの制限を超えると、そのファイルは監視ファイルリストから削除されます。この値はhttps://docs.fluentbit.io/manual/v/dev-2.2/administration/configuring-fluent-bit/unit-sizes の指定に従わなければならない。 | 32k |
エラー発生原因のログは51.091kbであり、32kbを超えており、
[appname@prod] grep "2024-04-29T21:01:44.647987737Z" /var/log/hogehoge/stdout.log | wc -c
51091
以下のように該当のログを出力する箇所（ここではhogehoge_usecase.goとします）を確認すると、時折32kbを超えることがありました。
[appname@prod] $ grep "hogehoge_usecase.go" /var/log/hogehoge/stdout.log | while read -r line || [ -n "${line}" ]; do
byte_count=$(echo -n "$line" | wc -c)
if (( byte_count > 32000 )); then
echo -n "$byte_count"
echo "\n"
fi
done
49852
49851
49852
49852
50009
そこで以下のIssueと、上記のbyte数を参考に、Buffer_Chunk_SizeおよびBuffer_Max_Sizeを2MBに設定しました。
ログ行が32kbを超える場合は、Buffer_Chunk_Sizeプロパティに従って、希望の値に調整してください：
retry_limit
また、エラー時に何度もログが再送されていたことより、リトライ回数に明示的に制限をかけました。
今回はretry_limit 5 としています。
Configuring Retries
スケジューラーにはRetry_Limitという簡単な設定オプションがあり、各出力セクションで個別に設定できる。
このオプションによって、リトライを無効にしたり、リミットを設けてN回トライし、そのリミットに達したらデータを破棄したりすることができる：
| Value | Description | |
|---|---|---|
| Retry_Limit | N | 再試行の最大回数を設定する整数値。 Nは≧1でなければならない（デフォルト：1）。 |
| Retry_Limit | no_limits or False | Retry_Limitがno_limitsまたはFalseに設定されている場合、スケジューラが実行できる再試行回数に制限がないことを意味する。 |
| Retry_Limit | no_retries | Retry_Limitがno_retriesに設定されている場合、リトライは無効になり、スケジューラは最初の送信が失敗した場合、宛先へのデータ送信を試みない。 |
2の解決策
Skip_Long_Lines On
requires a larger buffer size, lines are too long. Skipping file. の発生時にfluent-bitがログファイルを最初から読み直す問題は、以下Issueでも報告されています。
[issue] fluent-bitはmycatのログを収集する。ログが長すぎる場合、fluent-bit はログを最初から収集し直します。
ここでは解決策として、Skip_Long_LinesをOnにすることが挙げられています。
また、Fluent-bitの開発者は以下のように言及しており、fluent-bitのこの挙動は仕様だと思われます。
ファイルオフセットが戻らない、つまり前の位置から読み始めない。ノーマルモードとマルチラインモードでテストしました。動作は予想通り。
長い行が見つかるとエラーメッセージが表示され、ファイルは監視されなくなる。長い行をスキップして他の行の処理を続けたい場合は、ファイルの入力末尾セクションに 'Skip_Long_Lines On' を追加してください。
要約
fluent-bitから送信Cloudwatch Logsへされるアプリケーションログが2024-04-29 21:03:48から2024-04-30 00:58:48の間急増しました。
原因は2つあります。
- requires a larger buffer size, lines are too long. Skipping file.というエラーがが繰り返し発生したこと。
- 1のエラー発生時に、fluent-bitによってログファイル全体がcloudwatchへ再送されたこと。
なお、2の挙動は想定通りだとfluent-bit開発者が言及しています。
上記1.2の対応策として、
該当アプリケーション用のfluent-bit設定ファイルに以下４つの設定を追加しました。
- confファイル
[INPUT]
Name tail
Path /var/log/hogehoge/stdout.log
Tag hogehoge.log
Buffer_Chunk_Size 2M // 追加
Buffer_Max_Size 2M // 追加
Skip_Long_Lines On // 追加
[OUTPUT]
name cloudwatch_logs
match hogehoge.log
region ap-northeast-1
log_group_name /aws/ec2/hogehoge
log_stream_name ${EC2_TAG_NAME}-${DEPLOY_DATETIME}
auto_create_group true
workers 1
log_retention_days 3
log_key log
retry_limit 5 // 追加
振り返り
弊社サービスでは、可変長かつ大きめのログが吐かれる箇所が存在しており、設定時にその考慮が不足していました。
その結果、不要なログの再送が発生し、コストの増加を招いてしまいました。
今後は設定漏れ・考慮漏れがないように、issue等を確認して起こりうるエラーを調査しておくなどの対策が必要ですね。