2026-03-24: 記事ページ 500 エラー

概要

2026-03-24 10:35-10:45 JST (01:35-01:45 UTC) の約10分間、ブログの全記事ページで Failed to fetch article: 500 エラーが発生。Vercel のログ、CloudWatch Logs、CloudWatch メトリクスを突き合わせて原因を特定した。

公開情報に関する注記

本ドキュメントは公開リポジトリに含まれるため、以下の情報はマスクしている。

カテゴリ	マスク表記	説明
AWS リソース	`<dsql-cluster-id>`	DSQL クラスター識別子
AWS リソース	`<lambda-function-name>`	Lambda 関数名
AWS リソース	`<lambda-log-group>`	CloudWatch Logs ロググループ名

エラー発生状況

影響を受けた記事 (確認分)

slug	リクエスト元
`01fqn7vgp6hcejnyhe6k0fs208`	LinkCardBot
`01f07hctzhjcwtdq4h6ew9stk8`	LinkCardBot
`20260108-shuntaka-blog-rearchitecture`	LinkCardBot
`20260201-poem`	LinkCardBot, meta-externalagent
`20251224-reflecting-on-2025`	LinkCardBot, meta-externalagent
`20250116-poem2`	meta-externalagent
`01ezm5k2rt1jm6zbsewm33r0xw`	Chrome (一般ユーザー)
`20230908-js-runtime`	meta-externalagent
`2025022-tech-poem`	Chrome (一般ユーザー)
`01fvkbeq00ejdq4xe38a7ccfb0`	meta-externalagent
`vim-conf-2024`	Chrome (一般ユーザー)
`20230717-lean-devops`	meta-externalagent

記事一覧API (/users/shuntaka/articles?type=tech, ?type=note) でも同様のエラーを確認。

Vercel 側の挙動

ルート /[userName]/articles/[slug] のSSR 中に blog-api へのフェッチが 500 で失敗
getArticleBySlug() と generateMetadata() の両方でエラーが発生（同一リクエストで複数のエラーログが出力される原因）
Vercel のキャッシュが STALE だったため、レスポンス自体は 200 を返しているが内容はエラー

根本原因

DSQL IAM 認証トークンの期限切れ。

背景: DSQL の認証方式

AWS DSQL は固定パスワードをサポートせず、IAM 認証トークン（SigV4 署名付き URL）のみで接続する。トークンのデフォルト有効期限は 15分間。

現在の blog-api (adapter/src/database/mod.rs) は、Axum サーバー起動時に1回だけ IAM トークンを生成し、SQLx の PgPool にパスワードとして固定で埋め込んでいる。Lambda Web Adapter 上ではプロセスが常駐するため、15分を超えるとトークンが期限切れとなり、プールが新規接続を張ろうとした際に access denied で拒否される。

なお、Lambda はリクエストが来ない間プロセスをフリーズ（一時停止）し、次のリクエスト時に解凍（thaw）して再開する。この際 bootstrap() は再実行されず、メモリ上の状態（トークン、コネクションプール等）がそのまま復元される。フリーズ中は tokio ランタイムのタイマーも停止するため、tokio::time::interval による定期リフレッシュを実装しても、壁時計上の経過時間とタイマーの経過時間にずれが生じる可能性がある。

さらに、SQLx の PgPoolOptions にはコネクションのライフサイクルに関するデフォルト値が存在する。

設定	デフォルト値	挙動
`max_lifetime`	30分	接続の最大生存時間。超過するとプールが接続を閉じて再作成する
`idle_timeout`	10分	アイドル状態の接続がプールに留まれる最大時間。超過すると削除される

本番コードではこれらを明示的に設定しておらず、デフォルトが適用されていた。インスタンス A の時系列で、10:35:54 の正常レスポンス（既存コネクション利用）から 10:36:44 の最初のエラーまで約49秒の間隔があるが、これは idle_timeout により前のリクエスト後にアイドル状態になった接続がプールから除去され、次のリクエスト時に期限切れトークンで新規接続を試みた結果と考えられる。

CloudWatch Logs (`<lambda-log-group>`)

エラー時間帯のログを分析した結果、3つの Lambda インスタンス（ログストリーム）が関与していた。各インスタンスの特定は、CloudWatch Logs のログストリーム名（Lambda インスタンスごとに固有）をキーにして、エラーログと起動ログ（Listening on 0.0.0.0:8080）を突き合わせることで行った。

インスタンス一覧

インスタンス	起動時刻 (JST)	トークン状態（10:35 時点）	役割
A	10:04:10	期限切れ（31分経過）	エラー発生元
B	10:39:53	新規（フレッシュ）	回復に寄与
C	10:40:37	新規（フレッシュ）	回復に寄与

インスタンス A の時系列（エラー発生元）

時刻 (JST)	ステータス	レイテンシ	内容
10:35:54	200	55ms	既存のプール接続で成功（最後の正常レスポンス）
10:36:44	500	567ms	`access denied` — 新規接続がトークン期限切れで失敗
10:37:01	500	577ms	記事一覧 API でも同様のエラー
10:37:37	500	212ms	以降、全リクエストが失敗
...	500	121-988ms	同一エラーが継続（計21件）
10:40:40	500	911ms	インスタンス A 最後のエラー

インスタンス B, C の時系列（回復）

時刻 (JST)	インスタンス	ステータス	レイテンシ	内容
10:39:53	B	—	—	コールドスタート（Listening）
10:40:03	B	200	9,289ms	初回リクエスト成功（コールドスタート含む）
10:40:37	C	—	—	コールドスタート（Listening）
10:40:43	B	200	342ms	正常処理
10:40:44	C	200	7,320ms	初回リクエスト成功（コールドスタート含む）
10:40:46	B	200	213ms	以降、正常に処理
10:40:49	C	200	39ms	以降、正常に処理

全エラーはインスタンス A（起動から32分経過、トークン期限切れ）からのみ発生。インスタンス B, C はフレッシュなトークンで起動し、エラーなく処理を開始した。

CloudWatch メトリクス

Lambda メトリクス (`<lambda-function-name>`)

時刻 (JST)	Invocations	Duration Max (ms)
10:25	1	70
10:30	3	480
10:35	20	9,636
10:40	20	7,427
10:45	15	7,431
10:50	2	62

Lambda Errors = 0: Lambda 自体はクラッシュしておらず、アプリ内でエラーをキャッチして HTTP 500 を返している
Duration が約100倍に急増: 通常 60-70ms → エラー時 7,000-9,600ms（新規インスタンスのコールドスタートが主因）
Throttles = 0: Lambda のスロットリングは発生していない

DSQL メトリクス (`<dsql-cluster-id>`)

時刻 (JST)	TotalTransactions	ReadOnlyTransactions	ComputeTime (ms)
10:25	1	1	2.82
10:30	3	3	8.89
10:35	5	5	239.43
10:40	21	21	63.68
10:45	14	14	49.06
10:50	(no data)	(no data)	(no data)

CommitLatency = 0: 全トランザクションが ReadOnly（SELECT のみ）
10:35 で Invocations=20 に対し Transactions=5: インスタンス A 経由の大半が DSQL 接続に失敗

エラーの流れ

Bot (LinkCardBot / meta-externalagent)
  → Vercel (Next.js SSR)
    → fetch(`${API_BASE_URL}/users/${userName}/articles/${slug}`, { next: { revalidate: 30 } })
      → Lambda (<lambda-function-name>)
        → DSQL 接続試行
          → "unable to accept connection, access denied" ← ★ ここで失敗
        → HTTP 500 レスポンス
      → throw new Error(`Failed to fetch article: 500`)
    → generateMetadata() でも同じ fetch が走り同じエラー
  → エラーページ表示 (ただし STALE キャッシュにより 200 ステータス)

トリガー

Bot (LinkCardBot, meta-externalagent) が短時間に大量の記事ページを同時クロールしたことで Lambda の同時実行数が急増（通常 1-5 → 15-20）。ウォーム状態の Lambda インスタンス（起動から15分以上経過、IAM トークン期限切れ）が新規 DSQL 接続を張ろうとして access denied で失敗した。

なお、LinkCardBot (Mozilla/5.0 (compatible; LinkCardBot/1.0)) は外部サービスではなく、blog-api 自身の Markdown→HTML 変換時にリンクカード用 OGP 情報を取得する際の User-Agent である（apps/blog-api/markdown/src/lib.rs:39）。

対策案

優先度	対策	効果
高	DSQL IAM トークンの定期リフレッシュ	根本原因の解消。バックグラウンドタスクで10分ごとにプール再構築
中	ISR の revalidate を長くする（現在 30 秒 → 5分等）	Bot リクエストの API 到達頻度を削減
中	`robots.txt` でクロール頻度を制御	Bot の同時アクセスを抑制
低	Next.js 側で API エラー時のフォールバック強化	UX の改善（エラー時に古いキャッシュを表示等）