三つのホストがそれぞれ別の時計でログを書いていた
目標
3つのホストがそれぞれ別の時計で記録したログから、オフセットがない表記や意味が違う表記を見分け、基準イベントでホストごとのタイムゾーンオフセットと時計のずれを分けて推定し、すべての行を信頼できるUTCで書き直して、ひっくり返った因果の順序を正しく並べます。
なぜ重要なのか
障害調査で最初に決めるのは、「何が先に起きたか」です。その順序の根拠がログの時刻ですが、その時刻は事実ではなく主張です。オフセットがなければ、どの地域の時計なのか外からはわからず、-00:00はZと意味が違い、オフセットが正確でも、ホストの時計が数秒進んでいれば、原因が結果より後ろに記録されます。時刻を信頼できるようにすることは、分析の準備ではなく、分析そのものです。
ステップ
/root/clock/gen_clock.pyを作成して実行し、/root/clock/raw/の下にapp-seoul.log・db-frankfurt.log・edge-newyork.logを作ってください。/root/clock/stamps.json: ファイルごとに時刻の表記がどう違うか、今すぐUTCに変換できる行が何行かを書いてください。/root/clock/dst_probe.json: 夏時間がある地域のローカル時刻が、消えたり2度来たりすることを、zoneinfoで実測してください。/root/clock/anchors.json: 3つのファイルすべてに痕跡を残したプローブ信号を探してください。/root/clock/skew.json: 基準イベントで、ホストごとのタイムゾーンオフセットと時計のずれを分けて推定してください。/root/clock/fixed.ndjson: すべての行を補正したUTC時刻で書き直し、時間順に並べてください。/root/clock/causality.json: 補正前に原因が結果より後ろに記録されていたリクエストを数え、補正後と比べてください。/root/clock/clock_report.md: 何をどのような根拠で補正したかを、報告書として残してください。
参考
- 補正した
tsは、すべて2026-03-08T06:05:00.200Zの形で書きます。日付と時刻の間に大文字のT、ミリ秒3桁、末尾に大文字のZです。 - 行の時刻を読むルールは、1つに統一します。オフセットが付いていればそのまま読み、なければ、いったんUTCとして読みます。その仮定が正しいかどうかは、基準イベントが判定します。
- Pythonの
strptimeは、%zで-05:00と-00:00の両方を読めます。zoneinfo.ZoneInfoとdatetimeのfoldで、夏時間の区間を扱います。 - タイムゾーンオフセットは15分の倍数です。基準との差を最も近い15分に丸めればタイムゾーンオフセットが出て、余った秒が、そのホストの時計のずれです。
- よくあるミスは、
-00:00をZと同じ意味で読むこと、オフセットのない行をUTCのまま並べること、余った数秒をノイズと見て捨てること、夏時間の切り替え日にオフセットを1種類に固定することの4つです。 - このラボの成果物は、すべて
/root/clock/の下に集めます。セッションが終わると消えるので、重要なものは画面に残しておいてください。
3つのホストのログを再現する
/root/clock/gen_clock.pyを作成して実行し、/root/clockディレクトリの下に、app-seoul.log(65行)・db-frankfurt.log(41行)・edge-newyork.log(61行)を作ってください。
3つのファイルは、それぞれ別のホストが自分の時計で書いたものなので、時刻の表記が違います。1つはオフセットがまったくなく、1つはオフセットを-00:00で付け、1つはタイムゾーンオフセットをきちんと付けます。まず/root/clock/rawを作り、その中に3つのファイルを書きます。
どの行が今すぐUTCに変換できるかを数える
/root/clock/stamps.jsonに、ホスト名(app-seoul・db-frankfurt・edge-newyork)ごとに、lines・offset_style・utc_resolvable・distinct_offsetsを書いてください。offset_styleは、オフセットが1つもなければnone、すべてのオフセットが-00:00なら-00:00、それ以外ならexplicitです。utc_resolvableは、その行だけを見てUTCに変換できる行数です。
原本は、/root/clock/raw/app-seoul.log・db-frankfurt.log・edge-newyork.logの3つです。オフセットが付いている行だけが、その行1つでUTCが決まります。distinct_offsetsは、そのファイルに実際に現れたオフセットの文字列を、重複なしで集めたもので、1つのファイルで値が2種類出るなら、そのウィンドウが何をまたいだのかを考えてみてください。
消える時刻と2度来る時刻を実測する
/root/clock/dst_probe.jsonに、下の6つをこの順序のまま配列で書いてください。各項目はzone・local・count・utcの4つのキーを持ち、countはそのローカル時刻に対応するUTCの瞬間の個数、utcはその瞬間を2026-03-08T08:30:00.000Zの形で昇順に入れた配列です。(1) America/New_York 2026-03-08 02:30:00 (2) America/New_York 2026-03-08 04:30:00 (3) America/New_York 2026-11-01 01:30:00 (4) Asia/Seoul 2026-03-08 02:30:00 (5) Europe/Berlin 2026-03-29 02:30:00 (6) Europe/Berlin 2026-10-25 02:30:00
zoneinfo.ZoneInfoでタイムゾーンを付け、datetimeのfoldを0と1に変えて、2つの候補を作ります。各候補をUTCに変換してから、またそのタイムゾーンに戻したときに、元のローカル時刻と同じになるものだけが本物です。戻ってくるものがなければ、そのローカル時刻は存在せず、互いに違う2つが戻ってくれば、2度来る時刻です。
3つのファイルに一緒に記録された基準イベントを探す
/root/clock/anchors.jsonに、reference_hostをdb-frankfurtとして書き、anchorsには、3つのファイルすべてに現れたprobe=の値ごとに、corr・app-seoul・db-frankfurt・edge-newyorkの4つのキーを入れて、corrの昇順で書いてください。3つのホストの値は、そのファイルに書かれた時刻の文字列のままです。
原本は、/root/clock/raw/app-seoul.log・/root/clock/raw/db-frankfurt.log・/root/clock/raw/edge-newyork.logの3つです。運用スケジューラーが配信したプローブ信号は、probe=SYNC-xxxxとして記録されています。1つのホストにしかない信号は物差しとして使えないので、3つのファイルの共通部分だけを残します。時刻の文字列は、オフセットまで含めて原文のまま入れなければ、あとでたどり直せません。基準は、オフセットを付けてUTCを知らせてくれるホストのうち、時計を信頼できるほうを選びます。
タイムゾーンオフセットと時計のずれを分けて推定する
/root/clock/skew.jsonに、reference_hostとhostsを書いてください。hostsは、ホストごとにzone_offset_minutes・skew_seconds・anchors_usedを持ちます。基準イベントごとに、その行が言っている時刻(オフセットがあればそのまま、なければUTCとして読んだ値)から、基準ホストの時刻を引いた差を求め、その差を最も近い15分に丸めたものがzone_offset_minutes、余った秒がskew_secondsです。
材料は、ステップ4で作った/root/clock/anchors.jsonです。差1つに、2つのものが混ざって入ってきます。文字盤がUTCからどれだけずれているか(タイムゾーンオフセット)と、その時計がどれだけ間違っているか(時計のずれ)です。IANAのタイムゾーンオフセットは15分の倍数なので、この2つを分けられます。基準イベントが複数あると、値がぶれることがあるので、中央値のように1つの値にまとめ、いくつ使ったかをanchors_usedに残してください。
すべての行を信頼できる時刻に書き直す
/root/clock/fixed.ndjsonに、3つのファイルのすべての行を、ts・host・raw_ts・corr・msgとして1行に1つずつ書き、tsの昇順に並べてください。tsは、その行が言っている時刻からzone_offset_minutesとskew_secondsを引いて得たUTCで、2026-03-08T06:05:00.200Zの形です。raw_tsは原文の時刻の文字列、corrはreq=やprobe=の値(なければnull)、msgは時刻のあとに残った本文です。
材料は、/root/clock/raw/の下の3つのファイルと、ステップ5で作った/root/clock/skew.jsonです。補正は、引き算2回です。文字盤がずれた分を引き、時計が間違っている分を引きます。元の文字列を上書きせず、raw_tsとして一緒に残してください。あとで基準を変えたら、最初から計算し直す必要がありますが、原文がなければそれができません。
原因が結果より後ろに記録されたリクエストを数える
/root/clock/causality.jsonに、pairs・inverted_before・inverted_after・examplesを書いてください。pairsは、edge-newyorkとdb-frankfurtの両方に現れたreq=RQ-の値の個数です。inverted_beforeは、補正前(その行が言っている時刻そのまま)で、前段の時刻がデータベースの時刻より遅い件数、inverted_afterは、補正した時刻で数え直した件数です。examplesは、補正前に逆転していた値のうち、昇順で先頭の3つです。
補正した時刻は、ステップ6で作った/root/clock/fixed.ndjsonにすでにあり、補正前の時刻は、同じファイルのraw_tsで復元できます。前段がリクエストを受け取ったことが原因で、データベースがそのリクエストを処理したことが結果なので、前段の時刻のほうが遅ければ、記録だけを見ると、結果が原因より先に起きたことになります。2つのホストとも、オフセットをきちんと付けているという点が、このステップの核心です。
何をどのような根拠で直したかを残す
/root/clock/clock_report.mdに、## 시계가 어떻게 어긋나 있었나、## 무엇을 기준으로 삼았나、## 보정한 뒤 무엇이 달라졌나、## 다음에 받을 때의 요구사항(韓国語の見出しは、順に「時計がどのようにずれていたか」「何を基準にしたか」「補正したあと何が変わったか」「次に受け取るときの要件」という意味です)の4つの節で書いてください。補正した全レコード数・app-seoulのzone_offset_minutes・補正前の逆転件数を、数字で含める必要があります。
材料は、/root/clock/skew.json・/root/clock/fixed.ndjson・/root/clock/causality.jsonです。補正値は測定値ではなく、あなたが基準イベントで立てた仮定なので、その仮定が何に頼っているかも一緒に書かなければ、次の人がたどり直せません。最後の節には、顧客に何を求めれば、この推定がまるごと不要になるかを書きます。