パイプは小さなプログラムを文に繋ぐ
一言でいうと
grep は選び、sed は直し、awk は数えます。この3つのツールをパイプでつなげば、数十万行のログから答えを引き出すのに5行あれば十分です。
なぜ必要なのか
障害の報告を受けました。「午後3時から応答が遅いです」。ログは40万行で、エディタで開くだけで数秒かかります。ここで必要なのはログビューアではなく、質問をコマンドに置き換える力です。
- 何件失敗したか -> 選んでから数える
- どのエンドポイントが問題か -> フィールドを取り出し、まとめて数えてから並べ替える
- 特定の IP が突出しているか -> 同じことを別のフィールドで行う
3つの質問はすべて同じ形です。だから、慣用句をひとつ覚えれば足ります。
... | sort | uniq -c | sort -rn | head
uniq -c は隣り合った重複だけを数えるので前に sort が必須で、後ろの sort -rn は件数の降順です。この4つの部品が、「何がいちばん多いか」という質問への標準的な答えです。
どう動くのか
ツールを選ぶ基準は単純です。行を選ぶだけなら grep、行を直すなら sed、フィールドを扱ったり計算したりするなら awk です。必要以上に強力なツールを使うと、遅くなって読みにくくなります。
パイプの正体も知っておいてください。パイプでつながれた各コマンドは、別々のプロセスで同時に実行され、前の stdout が後ろの stdin につながります。ここから2つの性質が導かれます。
- 大きなファイルもすべてをメモリに載せず、流しながら処理します。だから40万行でも速いのです。
- パイプの中で変更した変数は、外側に残りません。サブシェルだからです。
そしてパイプラインの終了コードは、既定では最後のコマンドのものです。curl ... | jq ... | wc -l で curl が失敗しても、wc が 0 を返せば全体は成功に見えます。スクリプトでこの罠を防ぐ仕組みが set -o pipefail で、次のコースで詳しく扱います。
性能のアンチパターンをいくつか、今のうちに直しておくとよいでしょう。
| こう書かずに | こう書く |
|---|---|
| `cat f | grep p` |
| `sort | uniq` |
| `cat f | wc -l` |
| `echo "$s" | cut -d. -f1` |
現場での姿
1つ目は、ステータスコードの集計です。 awk '$9 ~ /^5[0-9][0-9]$/ {print $7}' access.log | sort | uniq -c | sort -rn | head -10 の1行で、5xx をいちばん多く返したパス10個が出ます。ダッシュボードを開く前に、まずこれを打ちます。
2つ目は、割合の計算は awk で行うことです。 件数だけでは判断できないことがよくあります。awk '{t++; if ($5 != 200) e++} END {printf "%.1f\n", e*100/t}' のように END ブロックで一度に計算すれば、ファイルを2回読まなくて済みます。
3つ目は、ログを最初から読まないことです。 障害の発生時刻の前後5分だけを切り出すのが最初の動作です。40万行すべてを眺める習慣は、時間を食うだけでなく、すでに I/O が飽和したディスクでは、診断そのものが障害を大きくします。
大きなファイルに向き合う習慣
ログが数十ギガバイトになると、ツールの選択よりも読む量を減らすことのほうがはるかに大きく効きます。いくつかの習慣を身につけるだけで、数分かかるコマンドが数秒に変わります。
まず切り出す。 時刻で範囲を絞るのが最初の動作です。ログが時刻順に並んでいるなら、sed -n '/03:00/,/03:10/p' のように区間だけを取り出すか、そもそもその時間帯のファイルだけを選びます。そして、探しているものが確実なら、grep -m 1 で最初の一致で止めます。 40万行を最後まで読む理由はありません。
必要な列だけを取り出す。 awk '{print $7}' のようにフィールドを先に絞ると、後ろの sort が扱うデータがずっと小さくなります。sort はパイプラインの中でいちばん高価な場所なので、その前で減らすのが最も効果的です。
並べ替えが本当に必要か確認する。 数えるだけなら、awk の連想配列で一度に数えられます。awk '{c[$7]++} END {for (k in c) print c[k], k}' | sort -rn | head は、全体を並べ替えずに、最後に結果だけを並べ替えるので、行数が多くて種類が少ないときにずっと速くなります。
ロケールを切る。 先頭に LC_ALL=C を付けると、sort と grep が文字の比較規則を単純なバイト比較に切り替えるので、目に見えて速くなります。ただし並び順が変わるので、人に見せる結果には注意してください。
そして、圧縮されたログは展開せずにそのまま読みます。 zgrep、zcat を使えば、ディスクに一時ファイルを作らなくて済み、すでに満杯のディスクで診断して残りの容量まで埋めてしまう事故を避けられます。診断が障害を大きくしないようにすることが、大きなシステムで働くときの基本的なマナーです。
次のラボですること
/opt/lab/data/app.log を材料に、エラーの件数、リクエストが最も多い IP、ステータスコードごとの集計、上位のパス、エラー率を順に取り出し、最後にその結果を3行の要約レポートにまとめます。