LoginSignup
29
9

More than 3 years have passed since last update.

Firebase Functionsをブラウザから呼んでdeadline-exceededになる場合の対処

Last updated at Posted at 2019-11-19

TL;DR

  • タイムアウトの設定は、サーバー・クライアントの両方で別々に必要
    • サーバのデフォルト60秒
    • クライアントのデフォルト70秒
  • サーバー側のtimeoutだけ延ばすと、クライアントのtimeoutを超えた時点でdeadline-exceededが発生する
  • サーバー側のtimeout300秒なら、クライアント側は310秒 = 310,000ミリ秒にすべし!
  • Firebase Javascript SDKが吐くエラーの意味はここを参照せよ! https://github.com/grpc/grpc/blob/master/doc/statuscodes.md
client.js
(前略).httpsCallable('functionName', { timeout: 310 * 1000 })

しかしそもそも、そんな長いtimeoutが必要なのは設計がおかしいので、できる限り短時間で処理完了できるように検討しましょう。

以下、気が向いたら読んでください

筆者はFirebase初心者なので、なかなか恥ずかしい内容も混ざってるかもしれませんが、しかしこの「JavaScript SDKでのタイムアウト設定方法」は英語サイト含めてほとんどどこにも見つからなかったんですよ。今後かなり多くの人の役に立つことを祈って投稿します。

背景

kintoneのカスタマイズで、ブラウザのJSで重めの処理を動かしていました。
諸事情あり、Firebase Functionにメインのロジックを移して、
kintoneでボタンクリックするとFirebaseの関数が動いて、処理結果をkintoneで受け取るように変更しました。
(kintone知らない人も問題なく読み進められると思いますので)

プログラムの仕様

  • 受注データを発注するプログラム
  • レコードには未発注・発注済みのフラグがある
  • 未発注のレコードid一覧をFunctionで受け取って、kintoneにリクエスト投げて、発注済みに変更する
  • 発注済みのレコードidが混じっていたらエラーで止める
  • Functionsのレスポンスを受けて成功・失敗のメッセージをkintoneで表示

最初に起きたエラー「発注済みです」

十数件のデータで試したら全く問題なく動いたので、本番反映したら、
本番データでは意味不明なエラーが起きたんですよ。

  • 処理が始まる
  • しばらく待たされる
  • 「すでに発注済みです」というエラーメッセージが起きて止まる
  • 結果は、全体の半分強が発注済みに変わって、残りは未発注のまま

そもそも、未発注のレコードIDしか渡していないので、「発注済み」であるわけがない。でも実際に「発注済みです」とエラーが出ている。
そして待ち時間的に、絶対にその場で発注処理を行っている。自分で発注したくせに「発注済みです」と言ってやがる雰囲気。

デバッグ1-1 長い旅の始まり…

本番でエラーが発生した時のデータをテスト環境で再現して、試行錯誤。
ログを確認したところ、どうやら同じFunctionが2連続で走っている。
もちろん発注ボタンは1回しか押していない。なぜだ????

どうやら原因はタイムアウトのようでした。
処理開始から1分くらい経過するとタイムアウトして、
ご丁寧にリトライしてくれていたようです。
そのため、途中まで発注されたレコード達をまた最初から発注しようとして、
「すでに発注済みです」とエラーが出ていた感じ。

いやはや、こういうとき、
コンピュータって何とバカなのかと思ってしまいますね。

デバッグ1-2 タイムアウトを延ばす

Firebase Functionsでは、はデフォルトのタイムアウトが60秒でした。

確かに、本来はこれくらいで処理完了させるべきだと思うんですよね。もともとkintone上で書いていたJSのロジックがかなり効率悪く、もっとパフォーマンス上げられる余地はあるんですが、そのレガシーコード改善が現段階ではかなりリスキーだと判断して、まずは既存のロジックに手を入れずにタイムアウトを延ばすという作戦を今回は取りました。(将来的には60秒に抑えたい)

https://firebase.google.com/docs/functions/manage-functions?hl=ja#set_timeout_and_memory_allocation
この手順に従って、タイムアウトを300秒に延ばしました。
これでまったく問題なく動くはずでしょう!

2回目のエラー deadline-exceeded

同じ処理を走らせてみると、別のエラーが。
その名もdeadline-exceeded
自分で用意したエラーメッセージではない。

この解決が本当に情報なくてつらかった。
ググると情報は無いわけじゃないんだけど、ほとんどCloud Firestoreがらみ。

Firebase Functions(Google Cloud Functions)の情報がない。

デバッグ2-1: Firebase上では止まっていない

Webの画面上でエラーが起きたものの、Firebase側では実は最後まで動いてて、ログのステータスも200になっていました。
kintoneのデータも全部「発注済み」になって、結果も正しかった。
もしかしてクライアント側の問題?
結果は正しいから、ユーザーにはエラーメッセージを無視してもらおうか…

デバッグ2-2: curlで実行してみる

試しにCLIからcurlコマンドで同じ引数を渡して実行してみました。
なんと、まったく問題なく動いてレスポンス返ってきた!
ということは、Web上で動かすためのFirebase Javascript SDK側の問題で間違いなさそう。

クライアントのタイムアウトを別途設定する必要があり、そこが短いままなのでは?という仮説。

デバッグ2-3: { timeout: 300 }

調べたら見つかりましたオプション!
https://firebase.google.com/docs/reference/js/firebase.functions.Functions.html#httpscallable
httpsCallable()関数には第二引数を渡すことができる。

https://firebase.google.com/docs/reference/js/firebase.functions.HttpsCallableOptions.html
その第二引数HttpsCallableOptions型の説明がこちら。
timeoutというプロパティしかない。なんかサンプルコードも無いしとっても不安になるけど、number型ということだけは分かったので、おそらく{ timeout: 300 }みたいなオブジェクトで300秒のタイムアウトになると踏んで、やってみる。

(前略).httpsCallable('functionName', { timeout: 300 })

なんと、おなじdeadline-exceededが発生する。しかも今度は一瞬でエラーになった。
しばし絶望し、このtimeoutとは別の設定が必要なのかとかいろいろ悩む。

デバッグ2-4: SDKのコードリーディング

最終手段。ドキュメントがないならコードを読んでやるよ!
だってプログラマーだもんね!オープンソース最高だね!

ってことで、まずdeadline-exceededでリポジトリ内を検索
https://github.com/firebase/firebase-js-sdk/search?q=deadline-exceeded&unscoped_q=deadline-exceeded

そこそこヒットして、エラーの説明も見つかった。
今後なにかエラーが起きたら、まずここを参照するとよいね。
https://github.com/grpc/grpc/blob/master/doc/statuscodes.md

Code Number Description
(中略)
DEADLINE_EXCEEDED 4 The deadline expired before the operation could complete. For operations that change the state of the system, this error may be returned even if the operation has completed successfully. For example, a successful response from a server could have been delayed long

実際にdeadline-exceededをスローしているのはfailAfter()関数。
読んで字のごとくsetTimeout()している。

function failAfter(millis: number): Promise<never> {
  return new Promise((_, reject) => {
    setTimeout(() => {
      reject(new HttpsErrorImpl('deadline-exceeded', 'deadline-exceeded'));
    }, millis);
  });
}

呼び出し元はここ。もうそのまんまっすね。

      failAfter(timeout),

このtimeoutさんは何者か。すぐ上にこんな定義

    // Default timeout to 70s, but let the options override it.
    const timeout = options.timeout || 70000;

ほうほう、サーバーのデフォルトが60秒だったので、オーバーヘッドを考慮してクライアントは60 + 10 = 70秒に設定されているのね。SDK設計の勉強にもなる。
サーバー300秒なら、クライアントは310秒が良さそうですね。

さて、近づいてきた。このoptions.timeoutは何者か。
call()関数の引数として渡ってきている。

  private async call(
    name: string,
    data: unknown,
    options: HttpsCallableOptions
  )

このHttpsCallableOptions型ってさっきのショボいドキュメントで見たとおりだよな。

ってことでcall()の呼び出し元は、こちら

  httpsCallable(name: string, options?: HttpsCallableOptions): HttpsCallable {
    return data => {
      return this.call(name, data, options || {});
    };
  }

みんな大好き、僕らのhttpsCallable()関数で御座いました。
第二引数のoptionsが、call()の第三引数にそのまんま渡ります。
タイムアウトの設定箇所自体は、デバッグ2-3の段階で合っていたのです。

何が間違っていたか。そう、もうお分かりですね。

    // Default timeout to 70s, but let the options override it.
    const timeout = options.timeout || 70000;

秒とミリ秒を間違えていたのです :sob:

最初300にしてて一瞬でエラーになったのも当然。0.3秒でタイムアウトですからね。setTimeout()の引数はミリ秒指定ですもんね。

でもね、いつもおっちょこちょいなワタクシですが、今回に関しては自分を責めませんよ!だっておかしいでしょう!

  • JavaScript SDKのドキュメントにはともミリ秒とも何も単位は書いてない
  • サーバーのタイムアウトは、ソースコード上でもで指定する仕様
  • だったら普通に考えてサーバーと同じ単位でを指定するだろう!
  • ところがクライアント側だけミリ秒だとぉ!?だったらドキュメントちゃんと書けー!!!!

というわけで、これでうまく行きました。

client.js
(前略).httpsCallable('functionName', { timeout: 310 * 1000 })

結論

ということで、大変長くなりましたが結論です。

  • タイムアウトの設定は、サーバー・クライアントの両方で別々に必要
    • サーバのデフォルト60秒
    • クライアントのデフォルト70秒
  • サーバー側のtimeoutだけ延ばすと、クライアントのtimeoutを超えた時点でdeadline-exceededが発生する
  • サーバー側のtimeout300秒なら、クライアント側は310秒 = 310,000ミリ秒にすべし!
  • Firebase Javascript SDKが吐くエラーの意味はここを参照せよ! https://github.com/grpc/grpc/blob/master/doc/statuscodes.md

しかしそもそも、そんな長いtimeoutが必要なのは設計がおかしいので、できる限り短時間で処理完了できるように検討しましょう。

めでたしめでたし!
"桁違い"に理不尽な思いをしたので、むしゃくしゃしてQiita書いてやったぜ!

29
9
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
29
9