😇

Exception from a finished function: Error: 13 INTERNAL: Received RST_S

2023/10/25に公開

概要

  • 追記(2023/10/27): 不具合だったっぽいです
  • 開発しているプロダクトを利用している部署から、不具合報告があがった(かっこよくいっているけど、席にきて口頭で説明されただけ)
  • 何もしていないけど壊れました事象っぽかったので、ログになにかないかな?と思って調査したところ、突如現れた ``
  • ぐぐったらIssueがいくつかでてきたが、謎
  • こうすれば修正されるよ!と書いているコメントが調査中にでてきて検証進めて修正できたのでメモする

不具合が発生したプロダクトの技術スタックと処理について

不具合がおきたプロダクトの技術スタック

  • Cloud Functions for Firebase (1st)
    • Node.js
    • TypeScript
  • GCP Cloud Pub/Sub
  • GCP Cloud Scheduler
  • Firestore

GCP Pub/SubとCloud Schedulerについては下記参考

https://cloud.google.com/scheduler/docs/tut-pub-sub?hl=ja

不具合がおきた機能の簡単な説明

  1. 分毎にCloud Functionsを起動する
  2. Cloud FunctionsからFirebase Admin SDKを利用して、Firestoreを検索する
  3. 検索結果(Documentの配列)があれば、ループし、ドキュメントを更新する

調査

まず再現するか確認

再現しなかった?なぜ?

ログエクスプローラを使って、とりあえずエラーログないかなと検索

とりあえず下記クエリ(?)で見つからんかなーと思ってなげたら、ビンゴだった

resource.labels.function_name="${Cloud Functionsの名前}"
SEARCH("`Exception`")

Cloud Functionsが実行されたタイミングでこのエラーが大量にでていた。何ぞ???

Exception from a finished function: Error: 13 INTERNAL: Received RST_STREAM with code 1

ぐぐるとIssueに出会う

https://github.com/googleapis/nodejs-firestore/issues/1023
https://github.com/firebase/firebase-admin-node/issues/2345

よくわからないが、読み進めていると「複数回Firestoreにクエリ投げると〜」的なコメントがあったのと、たしかに今回発生した事象は、「ある時間帯にCloud Functionsを起動したら複数ドキュメントを更新しようとしてエラーになった」ということだったので、検証してみようと思った

複数ドキュメントを更新しようとした場合、再現するか確認する

再現した!

原因がこれっぽいので解消できるのかIssueを再度確認する

読み進めていると。。。。

https://github.com/firebase/firebase-admin-node/issues/2345#issuecomment-1776090309

I had the same problem since last friday and so far I understood looks like something inside firebase / grpc implementation related to long time delays between firebase calls.

Also, correct me if I'm wrong, firebase library seems to be moving away from gRPC but it still keeps it as a default option if you don't set preferRest: true (see docs)

For me the solution was calling init right before performing an operation and/or changing firebase config to prefer using rest comunication.

Here is my code snipet:

神が現れました やはり神はインターネットにいます

原因が grpc 周りらしいですが、聞いたことはありますが、正直どういうプロトコルなのか(そもそもプロトコルなのか?も含め)全然わかっていなかったので、ChatGPTに聞きながら調査しました

gRPCとHTTP2を知る旅にでる

https://qiita.com/namusyaka/items/71cf27fd3242adbf348c
https://qiita.com/0xfffffff7/items/c8cabb51ced5efcaec6f
https://zenn.dev/mryhryki/articles/2019-12-30-hatena-http2

ふわっと理解しましたが、わかったこととして

  • RST_STREAM から、特定のストリームが何らかの理由で中断されたっぽい
  • Firestoreとの通信で、gRPCの利用を抑制(おそらく)するオプションをいれたら、REST通信になるので、↑は発生しなくなる

ということらしいです(たぶん)

修正その1

とりあえずまずは修正して検証してみる

import * as firebaseAdmin from 'firebase-admin'

firebaseAdmin.initializeApp(options)
const db = firebaseAdmin.firestore()
db.settings({ preferRest: true }) // こいつを追加

// ...
// 別のところで呼び出して利用する
const db = firebaseAdmin.firestore()

検証

うおおおお、発生しなくなった!!!

ただ、数件失敗していることを確認した。ログを確認してみると

Exception from a finished function: FetchError: request to https://firestore.googleapis.com/v1/projects/projenct-name/databases/(default)/documents:commit?$alt=json%3Benum-encoding=int failed, reason: socket hang up

なるほど。。。。

修正その2

そもそもですが、大量に書き込むならバッチのほうがいいのでは?ってなりました

https://firebase.google.com/docs/firestore/manage-data/transactions?hl=ja#batched-writes

書き込みコードが update だったので、そこをまるっと、 batch へ変更しました

import * as firebaseAdmin from 'firebase-admin'
import * as _ from 'lodash'

const batchUpdate = async (docs: firebaseAdmin.firestore.DocumentData[]) => {
  const db = firebaseAdmin.firestore()
  // batch.commitは500件までしか書き込めないため、500件ずつ分割して書き込む
  // eslint-disable-next-line import/namespace
  for (const chunkDocs of _.chunk(docs, 500)) {
    const batch = db.batch()
    chunkDocs.forEach((d) => {
      const docRef = db.collection('CollectionNames').doc(d.id)
      batch.update(docRef, { ... }) // 更新するデータを入れる
    })
    console.log('バッチ書き込み開始')
    await batch.commit()
    console.log('バッチ書き込み終了')
  }
}

検証

動いた!!!!

雑なまとめ

  • ログエクスプローラー、最初UI意味わからんかったけど、クエリ?操作できるようになったら便利そう
  • Cloud FunctionsのエラーをNewRelicとかに転送する術を覚えたい
  • 大量でもないけど、Firestoreのデータを複数更新する場合は、batchを利用したほうが良さそうな事案でした
    • ただ、Issueはまだ終わってなくて、やっぱりバックエンド側になにか問題が発生していないか?がずっと議論されておる
    • 引き続きwatchしていきます(多分今回やったことはたまたま batch に変えることができただけで、ベストではない)

Firestore難しいです!!!!(違

追記(2023/10/27 09:35)

修正できたらしいですが、謎

https://github.com/firebase/firebase-admin-node/issues/2345#issuecomment-1781485097

CBcloud Tech Blog

Discussion