その 504 は誰も見ていない ― 生ログに UA を一列足したら、踏んでいたのは Cloudflare 内部だった

前回、GA4 に映らない 5xx を Cloudflare の GraphQL 集計 API で拾うところまでやった。そこでの結論はこうだった。

504 が / /about/ /projects/ /tags/* と満遍なく出ている。 特定ページのバグではなく、サイト全体が断続的にタイムアウトしている ―― つまり基盤側の問題だ。

この診断は間違っていた。 本記事はその訂正である。

間違えた原因も単純で、集計 API は「どのステータスがどの URL で何件」までしか答えない。誰が踏んだのかを聞いていなかった。生ログを取って userAgent を一列足したら、5 分で結論がひっくり返った。

TL;DR

• 9 日ぶんの生ログで 504 は 307 件。その 100% が Cloudflare の Early Hints による内部リクエスト（UA: bastion early hints / nginx-ssl early hints）。実ユーザーの UA はゼロ
• つまりユーザー影響は無い。「サイト全体が断続的にタイムアウトしている」は誤診だった
• 一方 522 は本物。71 件中 66 件が MobileSafari、63 個の異なるアドレスから。こちらは実害
• 生ログは Enterprise 限定だと思っていたが、Logpush（配信）が Enterprise なだけで、GraphQL からの照会は無料プランでも通る
• 無料プランのログ保持は 8 日。それより前は取得手段が無い

課題：件数は分かるが、誰かが分からない

集計 API（httpRequestsAdaptiveGroups）が返すのは次元ごとの件数だ。「504 が 43 件」「/static/favicons/site.webmanifest で 30 件」までは分かる。

分からないのは 3 つ。

1. 散発か集中か。 24 時間を 1 つに畳んでいるので、43 件が一日に散らばっているのか 5 分間に集中したのかが区別できない。前者は慢性、後者はデプロイ事故で、対応が全く違う
2. 誰が踏んだか。 ブラウザなのかクローラーなのか
3. 本当にユーザーが困っているのか

3 番目が本丸だ。エラーが出ていることと、誰かが困っていることは別である。

選択肢：生ログをどう手に入れるか

前回の記事で「生ログは Enterprise 限定」と書いたが、それは Logpush という配信プロダクトの話だった¹。同じデータを GraphQL の httpRequestsAdaptive（Groups が付かない方）から照会するぶんには、無料プランでも通る。集計版しか試していなかったので気づかなかった。

構成はこうした。

Cloudflare GraphQL ──15分毎──> EC2 (cron) ──> S3 (NDJSON.gz, 日時パーティション)
                                                    │
                                                    └──> DuckDB (httpfs で直読み)

手を動かす：3 つの制約が実測で出た

ドキュメントを読んでいても出てこず、叩いて初めて分かったものを挙げる。

① 約 20 分の反映遅延

「直近 15 分」を取りに行くと必ず 0 件になる。最新レコードが常に 20 分ほど過去に留まる。取得窓を 30 分ずらして解決した。

これは静かに壊れる類の罠で、素直に実装していたら空ファイルを書き続けながら正常に見えていた。

② limit は最大 10000

超えると弾かれる。このサイトは 24 時間で約 1100 行なので余裕はあるが、上限に達した場合は取りこぼしなので警告を出すようにした。

③ 使えないフィールドが 1 つでも混ざるとクエリ全体が落ちる

該当フィールドだけ無視されるのではなく、リクエスト全体がエラーになる。無料プランで弾かれたのは以下。

botScore, rayName, edgeResponseBytes, originIP, originASN,
cacheReserveUsed, clientRefererHost

1 つずつ検査して 19 フィールドを確定させた。なお verifiedBotCategory は無料で使える。Bot Management を契約しなくても検証済みボットの判別はできる。

起きた事象：UA を一列足したら診断が覆った

9 日ぶん（6564 行）を DuckDB に食わせ、504 を UA で割った。

SELECT userAgent, count(*) n, count(DISTINCT clientIP) ips
FROM read_json_auto('s3://.../cf-logs/**/*.ndjson.gz')
WHERE edgeResponseStatus = 504
GROUP BY 1 ORDER BY n DESC;

307 件すべてが Early Hints だった。 bastion も nginx-ssl も Cloudflare 内部コンポーネントの名前で、ブラウザではない。

Early Hints の UA だけで切り直すと、失敗率が見える。

Early Hints のリクエストは 7 割が 504 で落ちている。 そして同時に、静的サイトに PUT が飛んで 204 が返るという不可解な記録も、これが正体だった。攻撃ではない。

前回「サイト全体が断続的にタイムアウトしている」と読んだのは、Early Hints が全ページを舐めていたからだった。満遍なく出ていて当然である。

最大の発生源だった /static/favicons/site.webmanifest も同じで、504 の 176 件は全部 Early Hints。実ユーザーが受け取っていたのは 304 が 301 件と 200 が 18 件で、正常に動いていた。

userAgentBrowser が Unknown になっていた時点で気づくべきだった。ブラウザとして解釈できない UA なら、それはブラウザではない。

なお Cloudflare Pages で Early Hints が 504 を誘発する事例は、コミュニティにも報告がある²³。

522 のほうは本物だった

同じ 9 日間で 522 が 71 件。こちらは UA で割ると景色が違う。

63 個の異なるアドレスから、モバイルの実ユーザーが www サブドメインでエラー画面を見ている。 毎日 8〜13 件のペースで、9 日間途切れていない。

前回の記事の最後にこう書いた。

そしてその前に、522 の犯人を潰す。順番としては、たぶんそっちが先だ。

潰せていなかった。 書いてから 2 週間、毎日出続けている。

もうひとつの発見：ログは 8 日で消える

「ブログ開設（6/3）からの全ログが欲しい」と思って遡ったところ、Cloudflare がこう返した。

cannot request data older than 1w1d,
but your query requests data from 1w6d3s ago

1w1d ＝ 8 日。 それより古いデータは無料プランでは保持されていない。開設から 6 週間ぶんは、既に取り返しがつかない。

ログは「必要になってから欲しい」と言えない。 貯める仕組みを先に置くしかない、という当たり前の話が、実費ゼロで証明された格好になった。残っていた 8 日ぶんは即座に S3 に退避した。

結論

「エラーが出ている」と「ユーザーが困っている」は別の事実である。 前者から後者を推論すると、今回のように誤診する。両者を分けるのは UA という 1 列だった。

そして誤診の構造は、観測の粒度で決まっていた。

• 点検（今叩く） → 「今は正常」しか分からない。実際これで 2 回、直ったと誤判断した
• 24 時間の集計 → 件数は見えるが、散発か集中か、誰が踏んだかが分からない
• 9 日ぶんの生ログ → 初めて「毎日出ている」「全部内部リクエスト」が見える

監視を足すべきかを判断する材料は、多くの場合すでに手元にある。足りないのはデータ量ではなく、次元だった。

未解決

Cloudflare の設定画面で Early Hints は無効になっている。 にもかかわらず、ログ上は 7/19 18:33 まで当該リクエストが出続けていた。

考えられるのは、(a) 直前に無効化されたばかりで観測に反映されていない、(b) Cloudflare Pages 側にゾーン設定と独立した挙動がある、(c) 別機能が同種の内部 UA を使っている、のいずれか。

推測で埋めるのはやめる。15 分ごとの収集はもう回っているので、数日ぶん見れば判定できる。 続報を書く。