3
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

Cloudwatch Logsに吐かれるログを爆増させてしまった話【fluent-bit】

Last updated at Posted at 2024-07-24

概要

先日、以下の記事で紹介したように、fluent-bitを利用して
アプリケーションログをCloudwatch Logsに吐かせる設定を行いました。

しかし、時折Cloudwatch Logsへ異常なほど多いログが吐かれる事態が発生し、コストの上昇を招いてしまいました。
今回は、解決方法と根本原因について説明します。

何が起こったか

fluent-bitからCloudwatch Logsへ送信されるアプリケーションログが
2024-04-29 21:03:48から2024-04-30 00:58:48の間急増しました。

スクリーンショット 2024-07-13 16.55.00.png

fluent-bitのログを確認すると、requires a larger buffer size, lines are too long. Skipping fileが約1分毎に発生していることが分かりました。

また、CloudWatch Logs Insightsにて1時間ごとのログ件数を調べると、該当期間のログが数万から10万倍になっていました。

スクリーンショット 2024-07-13 16.58.21.png

原因と思われるエラー

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 // 追加

対応の根拠と根本原因

原因は、以下の2点です。

  1. [error] [input:tail:tail.0] file=/var/log/hogehoge/stdout.log requires a larger buffer size, lines are too long. Skipping file.が発生したこと
  2. 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プロパティに従って、希望の値に調整してください:

http://fluentbit.io/documentation/0.11/input/tail.html

https://github.com/fluent/fluent-bit/issues/354

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つあります。

  1. requires a larger buffer size, lines are too long. Skipping file.というエラーがが繰り返し発生したこと。
  2. 1のエラー発生時に、fluent-bitによってログファイル全体がcloudwatchへ再送されたこと。

なお、2の挙動は想定通りだとfluent-bit開発者が言及しています。

上記1.2の対応策として、

該当アプリケーション用の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 // 追加

振り返り

弊社サービスでは、可変長かつ大きめのログが吐かれる箇所が存在しており、設定時にその考慮が不足していました。
その結果、不要なログの再送が発生し、コストの増加を招いてしまいました。

今後は設定漏れ・考慮漏れがないように、issue等を確認して起こりうるエラーを調査しておくなどの対策が必要ですね。

3
1
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
3
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?