docker ps を見ると、こうなっていました。
nginx Up 5 days (unhealthy)
backend Up 5 days (healthy)
postgres Up 5 days (healthy)
nginx だけ赤い。 でもサイトは普通に見えていました。記事も表示され、画像も出て、HTTPS も効いています。誰も困っていません。
そのまま5日間放置しました。
この記事は、放置してよかったのかと、実際の原因は何だったかの話です。 原因は、私が最初に疑ったものとは違いました。
いま原因を調べたい場合は、先にチェックの記録を確認する手順へ進んでください。設定を変える前に、Dockerが保存した終了コードや出力を見ます。出力が空の場合の注意も同じ節にあります。
まず疑ったこと ―「重すぎてタイムアウト」は外れました
設定はこうなっていました。
healthcheck:
test: wget -q -O - http://127.0.0.1/
interval: 5s
timeout: 3s
ヘルスチェックは、自分で書いていなくても動いていることがあります。 イメージ側(Dockerfile)に最初から書かれている場合があるためです。いま何が実行されているかは、こう見られます。
docker inspect <コンテナ名> --format '{{json .Config.Healthcheck}}'
設定ファイルではなく、動いているものを見てください。
トップページ全体を、5秒ごとに取得していました。 そのページは約100KBあります。そして制限時間は3秒でした。
「約100KBを3秒以内に返せていないのだろう」と考えました。もっともらしい話です。
実際に叩いてみるまでは。
$ wget -q -O - http://127.0.0.1/
ssl_client: certificate verify failed
$ echo $?
1
タイムアウトではありませんでした。 証明書の検証に失敗していました。
原因は ssl_client: certificate verify failed — 301 と証明書でした
順に追うとこうなります。
1. wget が http://127.0.0.1/ を叩く ← http(暗号化なし)
2. サーバーは「https で来てください」と返す ← 301 リダイレクト
3. wget が https://127.0.0.1/ を追いかける
4. 証明書を確かめる
証明書に書いてある名前 : example.com
いま接続している相手 : 127.0.0.1
→ 一致しない → 失敗
HTTPS を正しく設定したこと自体が、原因でした。
サイトを https に統一するために、http で来た人を全部 https へ送る設定を入れていました。その設定が、自分自身のヘルスチェックにも適用されていました。
証明書は「名前」に対して発行されます。https://example.com と https://127.0.0.1 は、同じサーバーでも別の相手として扱われます。証明書には名前が書いてあり、ふつうはドメイン名なので、IPアドレスで接続すると一致しません。(IPアドレス向けの証明書も発行できるようになりましたが、ふつうのサイト用の証明書には入っていません。)
これは正しい動きです。名前が一致しない証明書を信用したら、証明書の意味がなくなります。
つまり、重かったから失敗していたのではなく、構造的に一度も成功できませんでした。 5日どころか、設定した瞬間から一度も通っていません。
私のローカル環境では起きませんでした
手元の開発環境では、ヘルスチェックは成功していました。
理由は単純で、ローカルには https へのリダイレクトが無いからです。
ローカル : http://127.0.0.1/ → そのまま 200 → 成功
本番 : http://127.0.0.1/ → 301 → https → 証明書で失敗
同じ設定ファイルなのに、結果が逆になります。
「ローカルで動いたから大丈夫」が効かない典型です。本番にだけある仕組み(この場合はHTTPS化)が、本番にだけある失敗を作ります。
直し方
2つ変えました。
① 軽いものを叩く
まず、叩く先を軽くします。ただし、これだけでは本番は直りません(理由は②で書きます)。
test: wget -q -O - http://127.0.0.1/api/health
約100KBのトップページから、15バイトの確認用エンドポイントにしました。
そもそも、5秒ごとにトップページ全体を作らせていたのが無駄でした。1日に換算すると17,000回以上です。自分で自分に仕事をさせていました。
確認用のエンドポイントが無い場合は、何か軽いものを1つ用意してください。中身は ok の2文字でも構いません。「アプリが返事できる状態か」が分かれば十分で、トップページである必要はありません。
② 本番だけ、証明書の検証を外す(いちばん手軽)
①の http のままでは、本番は直りません。 さっき書いた301リダイレクトは、どのパスにもかかるからです。
http://127.0.0.1/api/health → 301 → https://127.0.0.1/api/health → 証明書不一致 → 失敗
軽くはなりましたが、赤いままです。
# 本番用のファイルだけ
test: wget --no-check-certificate -q -O - https://127.0.0.1/api/health
最初から https で叩けば、リダイレクトが起きません。 そのうえで、127.0.0.1 に対する証明書の不一致を承知のうえで無視します。
ベースには①、本番用のファイルには②、という形になります。同じ項目を、ファイルを分けて書き分ける話は別の記事に書きました。書き分けたつもりで書けていないという失敗を、私はそこでもやっています。
→ docker-compose.prod.yml が効かない — 本番が開発モード
③ そもそもリダイレクトさせない(根本的)
②が必要になるのは、http で叩くとリダイレクトされるからでした。 確認用のパスだけリダイレクトの対象外にすれば、証明書がそもそも登場しません。
/api/health だけは https へ転送しない
→ http のまま 200 が返る
→ 証明書を確かめる場面が無い
→ 「外すかどうか」を判断する必要も無い
無料の証明書を、サーバーで http を受け取る方式で自動更新しているなら、同じ形の例外がもう入っているはずです。更新のときにサーバーが /.well-known/acme-challenge/ を http で受け取る必要があるので、その1本だけはリダイレクトから外してあります。そこに1本足すだけです。
DNS のレコードで証明する方式を使っている場合は、この例外がありません。探しても見つからなければ、そちらの方式かもしれません。
そして③にすると、ベースと本番で書き分ける必要がなくなります。 どちらも http://127.0.0.1/api/health のままでよくなるからです。書き分けないで済むなら、書き分けを間違えることもありません。
②のほうが手軽で、③のほうが確実です。 私は②で直しました。③に気づいたのは、これを書いていてです。
⚠️ 間隔を変えたら、回数も見直してください
ここで、もう1つ考えることがあります。
interval: 5s
retries: 20 # 20回連続で失敗したら unhealthy
5秒 × 20回 = 約100秒で異常と判断される設定でした。
間隔だけを 30 秒に伸ばすと、こうなります。
30秒 × 20回 = 10分
異常に気づくまで10分かかるようになります。 負荷は減りましたが、反応が鈍くなりました。
回数のほうも減らして、元と同じくらいに戻します。
interval: 30s
retries: 3 # 30秒 × 3回 = 約90秒
ところで、この2つは Docker の既定値と同じです。
interval 既定 30s
retries 既定 3
「5秒ごとに20回」は、私が自分で決めた値でした。 そして調整して戻ってきた先が、何も指定しなかったときの値でした。
既定値には理由があります。 変えるなら、変える理由のほうを説明できる必要があります。
片方だけ変えると、静かに別のものが悪くなります。「軽くする」つもりの変更が、「気づくのが遅くなる」変更になっていました。
起動直後は starting と出ます
直したあと、起動してすぐ見ると health: starting と出て焦ります。
Docker の最初のチェックは、間隔の時間が経ってから走ります。 30秒間隔にしたので、しばらくは判定前です。異常ではありません。
なお start_period を設定していると、その間だけ短い間隔で走るという仕組みが新しめの Docker にあります。私は自分の環境でそこまで測っていませんので、「最初の30秒は必ず判定前」とは書きません。正確に知りたければ、記録を見てください。さっきの docker inspect の出力に、実行された時刻が1回ずつ入っています。
いちばん怖いのは、赤い表示に慣れることです
直したあとの表示です。
nginx Up 17 seconds (healthy)
frontend Up 23 seconds (healthy)
backend Up 47 hours (healthy)
サイトの動きは、直す前と後で何ひとつ変わっていません。 直す前も正常に見えていました。
では何が変わったか。赤が意味を取り戻しました。
5日間 (unhealthy) を見続けた私は、その表示を「そういうもの」として扱うようになっていました。もし6日目に本当に壊れていたら、同じ赤を見て、同じように無視していたはずです。
警告が常に出ている状態は、警告が無い状態より危険です。 無いなら「無い」と分かりますが、常にあるものは見えなくなります。
これは「アラート疲れ」と呼ばれる、よく知られた現象です。私の感想ではありません。鳴り続ける警報は、鳴らない警報より危険になる——病院の機器でも同じことが問題になっています。
個人開発のサーバーでも、同じことが起きます。見ているのが自分ひとりなら、なおさらです。
まとめ
表示は赤い。でもサイトは動いている → コンテナは止まらないので、動き続ける
疑ったこと(重すぎる) → 外れた
実際 → 301 → https → 証明書の名前が一致しない
ローカルでは → リダイレクトが無いので成功する
直し方 → 軽いものを叩く + 本番だけ検証を外す
一緒に見直す → 間隔を変えたら回数も
このサイトでは「動いているのに壊れている」話を何度か書きました。これはその逆で、壊れていないのに壊れて見えていた話です。
どちらも、表示と実態がずれています。 そしてずれたまま放置すると、表示が使えなくなります。
次にやること
いま何かをコンテナで動かしているなら、この順に見てください。
- 赤いものがあるか
docker compose ps
- その理由は、もう記録されています
docker inspect <コンテナ名> --format '{{json .State.Health}}'
チェックの標準出力・標準エラーを保存し、docker inspect で参照できる仕組みは、DockerのHEALTHCHECK仕様にも記載されています。ログを人に見せるときは、接続先や認証情報が含まれていないかを確認してください。
コンテナ名は docker compose ps の出力に出ています。Compose が付ける名前は
<プロジェクト名>-<サービス名>-<番号>(例 myapp-nginx-1)で、サービス名だけでは引けません。
- それでも分からなければ、手で実行してみる
docker compose exec <サービス名> wget -q -O - http://127.0.0.1/
サーバーを借りるところから始める場合は、先に読んでおくと詰まりにくい記事があります。
設定ファイルを重ねて使っているなら、こちらも同じ種類の話です。
