--- title: 実践デバッグ tags: author: [ashphy](https://www.docswell.com/user/ashphy) site: [Docswell](https://www.docswell.com/) thumbnail: https://bcdn.docswell.com/page/GEWG6K21J2.jpg?width=480 description: カンに頼らずに原因を見つけよう published: July 10, 26 canonical: https://www.docswell.com/s/ashphy/K27W7N-debug --- # Page. 1 ![Page Image](https://bcdn.docswell.com/page/GEWG6K21J2.jpg) 実践デバッグ カンに頼らずに原因を見つけよう ashphy @ashphy@mstdn.nere9.help 2026-07-03 # Page. 2 ![Page Image](https://bcdn.docswell.com/page/47ZLYZDXJ3.jpg) メールが約500マイルより遠くに送れない。 それ以上は無理なんだ。 統計学科の学科長 02 # Page. 3 ![Page Image](https://bcdn.docswell.com/page/YJ6WDZ1PJV.jpg) 統計の先生なので調べてみた 届く 届かない ✗ プロビデンス 〜580マイル ✓ プリンストン 〜400マイル ✗ メンフィス 〜600マイル ✓ ニューヨーク 〜420マイル チャペルヒル 大西洋 半径 約520マイル 03 # Page. 4 ![Page Image](https://bcdn.docswell.com/page/GJ5M3W4PJ4.jpg) 500マイルの正体 設定ファイルのバージョン更新時に、SMTP接続のタイムアウト値が0に なっていた タイムアウト0だが、このマシンの負荷では接続試行を約3ミリ秒で打ち切る 3ミリ秒 × 光速 ≒ 約558マイル タイムアウトの秒数が、光速を介して物理的な距離に化けていた こんな一見手のつけようがないバグに、どう立ち向かえばいいだろう？ 04 # Page. 5 ![Page Image](https://bcdn.docswell.com/page/LE3W64G6E5.jpg) 原因の場所を絞り込む # Page. 6 ![Page Image](https://bcdn.docswell.com/page/8EDKVQ1M7G.jpg) とある業務アプリ 「受注 #10238 の割引額がおかしい」と問い合わせが来た 📦 受注管理システム 📋 受注一覧 📊 レポート 👥 顧客管理 ⚙️ 設定 👤 田中太郎 受注一覧 受注ID #10238 #10237 #10236 #10235 顧客名 鈴木商事 高橋物産 佐藤工業 山田電機 商品 ラックマウントキット 冷却ファンユニット ネットワークスイッチ UPS バッテリー 金額 ステータス ¥121,200 新規 ¥156,000 出荷済 ¥890,000 新規 ¥340,000 処理中 06 # Page. 7 ![Page Image](https://bcdn.docswell.com/page/V7PKVLQQJ8.jpg) 1つのリクエストが通る経路 確認画面を開いてから金額が表示されるまで、これだけの経路を通っている ▼ 症状が見えるのはここ ブラウザ 画面の表示 ブラウザの中 JSエラー 状態管理のバグ API Gateway リクエスト中継 ブラウザ ⇄ Gateway 名前解決の失敗 TLS証明書の期限切れ Gateway ⇄ APIサーバ ルーティング設定ミス タイムアウト APIサーバ データベース 業務ロジック APIサーバの中 ロジックのバグ 例外ハンドリング漏れ データ保存 APIサーバ ⇄ DB スロークエリ 接続プール枯渇 見るべき範囲が多いとき、どうしたらいいだろう？ 07 # Page. 8 ![Page Image](https://bcdn.docswell.com/page/2JVVZQ5PJQ.jpg) 二分探索の考え方 怪しい範囲を毎回半分に割る。これを繰り返すだけで、原因の場所に たどり着ける 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 → 特定! 4回の観測で、16箇所から1箇所に絞れる（log2 n） ​ 08 # Page. 9 ![Page Image](https://bcdn.docswell.com/page/5EGL4W6QJL.jpg) では、この経路のどこで切るか？ 経路上のどのポイントでも、問題は起こりうる まず、フロントエンドとバックエンドの境界で切る ブラウザ 画面の表示 ブラウザの中 JSエラー 状態管理のバグ API Gateway リクエスト中継 ブラウザ ⇄ Gateway 名前解決の失敗 TLS証明書の期限切れ Gateway ⇄ APIサーバ ルーティング設定ミス タイムアウト APIサーバ 業務ロジック APIサーバの中 ロジックのバグ 例外ハンドリング漏れ データベース データ保存 APIサーバ ⇄ DB スロークエリ 接続プール枯渇 09 # Page. 10 ![Page Image](https://bcdn.docswell.com/page/4JQYG34W7P.jpg) 仮説を立てて検証する 仮説 フロントエンドの問題であれば、APIの応答には正しい金額が入っているはずだ Elements Console Network Sources Performance Status Method URL Type Time 200 GET /api/config json 23 ms 200 GET /api/users/me json 45 ms 200 GET /api/orders/10238 json 52 ms Headers Preview Response { "orderId": 10238, "subtotal": 120000, "discount": 0, "shipping": 1200, "total": 121200 } レスポンスで割引額が0円。バックエンドを調べれば良い。 10 # Page. 11 ![Page Image](https://bcdn.docswell.com/page/K74W51Q1E1.jpg) 次はどこで切るか？ 原因はバックエンド以降に絞れた。同じように、残った範囲を半分に切る 次は、APIサーバで切る ブラウザ 画面の表示 ブラウザの中 JSエラー 状態管理のバグ API Gateway リクエスト中継 ブラウザ ⇄ Gateway 名前解決の失敗 TLS証明書の期限切れ Gateway ⇄ APIサーバ ルーティング設定ミス タイムアウト APIサーバ 業務ロジック APIサーバの中 ロジックのバグ 例外ハンドリング漏れ データベース データ保存 APIサーバ ⇄ DB スロークエリ 接続プール枯渇 11 # Page. 12 ![Page Image](https://bcdn.docswell.com/page/LJ1YWGP5EG.jpg) バックエンド内部の切り分け 同じ手順をもう一度。仮説を立てて、ログの観測で検証する 仮説 原因がAPIサーバの外（GatewayやDB）にあるなら、サーバに出入りする 値が壊れているはずだ app.log — api-server 2024-01-15 14:23:01 INFO GET /api/orders/10238 - started 2024-01-15 14:23:01 INFO Params: orderId=10238, coupon=SAVE10 ✓ 届いたリクエストは正しい → Gatewayは無実 2024-01-15 14:23:01 INFO Query: SELECT ... FROM orders → subtotal=120000 から返る値も正しい → DBは無実 ✗ 出ていく時点で、もう壊れている 2024-01-15 14:23:01 INFO Query: SELECT rate FROM coupons WHERE code='SAVE10' → 0.10 2024-01-15 14:23:01 INFO GET /api/orders/10238 - 200 OK (total=121200) ✓ DB 仮説は棄却 —— 入ってくる値も、DBから返る値も正しい。壊れた金額は、APIサーバの中で 生まれている 「APIサーバのコードの中」まで絞れた 12 # Page. 13 ![Page Image](https://bcdn.docswell.com/page/GJWG6K2W72.jpg) コードの中を絞り込む # Page. 14 ![Page Image](https://bcdn.docswell.com/page/4EZLYZD273.jpg) コードを全部読むか？ 関係するコードはおよそ10,000行。さて、どこから読む？ 1行ずつ、全部読む — 500行読んでも、まだ全体の5% 10,000 境界で観測して、半分に絞る 0 1 2 3 4 5 6 7 8 9 10 11 12 13 10,000 5,000 2,500 1,250 625 312 156 78 39 19 9 4 2 1 観測13回でたどり着ける（log₂ 10,000 ≒ 13）。二分探索の数直線と同じ 14 # Page. 15 ![Page Image](https://bcdn.docswell.com/page/Y76WDZ367V.jpg) ステップオーバーで境界を観測する 関数の中身には入らない。呼び出しの前後で、戻り値だけを確かめる ▶ 続行 ↷ ステップオーバー ⤵ ステップイン ⤴ ステップアウト 1 function calculateOrderTotal(order) { 2 const subtotal = sumItems(order.items); 3 const discount = applyDiscount(subtotal, order); 4 const shipping = calcShipping(order); 5 return subtotal - discount + shipping; デバッグ中 — orderService.js 想定どおり discount = 0 ✗ 期待は 12000 subtotal = 120000 ✓ もう見なくていい 6 } 小計までは正常 sumItems は想定どおりの値を 返している applyDiscount が壊れた値を返した 犯人の関数はここ。calcShipping 以降は調べる必要すらない 15 # Page. 16 ![Page Image](https://bcdn.docswell.com/page/G75M3WL574.jpg) ステップインで絞り込む 犯人の関数の中に入って、同じことをもう一度やるだけ sumItems 観測済み、正常 applyDiscount ここで値が壊れた calcShipping 見なくていい ⤵ ステップイン（拡大する） クーポン適用 顧客ランク割引 上限チェック 金額計算 この中で、また出入り口の値を観測して絞る ↷ ステップオーバー ⤵ ステップイン 関数を箱のまま扱い、境界で観測して範囲を絞る 箱を開けて、さらに絞り込む 16 # Page. 17 ![Page Image](https://bcdn.docswell.com/page/9J29ZQLGER.jpg) 関係のある行だけを追う 壊れていた値から、影響する行だけを逆にたどる。全部は読まない 戻り値から逆にたどる 戻り値 ← amount ← rate。rate に触らない行は読まなくていい 見つけた 「併用不可」を「割引なし」と 実装していた。割引 ¥0 の正体 discountService.js — applyDiscount function applyDiscount(subtotal, order) { const started = Date.now(); let rate = 0; if (order.coupon) { metrics.increment("coupon.used"); logger.info("coupon: " + order.coupon.code); rate = order.coupon.rate; // 0.10 } const customer = findCustomer(order.customerId); updateLastAccessed(customer); if (customer.isPremium) { rate = order.coupon ? 0 : PREMIUM_RATE; // 併用不可 } if (rate > MAX_RATE) rate = MAX_RATE; const amount = subtotal * rate; metrics.timing("discount", Date.now() - started); notifyCampaign(order); return Math.floor(amount); } プログラムスライシングで変数の流れを追う 17 # Page. 18 ![Page Image](https://bcdn.docswell.com/page/DEY4RWQGJM.jpg) AIとの協調 # Page. 19 ![Page Image](https://bcdn.docswell.com/page/VJNYD9K878.jpg) ある日、デプロイが失敗した 2026年6月8日の昼、CI/CDのTerraformデプロイが突然失敗した CodeBuild — build log [Container] 2026/06/08 03:08:52 Running command make stg-apply Plan: 5 to add, 16 to change, 1 to destroy. ╷ │ Error: reading Lambda Function (stg-app-foo) code signing config: │ operation error Lambda: GetFunctionCodeSigningConfig, https response error │ StatusCode: 403, api error InvalidSignatureException: Signature not yet current: │ 20260608T030924Z is still later than 20260608T001557Z (20260608T001057Z + 5 min.) ╵ make: *** [stg-apply] Error 1 [Container] 2026/06/08 03:09:45 Phase complete: BUILD State: FAILED 原因はどこにあるでしょう？ 19 # Page. 20 ![Page Image](https://bcdn.docswell.com/page/YE9PG2VXJ3.jpg) まず、ログのエラーだけを読む 数百行のログを全部は読まない。最初に拾うのは Error だけ Error はこの2ブロックだけ plan差分やビルドの定型出力は、 いまは読まなくていい ︙ ︙ build log — 数百行 ~ merge_pdf = { Parameters = { Payload = { ... } } } # (6 unchanged attributes hidden) + resource "aws_security_group_rule" "lambda_egress_sqs" { + description = "Allow HTTPS to SQS VPC endpoint" + from_port = 443 （Terraformのplan差分が延々と続く） Plan: 5 to add, 16 to change, 1 to destroy. │ Error: reading Lambda Function (stg-app-foo) code signing │ config: ... api error InvalidSignatureException ... │ Error: reading Lambda Function (stg-app-bar) latest │ version: ... api error InvalidSignatureException ... make: *** [stg-apply] Error 1 [Container] 2026/06/08 03:09:45 Phase complete: BUILD State: FAILED 20 # Page. 21 ![Page Image](https://bcdn.docswell.com/page/GE8DV5P9ED.jpg) ログを「読む」とは？ 目に映っていることと、読めていることは違う 目に入れた スクロールして全体を眺めた。 ≠ 読んだ 何が・いつ・どの順で起きて、 どう失敗したかを言葉にできる 起こっている事象を、他人に説明できる状態になること 21 # Page. 22 ![Page Image](https://bcdn.docswell.com/page/LELM5Y1M7R.jpg) エラーメッセージを分解して読む 英語で長いが、区切って読めば1つずつは難しくない リクエストの署名が不正 「署名がまだ現在になっていない」＝ 署名の時刻が未来すぎる 署名に埋め込まれた時刻＝ クライアントの時計（日本時間 12:09） 受理できる上限＝ サーバーの時計＋5分（日本時間 9:10） クライアントは 12:09、サーバーは 9:10 —— 約3時間食い違っている api error InvalidSignatureException Signature not yet current: 20260608T030924Z is still later than 20260608T001557Z (20260608T001057Z + 5 min.) 22 # Page. 23 ![Page Image](https://bcdn.docswell.com/page/4JMY3NW6JW.jpg) AWSのリクエスト署名（SigV4） AWSへのAPIリクエストは、1つずつ「時刻入りの署名」を付けて送られている ① assume-role で認証情報を取得 AWS STS Auth Runtime Service（ARS） 一時的な認証情報を発行 署名と時刻を検証する内部サービス CodeBuild コンテナ AWS APIエンドポイント クライアント（Terraform） 署名を検証してから処理する ② リクエストに「いま何時か」を書き込んで署名 x-amz-date: 20260608T030924Z（自分の時計） コンテナの時計 03:09:24 UTC（日本時間 12:09） ずれ 約3時間 ③ 裏の ARS が署名を検証し、 時刻が自分の時計 ±5分以内かを確認 検証サーバー（ARS）の時計 00:10:57 UTC（日本時間 9:10） 23 # Page. 24 ![Page Image](https://bcdn.docswell.com/page/PJR9QDYN79.jpg) 第三の時計と突き合わせる 自分の記憶 12:09 コンテナのログ 03:09 UTC デプロイしたのは 間違いなく昼の 12時すぎ [Container] 2026/06/08 03:09:45 独立した3つの時計が一致 CloudWatch Logs 03:09 UTC 署名検証サーバー 00:10 UTC ログイベントの記録時刻 （AWSの別サービス） ひとりだけ 3時間ずれている AWSの中ですら食い違っている 自分・コンテナ・CloudWatch。全員が「いまは CloudWatchと署名検証サーバーで3時間差。 12:09（JST）」と言っている 狂っているのはAWS側だと確定 検証サーバの時間だけおかしい 24 # Page. 25 ![Page Image](https://bcdn.docswell.com/page/PEXQ51G8JX.jpg) 疑いを確信に変える 仮説 もしCodeBuildの時間がズレていたら、すべてのAPIリクエストが失敗するはずだ CodeBuild — build log aws_iam_role.app: Refreshing state... [id=stg-app-role] aws_s3_bucket.assets: Refreshing state... [id=stg-app-assets] aws_security_group.lambda: Refreshing state... [id=sg-12345678] これらもAWSへの署名付きAPIリクエスト —— 成功している Plan: 5 to add, 16 to change, 1 to destroy. │ Error: reading Lambda Function (stg-app-foo) code signing config: │ api error InvalidSignatureException: Signature not yet current 仮説は棄却 —— 一部のリクエストは通っている。時計がズレたクライアントの署名なら、 1つも通らないはずだ 25 # Page. 26 ![Page Image](https://bcdn.docswell.com/page/3EK9624LED.jpg) ちなみに、AIに聞くとどうなるか このログをそのままAIに渡して「原因を調査して」と頼んだ 🤖 Claude Opus 4.8（実際の回答） 原因: CodeBuildコンテナの時計が実時刻より約3時間進んでおり、AWS APIの SigV4署名タイムスタンプが未来すぎ（許容の5分超）で拒否された。 対策1: まずジョブを再実行する（コンテナ再作成で時計が正常化すれば復旧する）。 対策2: 恒久的にはビルド環境のNTP時刻同期を点検する。 もっともらしい 仕組みの説明も正確 対処まで具体的 自信満々 そして 結論が真逆 26 # Page. 27 ![Page Image](https://bcdn.docswell.com/page/L73W64L675.jpg) ハルシネーションを起こさせるのは人間 AIはデバッグを強力に加速する。だからこそ、責任の所在をはっきりさせておく 1. AIは使わない手はない。ただし、ハルシネーションのリスクは常にある 2. その起きやすさを左右するのはコンテキスト。コンテキストを 与えるのは人間 3. 正しいコンテキストを選び、答えを検証するには、自分自身の システム理解が要る 「AIがあればデバッグを学ばなくていい」の逆。使いこなすには理解が要る 27 # Page. 28 ![Page Image](https://bcdn.docswell.com/page/87DKVQNMJG.jpg) すべてを疑う CPUも計算を間違うことがある 確実な証拠を積み上げていくことが大事 疑って、観測して、確かめる 28 # Page. 29 ![Page Image](https://bcdn.docswell.com/page/VJPKVL5QE8.jpg) まとめ # Page. 30 ![Page Image](https://bcdn.docswell.com/page/2EVVZQPPEQ.jpg) デバッグの原則 1. システムを理解する 開発・運用するシステムを深く理解しよう 2. まず観測する 憶測で手を動かさずに、観測して証拠を集めよう 3. 分割して攻略する すべて見ていては時間が足りない。効率よく絞り込もう 4. 事実を元に考える すべての事実を疑う。確認された事実、推測、憶測を分けて考えよう 5. 仮説を立てて検証する よい仮説は、次の行動を教えてくれる 30 # Page. 31 ![Page Image](https://bcdn.docswell.com/page/57GL4WPQEL.jpg) The Incident Challenge 本番障害をゲーム化したサイト ログ、コード、設定、図、紛らわしい症状が与えられる 制限時間内に根本原因を見つけて直す 「混乱の中で何を見て何を捨てるかの判断力」が試される AIの持ち込みは可。ただし、それでも自分の頭が要る theincidentchallenge.com 腕に覚えがある人はぜひ 31 # Page. 32 ![Page Image](https://bcdn.docswell.com/page/4EQYG32WJP.jpg) 参考文献 # Page. 33 ![Page Image](https://bcdn.docswell.com/page/KJ4W51L171.jpg) おすすめの一冊 デバッグの理論と実践 なぜプログラムはうまく動かないのか Andreas Zeller 著、中田秀基 監訳（オライリー・ジャパン, 2012） 原書: Why Programs Fail, 2nd Edition 今日話した「仮説を立てて、観測で絞り込む」という考え方を、体系立てて 解説している本 差分デバッグやプログラムスライスなど、手を動かすための具体的な技法まで 踏み込んでいる https://www.oreilly.co.jp/books/9784873115931/ 33 # Page. 34 ![Page Image](https://bcdn.docswell.com/page/LE1YWGL57G.jpg) 参考文献 Trey Harris, "The case of the 500-mile email" https://www.ibiblio.org/harris/500milemail.html 大原雄介, "CPU黒歴史 大損失と貴重な教訓を生んだPentiumのバグ" (ASCII.jp, 2013) https://ascii.jp/elem/000/000/757/757002/ AWS, "署名バージョン 4 を使用した AWS API リクエストの署名要素" (AWS IAM ユーザーガイド) https://docs.aws.amazon.com/ja_jp/IAM/latest/UserGuide/reference_sigvsigning-elements.html 34