サイレント障害3層を解剖｜200で返るのに動かないバグ実録

サイレント障害3層を解剖｜200で返るのに動かないバグ実録
まずは症状を整理する
第1層: catchブロックがdebugログで例外を握り潰していた
第2層: DBに残った無効なAPIキーが.envフォールバックを上書きしていた
第3層: fire-and-forgetがdeleteせず候補を積み上げていた
3つの失敗に共通していたこと
今回の経験から得られた3つの学び

サイレント障害3層を解剖｜200で返るのに動かないバグ実録

バックエンド開発に10年携わる筆者が、最も頭を悩ませる問題の一つに「エラーが出ないバグ」があります。

ログに赤い警告が出ていれば「ここが怪しい」と特定できますし、例外がスローされればスタックトレースが有力な手掛かりとなります。また、5xxエラーが返されれば、原因の特定はほぼ確実です。しかし、APIがHTTPステータスコード200を返し、あたかも正常に処理が完了したかのように振る舞いながら、実際には期待通りの動作をしていない――これほど厄介なものはありません。この現象を、私たちはサイレント障害（silent failure）と呼んでいます。

先日、自作の記事管理システム（Hono + SQLite + React構成）で、まさにこのサイレント障害に遭遇しました。

画像の「再生成」ボタンを押しても、候補が全く切り替わらない。ローディング表示は正常に完了し、エラーを示すトーストや赤い表示も一切出ない。

この不可解な現象を深く掘り下げていくと、原因は単一のものではありませんでした。設計段階ではそれぞれが合理的に見えた選択が、運用中に見事に重なり合い、3つのサイレント障害として顕在化していたのです。再発防止のための備忘録として、筆者が踏んだ順にその全貌を記録しておきます。

まずは症状を整理する

対象: POST /articles/:id/regenerate-slot — 記事の1スロット分（3枚）の候補画像を再取得するAPI。
期待される動作: 3枚の新しい候補画像がデータベースに保存され、UIに表示される。
実際の動作: APIはHTTPステータスコード200を返すが、UIには古い候補が表示されたまま。
サーバーログ: 初期段階では、WARNやERRORレベルのログは一切見当たらなかった（実際には出力されていたものの、視認できていなかった）。

クライアントはHTTPステータスコード200を受け取り、正常完了と判断します。一方、サーバー側も処理が問題なく完了したと認識するため、両者間で齟齬が生じ、何も起きていないかのように見えてしまうのです。まさにサイレント障害の典型例でした。

第1層: catchブロックがdebugログで例外を握り潰していた

筆者の自作システムで画像候補を3枚取得する処理は、次のような構造で実装されていました。

private async fetchCandidates(
  imageProvider: ImageProvider,
  keywords: ImageKeywordResult,
): Promise<ImageResult[]> {
  const candidates: ImageResult[] = [];
  for (let i = 0; i < this.candidatesPerSlot; i++) {
    try {
      const image = await imageProvider.getImage({ query: keywords.query, ... });
      candidates.push(image);
    } catch (error) {
      this.logger.debug({ error, index: i }, "画像候補の取得に失敗（スキップ）");
    }
  }
  return candidates;
}

この設計の意図は、「たとえ1枚の画像取得が失敗しても、残りの候補は有効活用する」というものでした。しかし、問題はcatchブロック内でdebugレベルのログが出力されていた点にありました。

本番運用環境では、ログレベルは通常infoに設定されていることが多く、debugレベルの行は一切出力されません。結果として、3枚すべての画像取得が失敗していたにもかかわらず、返り値は[]（空の配列）となり、呼び出し側は「今回は0件だったな」と判断して処理を続行していました。ルート側のAPIも、候補が0件であることは技術的にはエラーではないと判断し、200 OKを返していたのです。

裏側でエラーが発生しているにもかかわらず、ログにすらその形跡が残らない。これが第1層のサイレント障害でした。

対策:
この問題を解消するため、ログレベルをwarnに引き上げました。

} catch (error) {
  this.logger.warn( // debugからwarnに格上げ
    { error: error instanceof Error ? error.message : String(error), index: i },
    "画像候補の取得に失敗（スキップ）",
  );
}

これにより、少なくとも「裏で何らかの失敗が起きている」という事実が、tail -f logs/server.logで監視しているログから視認できるようになりました。

深掘り: 外部APIを呼び出す処理のcatchブロックでは、安易にdebugレベルのログで例外を握り潰すべきではありません。本番環境でinfoレベル以上のログしか監視しない運用体制であれば、debugログは事実上「存在しない」のと同じです。最低でもwarnレベルで出力し、異常事態を確実に検知できる設計にすることが不可欠です。

第2層: DBに残った無効なAPIキーが.envフォールバックを上書きしていた

第1層の対策としてログレベルをwarnに上げて再実行したところ、今度はサーバーログに以下のメッセージが頻繁に出力されるようになりました。

"API key not valid. Please pass a valid API key."

これはGemini APIからのHTTP 400エラーメッセージで、3枚すべての画像取得が同じ理由で失敗していることを明確に示していました。

しかし、.envファイルに設定しているGEMINI_API_KEYは、curlコマンドで直接APIを叩けば正常に200 OKが返ってくる、有効なキーのはずです。なぜアプリケーション経由では「invalid」と判断されてしまうのでしょうか。

データベースを直接覗いてみると、その答えが明らかになりました。

sqlite> SELECT key, substr(value,1,30) FROM settings WHERE key LIKE 'image.gemini%';
image.gemini_api_key | Z0XPgwVVOkhOQY9u:1RKPWVaq0KbLD...

暗号化されたGemini APIキーが、DBのsettingsテーブルに保存されていたのです。そして、画像プロバイダの初期化ロジックは次のようになっていました。

// DB 設定が空の場合は .env の GEMINI_API_KEY にフォールバック
const apiKey = imageConfig.geminiApiKey || config.geminiApiKey;

imageConfig.geminiApiKeyが空文字であれば.envの値にフォールバックするという設計でした。しかし、実際には空文字ではなく「古くて既に無効になったキー」がDBに存在していました。このため、.envに設定された正しいキーは読み込まれることなく、DBの無効なキーでAPIを叩き続け、結果として400エラーを受け取っていたのです。

これはユーザー目線で見ると最悪の状況です。

.envファイルには正しいキーが設定されている。
DBの設定画面ではAPIキーが表示されない（暗号化されているため、UI上では********のようにマスク表示される）。
にもかかわらず、APIは繰り返し失敗し続ける。

目に見える場所のどこを探しても、問題の所在が全く分からない状態でした。

対策1（応急処置）: データベースの該当行を直接削除し、.envのフォールバックが機能するようにしました。

DELETE FROM settings WHERE key = 'image.gemini_api_key';

対策2（再発防止）: 設定保存時にAPIキーを軽くバリデーションするロジックを追加しました。保存前に一度だけ疎通確認（models.list相当のAPI呼び出し）を行い、失敗した場合は400エラーで保存を拒否するようにしました。

自作システムの設定保存ロジックに以下を追加しました。

// PUT /settings
const candidateGeminiKey = data.image?.geminiApiKey?.trim();
if (candidateGeminiKey) {
  const probe = new GeminiImageProvider(candidateGeminiKey, logger);
  const result = await probe.testConnection();
  if (!result.success) {
    throw new ValidationError(`Gemini API キーが無効です: ${result.message}`);
  }
}

これで「ユーザーがタイプミスしたキーを保存してしまう → 以後ずっと400エラーに悩まされる」というパターンを未然に防ぐことができます。

深掘り: 暗号化して保存する値は、直接目視で確認することができません。だからこそ、保存フェーズで厳格なバリデーションを導入することが極めて重要です。単なる空文字チェックだけでは不十分であり、実際にそのクレデンシャルが有効に機能するかどうかを検証するステップが不可欠と言えるでしょう。

参考: Gemini API キーの取得と管理（Google AI Studio公式ドキュメント）

第3層: fire-and-forgetがdeleteせず候補を積み上げていた

上記2つの問題を修正し、再度再生成ボタンを押すと、今度は画像候補が期待通りに切り替わるようになりました。しかし、今度は別の違和感が目に飛び込んできました。

1つのセクションの候補表示に、なぜか6枚もの画像が並んでいるのです。しかも、「選択中」のバッジは1枚にしか付かず、他の5枚は何度クリックしても選択できません。

UIのグルーピングキーを確認すると、以下のようになっていました。

const key = img.placement === "featured" ? "featured" : `section:${img.sectionHeading ?? ""}`;

placement + sectionHeadingの組み合わせで1スロットを識別し、データベースの選択更新ロジックも同じキーで排他制御を行っています。そのため、同じスロットに6枚の画像が溜まってしまうと、ユーザーが選択できるのはそのうちの1枚だけという状況に陥ってしまっていたのです。

なぜ画像が重複して溜まってしまったのか。データベースを調査すると、同じセクションに対してaltテキストの異なる2バッチの画像が存在していました。

id 176-178  section "出発点..."  alt: クラウドコンピューティング... (古いデータ)
id 188-190  section "出発点..."  alt: MacBook Pro...                 (新しいデータ)

記事の画像生成パイプラインには、画像を挿入する経路が2つ存在していました。

記事作成直後の、バックグラウンドで実行される fire-and-forget経路（insertImagesForArticle）
記事詳細画面の「画像を生成」ボタン経由で、ユーザーが明示的に実行する明示経路（POST /articles/:id/generate-images）

明示経路では、処理の冒頭でdeleteByArticleId(articleId)を呼び出し、「クリーンな状態」にしてから画像を挿入していました。しかし、fire-and-forget経路では、この重要な削除処理が呼ばれていなかったのです。

// POST /articles/:id/generate-images
await deps.articleImageRepo.deleteByArticleId(articleId);    // ← ここで削除している
const result = await deps.imageInsertionService.insertImages(...);

// vs

// 記事作成直後の fire-and-forget
//                                                             ← 削除処理がない！
const result = await deps.imageInsertionService.insertImages(...);

通常のフロー（記事作成 → fire-and-forget完了 → 明示経路で再生成）であれば問題は発生しません。しかし、以下のような並行処理や再実行のパターンで、同じスロットに複数の画像バッチが重複して保存されてしまう事態が発生しました。

記事作成中のfire-and-forgetが完了する前に、ユーザーが明示経路を実行する。
記事本文をLLMで書き直した後、再度fire-and-forgetが実行される。

対策は、たった1行のコード追加で解決しました。サービス層のinsertImages()メソッド冒頭でdeleteByArticleIdを呼び出すように変更し、どの経路から呼ばれても常にクリーンな状態から処理を開始するようにしました。

自作システムのinsertImagesメソッドを以下のように修正しました。

async insertImages(articleId, content, ...) {
  if (!imageProvider || imageSettings.provider === "none") {
    return { content, featuredImageUrl: null, insertedCount: 0 };
  }

  // どの経路から呼ばれても常にクリーンスレートな状態から始める
  await this.articleImageRepo.deleteByArticleId(articleId);

  // ...通常の挿入処理...
}

深掘り: クリーンアップ処理を「呼び出し側の責任」として任せていた場合、呼び出し元が複数存在すると、そのうちのいずれかが必ずその責任を忘れてしまうものです。共通のクリーンアップ処理は、サービス層など、より低レイヤーで一元的に実行されるように設計すべきであり、これにより処理の信頼性と整合性を高めることができます。

3つの失敗に共通していたこと

改めて今回遭遇したサイレント障害を並べてみると、すべて「ユーザーにもログにも現れない失敗」という共通点がありました。

層	失敗場所	見えなかった理由
1	`catch` ブロック	ログレベルが `debug` だったため、本番環境で出力されなかった
2	DB 設定値	暗号化されており、UIやログから目視で確認できなかった
3	fire-and-forget	UIへの通知経路がなく、クリーンアップ処理が欠けていた

これらは、サイレント障害を引き起こしやすい要素の典型例が揃っていたと言えます。意識してこのような設計にしたわけではなく、それぞれ別のコミットで「安全側に倒した設計」や「効率化」を選んだ結果、これらが複合的に作用することで、デバッグするまでその存在すら感知できない問題へと発展してしまったのです。

今回の経験から得られた3つの学び

今回の経験から得られた重要な学びは以下の3点に集約されます。

外部API呼び出しのcatchログレベルは最低warnに設定する: 本番環境でinfoレベル以上のログしか監視しない場合、debugログは事実上存在しないのと同じです。異常を検知できるよう、適切なログレベルを設定しましょう。
クレデンシャルは保存時に有効性をバリデーションする: 暗号化された値は目視で確認できないため、保存フェーズでその有効性を検証し、データの品質を担保することが極めて重要です。
クリーンアップ処理はサービス層に一元化する: 複数の呼び出し元が存在する場合、クリーンアップの責任を各呼び出し元に委ねると、必ずどこかで処理漏れが発生します。共通のクリーンアップ処理は、一元的に実行されるサービス層などの低レイヤーに配置すべきです。

後から振り返ると当たり前に思えることばかりですが、実装時はそれぞれ異なるタイミングで導入されたため、これらが組み合わさってサイレント障害を生み出すことは予想できませんでした。修正コード自体は合計で20行程度でしたが、問題の根深さはコードの行数とは関係ないという典型的な事例と言えるでしょう。

関連するハマりポイント: 同じプロジェクトの画像生成に関連して、「Gemini Nano Banana（社内呼称）の候補3枚がほぼ同じ絵になる問題」にも遭遇しました。こちらは別記事で詳しくまとめる予定です。

もし似た症状（エラーが出ないのに画像が切り替わらない、APIキーが無効なのに.envは正しい、など）でお困りの方がいらっしゃいましたら、本記事の3層のうち当てはまるものがないか確認してみてください。

この記事があなたの開発の一助となれば幸いです。ぜひX（旧Twitter）でシェアしてください！ご意見やご質問はコメント欄、またはX（@your_account_name）で直接お聞かせいただけると嬉しいです。