冪等性のないバッチ処理をCloud Schedulerで動かしていたら、まれに2回実行された。
夜間バッチの運用を始めてから2ヶ月後、データチームから「昨日の集計結果、なんか数字がおかしいんですが確認できますか」という問い合わせが来るようになった。最初は「データの問題だろう」と思って調査しても再現しないことが多く、原因を特定できないままになっていた。ところがある日、ログを丁寧に追うと原因が見えてきた。
Cloud Schedulerで毎晩0時に起動するバッチ処理が、まれに2回実行されていた。Cloud SchedulerはPub/Subを経由してCloud Functionsをトリガーする構成で、Pub/Subの配信は「at-least-once delivery」、つまり少なくとも1回は確実に届けるが、状況によっては2回届くことがある。この「まれに2回」が問題を引き起こしていた。
バッチ処理の中に「前日分のデータを集計してサマリーテーブルに追記する」処理があった。追記にはINSERT文を使っており、同じデータが2回INSERTされてもエラーにならない設計だった(ユニーク制約がなかった)。2回実行されると同じ集計行が2行挿入され、集計テーブルの合計が実際の2倍になる。月次レポートや売上集計がおかしくなっていたのはこのためだった。二重実行が発生する頻度は低く、数百回の実行に1回程度だ。毎晩走るバッチなので2ヶ月で数回は発生していた計算になる。その都度データチームが手動で重複行を特定して削除する作業をしていた。
修正は2段階で行った。まずINSERT文をUPSERT(INSERT ... ON CONFLICT DO UPDATE)に変更し、同じ日付のサマリーが既にあれば上書きするように変えた。これで2回実行されても結果が変わらない設計になった。次に処理の冒頭で「今日の実行済みフラグがDBにあればスキップする」という冪等チェックを追加した。加えてPub/Subのデッドレターキュー(DLQ)をすべてのトピックに設定するルールを設けた。「Cloud Schedulerだから1回だけ実行されるはず」という思い込みが、この問題の根本にあった。分散システムにおける「exactly-once」は保証されない、という原則を改めて意識させられた出来事だった。