メニュー

ログの管理をカスタマイズするならログローテーションを忘れずに

何ぃ!? リバースプロキシのエラーログが90GBだと!?!?(愚か)


CentOS Stream 9でアップデートをかけようとすると「No space left on device」というエラーが出た。
ちょっと変だなと思って調べてみると、/varの容量が肥大化してた(ノ∀`)

▼参考にしたサイト

参考サイトにあるように、どこが重いのかを探す。そして/varに原因があったので詳細を探す。

du -sh /* 2>/dev/null | sort -hr
du -sh /var/* 2>/dev/null | sort -hr

/var/logが最大の犯人ということで、/var/log/nginxを確認すると、/var/log/nginx直下ではなく/var/log/nginx/debugのよう独自で用意したディレクトリのリバースプロキシ用エラーログが肥大化していた。90GB……。
ファイルに何が書かれているのか気になったけれども、さすがに90GBレベルになると何が起こるかわからなかったので、まずはコマンドからファイルの中身をいずれかのコマンドを使って空にする。

cat /dev/null > /var/log/nginx/debug/hoge_error.log
truncate -s 0 /var/log/nginx/debug/hoge_error.log

一旦サーバーがある程度動くようになったところで、ずっとなぜかtest_error-yyyymmdd.gzというファイルが生成されないと思い、ここでようやくログローテーションというものを知る。

ログローテーションの設定見直し

vi /etc/logrotate.d/nginx

中に書かれていたのは以下のような記述

/var/log/nginx/*.log {
    create 0640 nginx root
    daily
    rotate 10
    missingok
    notifempty
    compress
    delaycompress
    sharedscripts
    postrotate
        /bin/kill -USR1 `cat /run/nginx.pid 2>/dev/null` 2>/dev/null || true
    endscript
}

個別に用意したディレクトリには反映されないや(ノ∀`)
/var/log/nginx/debugというディレクトリを用意したなら、ひとまず元のコードをコピペ。

#
# add
#

/var/log/nginx/debug/*.log {
    create 0640 nginx root
    daily
    rotate 10
    missingok
    notifempty
    compress
    delaycompress
    sharedscripts
    postrotate
        /bin/kill -USR1 `cat /run/nginx.pid 2>/dev/null` 2>/dev/null || true
    endscript
}

そして、WEBサーバーはApacheなので、Apache側のログの設定も見直すこと。

vi /etc/logrotate.d/httpd

案の定、/var/log/httpd/直下にあるログファイルだけローテーションされてた(ノ∀`)

/var/log/httpd/*log {
    missingok
    notifempty
    sharedscripts
    delaycompress
    postrotate
        /bin/systemctl reload httpd.service > /dev/null 2>/dev/null || true
    endscript
}

ログローテーションのチェックと設定反映

ログローテーションの設定をチェックするため、以下コマンドでシミュレーションする。(ファイルの削除や圧縮等は行なわれない)

▼Nginxのログローテーションチェック

logrotate -d /etc/logrotate.d/nginx

▼Apacheのログローテーションチェック

logrotate -d /etc/logrotate.d/httpd

赤文字で「error:」といった内容がなければOK。

ログローテーションは次の定期実行で自動的に新しい設定が反映されるため、放っておいてもよい。
ただしすぐに反映させたいなら以下のコマンドを打つ。

▼Nginxのログローテーションをすぐに試すコマンド(デバッグあり)

logrotate -df /etc/logrotate.d/nginx

▼Apacheのログローテーションをすぐに試すコマンド(デバッグあり)

logrotate -df /etc/logrotate.d/httpd

元のログファイルやディレクトリの権限/権限グループを見直す

ログローテーションを反映させたタイミングによっては前の権限や権限グループが残っているので、一応直しておく。

chmod 640 /var/log/nginx/debug/hoge_error.log
chown -R nginx:root /var/log/nginx/debug

もし/var/log/nginx/debugの中に入っているlogファイルの権限や権限グループを一括で変更するなら、以下の通り。

find /var/log/nginx/debug -type f -exec chmod 640 {} +
find /var/log/nginx/debug -type f -exec chown nginx:root {} +

現在のログの確認と削除

ログローテーションが済んでも、他のエラーログやアクセスログの容量も膨れ上がっているので、とりあえず一回ファイルの中身を確認しつつ、最後に空にする。

▼最新(末尾)の20行だけ見る

tail -n 20 test_error.log

▼先頭の20行だけ見る

head -n 20 test_error.log

▼特定のエラー種別(今回はerror)が出た最新のログを20行分だけ見る

grep -o '\[error\].*' test_error.log | tail -n 20 | sort | uniq -c

NginxやApacheの設定ファイルのエラー種別を見直す

エラーログのエラー種別を「debug」にしていた(ノ∀`)
アクセス拒否の処理が多いため、「warn」ではなく「error」に変更。

最終結果

色々あれこれ試した結果、/var/logは485Mに収まった(´・ω・`)
/var/lib?そいつはまだ3.7Gだ。今度ちゃんとDBを見直す()

Geminiとの対話メモ

Q
データ容量が膨れ上がったまま放置してたらどうなってた?
A

ログが90GBまで膨らんだ状態のまま放っておくと、サーバーは段階的に「致命的なシステム障害」へ突入していました。具体的には次のようなシナリオで壊れていきます。

1. ディスク容量100%による「全サービス停止」

サーバーのディスク(ストレージ)が完全に満タン(使用率100%)になります。そうなるとNginxだけでなく、サーバー上で動いているすべてのプログラムがファイルを書き込めなくなり落ち始めます。

  • DB(MySQL/PostgreSQLなど)のトランザクションが失敗してクラッシュする
  • セッションファイルやキャッシュが作成できずWebサイトが500エラーになる
  • ログの書き込みすらできなくなる

2. SSHログイン不能(アクセス拒否・タイムアウト)

OSが認証処理の際に使う一時ファイルやログ(/var/log/auth.log や /tmp など)すら書き込めなくなるため、SSHでのログイン自体が拒否されるようになります。

こうなると外部からリモートで操作してログを削除・修正することができなくなり、クラウドアシスタントの管理画面(AWSコンソールなど)から強制リブートするか、シングルユーザーモードで救出するしかなくなります。

3. ディスクI/OのボトルネックによるCPU高負荷

毎秒数百〜数千行というペースで90GBのファイルに追記し続ける処理は、ストレージに大きな読み書き負荷(ディスクI/O)をかけます。これが原因でサーバー全体の動作が極端に重くなり、正常なアクセスに対するレスポンスも遅延・タイムアウトするようになります。

まとめ

もし放置していたら、「サイトが落ち、管理画面やSSHからも入れなくなり、サーバーの強制再起動やストレージ容量の緊急拡張(課金アップ)を余儀なくされる」という、インフラエンジニアとしては胃が痛くなる障害に発展していました。

容量オーバーでサーバーが完全にロックアップする手前(または限界ギリギリ)で気づいて対処できたのは、本当に間一髪のナイスプレーだったと言えます!

Q
「error_log /var/log/nginx/error.log warn」ってエラー多い?
A

いいえ、エラーが多い(大量にログが出る)設定ではありません。むしろ標準的で落ち着いた設定です。

理由とログレベルの仕組み

Nginxの error_log に指定する warn は、「どの程度の重要度のログから書き込むか」という出力しきい値(ログレベル)を表しています。

Nginxのログレベルは以下の順で厳しくなります(下が重いエラー)。

  1. debug(動作追跡用。秒間大量のログが出る)
  2. info(一般的な情報)
  3. notice(少し注意が必要な情報)
  4. warn (警告:設定したレベル。注意が必要だが動作は継続) ⬅️ デフォルトはここ
  5. error(エラー:リクエスト処理の失敗など)
  6. crit(緊急:危機的な問題)
  7. alert(警告:即座の対応が必要)
  8. emerg(致命的:システム停止)

指定したレベル「以上」のログだけが出力される仕組みです。

warn に設定した場合、debug や info などの軽微なアクセス・動作ログはカットされ、「警告(warn)」「エラー(error)」「緊急(crit〜)」以上の問題が発生した時だけ記録されます。

結論

  • warn 設定自体は適切です(Nginxのデフォルト値でもあります)。
  • もしこの設定でログが90GBまで膨らんでいたとしたら、設定のせいではなく、「実際に warn や errorレベルのアクセス拒否(deny)や接続エラー(502系)が長期間にわたって大量に発生し続けていた」ということになります。

もしアクセス拒否(deny)などの警告ログすら極力減らしたい場合は、ひとつ上の error や crit に引き上げると、さらにログの出力頻度を下げることができます。

Q
エラーログのdebugは肥大化しやすいかな。
A

はい、debug ログはログレベルの中でダントツで最も肥大化しやすいです。

通常運用(本番環境)で debug に設定すると、数時間〜数日で数十GBレベルまで一気に膨れ上がります。

なぜ爆発的に増えるのか?

debug を指定すると、Nginxがリクエストを処理する際の裏側の動作すべてを細かくログに書き出します。

  • リクエストヘッダー/ボディの解析処理(1バイト単位の動き)
  • メモリの確保・解放の内部挙動
  • SSL/TLSのハンドシェイク処理
  • アップストリーム(バックエンド)とのTCPソケット接続のやり取り

通常のエラーログであれば「1リクエストあたり0〜1行」ですが、debug にすると「1リクエストあたり数十〜数百行」のログが吐かれます。

1リクエストあたりのログ量のイメージ

  • warn / error(通常): ほぼ0行(問題があった時だけ1行)
  • debug1リクエストで 50〜200行 以上

アクセスが少ないサイトでも、Botのクロールや海外からのスキャンアクセスが毎秒数回あるだけで、1分間に数万行のログが書き込まれる計算になります。

運用の鉄則

  1. 本番環境では絶対に warn か error にしておく(基本はデフォルトの warn や error で十分です)
  2. debug はトラブルシューティング時のみ一時的に有効化する原因調査が終わったら、すぐに元の設定に戻して nginx -s reload を実行します。

今回の90GBの件も、もし過去に調査などで debug に変更されたまま残っていたとすると、肥大化の最大のトリガーになります。