コンテナが死んだとき何から見るか
一言でいうと
コンテナの診断は、ログ → 終了コード → 状態フィールドの3つを順に見ることです。この3つで解決しなければ、そのときにコンテナの中へ入ります。
なぜ必要なのか
「コンテナが起動しません」という報告は、実際には少なくとも4つの異なる状況を、1つの文にまとめたものです。イメージがないか、コマンドがないか、アプリが設定を読めずに自分で終了したか、カーネルが殺したか、のいずれかです。この4つは対処がすべて違い、幸いにもとても低コストな手がかりで区別できます。
終了コードが最初に範囲を絞り込む
終了コード1つで、調査範囲が半分になります。ルールは単純です。128より大きければシグナルで死んだということで、128を引いた値がシグナル番号です。
| コード | 意味 | 最初に見る場所 |
|---|---|---|
| 0 | 正常終了 | アプリが仕事を終えて終了しました。サーバーなら、これも異常です |
| 1 | アプリが出した一般的なエラー | ログの最後の行 |
| 125 | Docker自体のエラー | コマンドのオプションが間違っています |
| 126 | コマンドを実行できない | 実行権限がありません |
| 127 | コマンドが見つからない | ENTRYPOINTのパスの誤記、またはシェルがないイメージ |
| 137 | SIGKILL (128+9) | OOMかどうかを必ず区別します |
| 139 | SIGSEGV (128+11) | ネイティブライブラリのクラッシュ |
| 143 | SIGTERM (128+15) | 正常終了の要求を受けました。事故とは限りません |
137が最も紛らわしいコードです。カーネルのOOM killerが殺した場合もあれば、人がdocker killした場合もあります。区別はState.OOMKilledの1行でできます。
docker inspect dk-err --format '{{.State.ExitCode}} {{.State.OOMKilled}}'
137 true
trueならメモリ上限を上げるか、アプリの使用量を減らす問題で、falseなら誰がなぜ殺したのかを探す問題です。まったく別の調査です。
ログの読み方
コンテナの標準出力と標準エラー出力は、ランタイムが横取りして保存します。そのため、コンテナがすでに死んでいても、docker logsで最後の瞬間を見られます。2つのストリームは混ざって見えますが、実際には分離されているので、シェルのリダイレクトで別々に取り出せます。
docker logs dk-err 2>/dev/null # 표준 출력만
docker logs dk-err 2>&1 1>/dev/null # 표준 오류만
docker logs --tail 50 -t dk-err # 마지막 50줄에 시각을 붙여서
docker logs --since 10m dk-err # 최근 10분만
時刻(-t)を付けることが重要です。ログ自体に時刻がないアプリが多く、その場合、「このエラーは死ぬ直前のものか、ずっと前のものか」がわかりません。
docker inspectは、1つのJSONに状態のすべてを収めています。診断で実際に使うフィールドは、いくつもありません。
| フィールド | 何がわかるか |
|---|---|
State.Status |
created / running / exited / paused |
State.ExitCode |
アプリが出した値か、シグナルで死んだか |
State.Error |
ランタイムがそもそも起動できなかった理由 |
State.OOMKilled |
137がOOMによるものか |
State.StartedAt / FinishedAt |
何秒で死んだか。即死なら設定の問題です |
RestartCount |
静かに再起動を繰り返していないか |
StartedAtとFinishedAtの差が1秒未満なら、アプリのロジックではなく起動条件の問題です。設定ファイル、環境変数、ポートの衝突の順に確認します。
現場での姿
最もよく踏む落とし穴は、ログが空の場合です。原因は3つです。
- アプリがファイルにログを書いています。コンテナでは、ログをファイルではなく標準出力に出すのが原則ですが、この決まりが守られないと、診断ツール全体が無力になります。一時的な対処として
docker execでファイルを読むことはできますが、コンテナが死ぬとそれもできません。 - バッファリングに閉じ込められています。Pythonは、標準出力が端末でない場合、ブロックバッファリングを行います。4KBが溜まる前に死ぬと、その中のログがまるごと消えます。
PYTHONUNBUFFERED=1やpython -uで無効にします。Nodeはデフォルトでバッファーなし、JavaはSystem.outが行単位なので、たいていは問題ありません。 - ログドライバーが違います。
--log-driverがnoneであるか、外部のログ収集ツールに設定されていると、docker logsは何も表示できません。
2つ目の落とし穴は、シェルがないイメージです。distrolessやscratchベースのイメージにはshがないため、docker exec -it ... shが動作しません。OCI runtime exec failed: exec: "sh": executable file not foundを見て、「コンテナがおかしい」と判断してはいけません。正常です。
こういうときは、同じネームスペースにツールの入ったコンテナを接続して、中を見ます。
docker run -it --rm --pid container:myapp --network container:myapp nicolaka/netshoot
--pidでプロセスを、--networkでネットワークを共有するため、psとssが対象コンテナのものをそのまま表示します。ファイルシステムは共有されないので、/proc/1/root/を通して見ます。
3つ目は、再起動の繰り返しです。RestartCountが増え続けている場合、docker logsは現在のインスタンスのものしか表示しません。死ぬ直前のインスタンスのログを見る必要がありますが、Dockerには、Kubernetesの--previousのようなオプションがありません。--restartポリシーを一時的にnoに変えて、1回だけ起動させて調査します。
次のラボですること
ログを末尾から切り出して見て、2つのストリームを分離し、死んだコンテナの終了コードとログを並べて原因を特定する練習をします。メモリ上限を低く設定して137を自分で再現し、OOMKilledがtrueと表示されることを確認します。