Cloud Scheduler が「成功」と言うのに通知が届かない時に確認すべき 3 つのこと

LINE ミニアプリ開発記 第 14 回

#Cloud Scheduler#Cloud Functions#GCP#ログ調査

Cloud Scheduler の管理画面で「成功」と表示されているのに、利用者の LINE には何も届いていない。最初に見たときは、これは Cloud Scheduler のバグなんじゃないか、と一瞬思いました。違いました。Cloud Scheduler の「成功」は、HTTP 200 が返った、というだけの意味 で、関数の中身が動いたかどうかは見ていません。

本記事はこの罠の正体と、通知未達を切り分けるときに確認する 3 つの場所を、ログコマンド込みでまとめます。「成功」表示を信用しないで済むようになるのが終端目標です。

状況・前提

詰まったポイント

Cloud Scheduler の「成功」は誤解を招く表現

Cloud Scheduler のジョブ実行履歴には、各実行に 「成功 / 失敗」 が表示されます。私はこれを「関数が最後まで実行できたかどうか」だと長らく勘違いしていました。実際には次の違いです。

Cloud Scheduler の「成功」= ターゲット URL が HTTP 200 を返した
   └─ 関数の中身がエラーで落ちていても、catch して 200 を返したら「成功」
   └─ Push が 1 通も飛んでいなくても、関数自体が 200 で終わったら「成功」

Cloud Scheduler の「失敗」= HTTP 5xx が返った / リトライ上限超過 / タイムアウト
   └─ ここはまっとうに「失敗」

つまり、関数の中で try/catch で握りつぶしてレスポンスを 200 にしている部分があれば、Cloud Scheduler から見ると永遠に「成功」になり続けます。

私のケースでは、対象ユーザーへの Push 失敗を「次のユーザーの処理を続けるため」に try/catch で握っていて、さらにその catch で console.error だけ呼んで終わっていました。Cloud Scheduler は満面の笑みで「成功」と言い続けていた、というわけです。

切り分け: 確認すべき 3 つの場所

1. Cloud Logging Explorer

Cloud Scheduler の「成功」を信用せず、まず Cloud Logging Explorer で 関数本体のログ を見ます。GCP コンソール → ロギング → ログエクスプローラ。

クエリの例(第 2 世代 Functions = Cloud Run functions の場合):

resource.type="cloud_run_revision"
resource.labels.service_name="senddailyreminders"
severity>=ERROR

第 2 世代 Functions(2024 年 8 月以降は Cloud Run functions に改称)は cloud_run_revision で取得します。第 1 世代を使っている場合は cloud_function に変えてください。resource.type を間違えると 1 件もヒットしないので、最初の切り分けでここを疑うのは有効です。

ここで console.error の出力や未捕捉エラーが見えます。severity>=DEFAULT にすれば console.log も含めて全部出ます。これが一番情報量が多いです。

クエリ言語のポイントは:

2. firebase functions:log の挙動と限界

CLI でも見れます。

firebase functions:log --only sendDailyReminders --lines 200

ただしこのコマンドは内部で Cloud Logging を叩いているので、Cloud Logging の取り込み遅延 がそのまま反映されます。体感では 数秒〜十数秒 程度のことが多く、関数が並列実行されているとログが順番通りに表示されない(インターリーブ)こともあります。私は最初これに気付かず、「ログが空だ → 関数が動いてない → 焦る」を繰り返しました。

[1] ジョブ実行 09:00:00
    ↓ 数秒〜十数秒
[2] firebase functions:log で見えるようになる
    └─ ただし複数インスタンスのログが入り混じる
[3] Cloud Logging Explorer は live tail で ほぼリアルタイム表示が可能
    ★ 緊急時は Logging Explorer の live tail のほうが向いている

短いタイムスパンで切り分けるなら、Cloud Logging Explorer の ライブテール機能 を使うのがおすすめです。firebase functions:log は事後の確認用、開発中の即時確認は Firebase Emulator のローカルログ、と使い分けると無駄な「ログ待ち」がなくなります。

3. 自己通知(Push 失敗を運営側にも飛ばす)

ログを開かなくても気付ける仕組みも必要です。私が入れているのは Push 失敗を運営の LINE 側にも飛ばす 仕組みです。reportError という別の Cloud Function を用意して、関数のなかから例外時にそこを叩きます。

async function pushTo(lineUserId: string, text: string) {
  const res = await fetch("https://api.line.me/v2/bot/message/push", { /* ... */ });
  if (!res.ok) {
    // Push 失敗を運営自身の LINE に通知
    await fetch(REPORT_ERROR_ENDPOINT, {
      method: "POST",
      headers: { "Content-Type": "application/json" },
      body: JSON.stringify({
        message: `Push failed: ${res.status} for ${lineUserId}`,
      }),
    });
  }
}

reportError 側は 管理者の LINE userIdU で始まる 33 文字)を別 Secret に持たせて、そこへ Push します。これがあると、利用者からのフィードバックを待たずに「あ、今朝のリマインダー失敗してる」と運営が気付けます。

解決手順: 切り分けの順序

実際に通知未達に遭遇したときの動き方:

[1] Cloud Logging Explorer を開く
    └─ severity>=ERROR で関数のエラーを確認
       ├─ エラーがある → 中身を読む(PERMISSION_DENIED / fetch failed / 等)
       └─ エラーなし → [2] へ

[2] severity>=DEFAULT で console.log を確認
    └─ 「N 件対象 / N 件 push 成功」のような自前ログを仕込んでおく
       ├─ 対象 0 件 → クエリ条件のミス(複合インデックス未デプロイ等)
       └─ Push 失敗 → [3] へ

[3] LINE Messaging API のレスポンスを確認
    └─ 401 / 403 → アクセストークン / シークレット切れ
    └─ 429 → レート制限・同時実行・月次上限のいずれか
    └─ 400 → リクエスト構造の不正(メッセージ形式・to の値)
       ★ 各ケースに合わせて修正

LINE Messaging API の 429 は実は 3 種類 あります。レスポンスボディの description で見分けます。

種類description の典型復帰方法
月次上限超過You have reached your monthly limit.翌月 1 日の自動リセット または プランアップグレード
レート制限超過Exceeded the rate limit for requests少し待ってから再試行(指数バックオフ)
同時実行制限超過(ナローキャストなど)一時的に発生少し待ってから再試行

「同じ 429 だから同じ対処」ではないので、description を必ずログに残します。さらに LINE は Retry Key(UUID 形式の任意ヘッダ)でべき等な再試行をサポートしているので、再送時の二重 Push を避けたければ Retry Key を仕込んでおくのが堅いです。

ログを仕込んでおくべき場所

将来の自分のために、関数のなかには 自前のサマリログ を仕込んでおきます。

console.log(JSON.stringify({
  event: "sendDailyReminders.summary",
  targetCount: snapshot.size,
  groupedUsers: grouped.size,
  pushSuccess,
  pushFailed,
}));

これがあると Logging Explorer のクエリで jsonPayload.event="sendDailyReminders.summary" だけ抽出して、毎日の運用状況を一覧できます。問題があった日の異常も発見しやすい。

学び・余談

「成功」「失敗」の語感を疑う、というのが今回の本当の教訓でした。プラットフォームが言う「成功」は そのプラットフォームの責任範囲内での成功 であって、ビジネスロジック上の成功とは別物。Cloud Scheduler は HTTP 200 を返す相手と話せたら成功で、その内部で何が起きていようが関心がない。当たり前と言えば当たり前なのですが、通知未達のような「届くべきものが届かない」種類の事故 は、表面上の「成功」に化けやすいので特に警戒します。

自己通知の仕組みは、入れた直後はやり過ぎに感じましたが、結局 1 回でも本番事故を未然に拾えれば元が取れる、という性質のものでした。個人開発で運営側の通知チャネルを 1 本確保しておくことを、強くおすすめします。

関連記事

参考


← ブログ一覧へ