読む前に、問いを決める

ログは何千行、何万行とあります。上から順に読むことはしません。問いを決めてから、コマンドで絞り込みます。障害のときの問いは、だいたい次の3つです。

問い	使うもの
何が多いか	awk で列を取り出し、`sort \
最初はいつか	grep -m1（最初の1件だけ）
同じリクエストの行はどれか	リクエストIDで grep

以下は、練習用に作ったログで手元で実行した結果です。障害の筋書きは「10:12 に新しい版を公開した直後から、応募が失敗している」です。

今まさに起きているかを見る：tail

tail -n 3 app.log                              # 最後の3行
tail -f app.log | grep --line-buffered ERROR   # 追記されたエラー行だけを流し続ける

tail -f は、ファイルに行が足されるたびに表示します（Ctrl+C で止める）。直した後に「もうエラーが出ていないか」を見張るときにも使います。--line-buffered を付けないと、grep が出力をためこんで、すぐに表示されないことがあります。

何が多いか：状態コードを数える

アクセスログは、空白で区切ると9番目の列が状態コードです。

awk '{print $9}' access.log | sort | uniq -c | sort -rn

   7 200
   4 500
   2 404
   1 302

500 が4件。では、どの画面で起きたか。

awk '$9 == 500 {print $7}' access.log | sort | uniq -c | sort -rn

   2 /jobs/12/apply
   1 /jobs/8/apply
   1 /jobs/31/apply

すべて応募（apply）でした。同じ件数の行の並び順は、環境によって変わることがあります。

「同じ500」の中身は同じとは限らない

アプリのログで、エラーの種類を数えます。

grep ERROR app.log | cut -d' ' -f4- | sort | uniq -c | sort -rn

   3 NoMethodError: undefined method 'name' for an instance of Job
   1 Net::ReadTimeout: notification server did not respond

外から見ると同じ「500」が4件でも、原因は2種類ありました。1件だけ、通知先のサーバが応答しなかったものです。まとめて1つの原因だと思い込むと、片方を直しても「まだ出ている」ことになります。

最初はいつか

grep -m1 ERROR app.log
grep deploy app.log

2026-10-24T10:13:05 ERROR [req=9a7f] NoMethodError: undefined method 'name' for an instance of Job
2026-10-24T10:12:30 INFO  [deploy] release 20261024101230 started

最初のエラーは、新しい版の公開の35秒後です。直近の変更が一番の容疑者になります（第6回）。最新のエラーだけを見ていると、この並びに気づけません。

時刻で範囲を切りたいときは、時刻が先頭にあり、2026-10-24T10:13:30 のように桁がそろった形なら、文字列の大小比較で絞れます。

awk '$1 >= "2026-10-24T10:13:30" && $1 < "2026-10-24T10:14:40"' app.log

同じリクエストの行をつなぐ：リクエストID

1つのリクエストの行は、ほかのリクエストの行と混ざって書かれます。そこで、多くのアプリは行にリクエストID（1回のリクエストに振られた番号）を付けます。これで探すと、1回分の出来事が順番に並びます。

grep 'req=9a7f' app.log

2026-10-24T10:13:05 INFO  [req=9a7f] POST /jobs/12/apply
2026-10-24T10:13:05 INFO  [req=9a7f] application saved id=902
2026-10-24T10:13:05 ERROR [req=9a7f] NoMethodError: undefined method 'name' for an instance of Job
2026-10-24T10:13:05 INFO  [req=9a7f] completed 500 in 47ms

応募は保存されてから、エラーになっています。 第2回の「データは届いているのに失敗と表示される」状態です。影響の見積もりが、ログ1つで変わります。

grep が「Binary file ... matches」としか言わないとき

ログに文字ではないバイト（NUL文字など）が混ざると、grep は中身を出さずに、こう言うだけになります（手元の macOS で確認。表示の文言は OS や grep の版で違います）。

Binary file broken.log matches

grep -a（文字として扱う）を付けるか、tr -d '\000' で取り除いてから探します。naminori の本番ログを集計するときも、この1手間を入れています。

tr -d '\000' < broken.log | grep ERROR

長い1ファイルを見て回る：less

less app.log で開き、/ERROR で検索、n で次へ、G で末尾、F で tail -f のように流し続ける、q で終わります。

ここで後から困ること

「エラーがたくさん出ています」とだけ報告すると、直した後に本当に減ったのかを比べられません。数えたコマンドと件数を、そのまま記録に残しておきます（第8回）。

• 問いを決めてから絞り込む
• tail -f で今を見張る
• 状態コードとエラーの種類を数える
• 最初のエラーと直近の変更を並べる
• リクエストIDで1回分の出来事をつなぐ
• Binary file matches の対処