処理成功なのにACKを返せておらず、同じ処理が数万回再実行された。
「昨日の夜間バッチ、なんか実行回数が異常に多いんだけど」とデータチームのメンバーから言われて確認したのが発端だった。Cloud Functionsの実行ログを見ると、同じメッセージIDに対して処理が数十回から数百回走っていた。本来は1件のメッセージに対して1回だけ処理が実行されるべきなのに、ログには同じpayloadに対する処理が何十行も並んでいた。
Pub/Subを使ったCloud Functionsのトリガーでは、メッセージが正しく処理されたことをACK（acknowledgement）でPub/Subに通知する必要がある。ACKが返らないとPub/SubはそのメッセージをNot processedと判断し、acknowledgement deadlineが過ぎるたびに再配信し続ける。Cloud Functionsの場合、関数が正常終了（例外なし）すればACKが自動で返される仕様だ。
処理コードを確認すると、問題は例外ハンドリングにあった。catchブロック内で独自のエラーオブジェクトをthrowしていた。意図としては「エラーをログに出してそのまま終了させたい」だったのだが、Cloud Functionsの観点からすると例外が上がった状態で終了したことになり、NACKが返された。処理は実際には最後まで完了していたのに、Pub/Subからは「失敗した」と判断されて再配信が延々と続いた。
さらに厄介だったのは、その処理が冪等でない操作を含んでいたことだ。外部の請求APIに対してトランザクションを確定するリクエストを送る処理で、本来1回だけ実行されるべきものが数十回走った。幸い外部API側でも重複チェックが実装されており実際の二重処理は起きなかったが、冷や汗をかきながら確認した。
まずcatchブロック内でエラーをログに記録した後はthrowせずに正常終了するように変えた。これでNACKが返らなくなり、再配信ループは止まった。加えてチームの設計ルールとして「Pub/Subで実行するすべての処理は冪等に設計する」ことを明文化した。具体的にはメッセージIDをキーにした処理済みフラグをDBに持ち、処理前に確認するパターンを標準にした。Pub/Subは「at-least-once delivery」であり「exactly-once」ではないことを全員が理解する必要がある。さらにデッドレターキュー（DLQ）の設定も全Pub/Subトピックに必須化した。一定回数配信されても処理されなかったメッセージを別のトピックに逃がすことで、無限ループの上限を設けられる。最初からこの設定があれば、今回の問題も数百回のループで止まっていた。