はじめに
Cloud Run で動かしている Slack bot（Bolt for JavaScript）で、同じ通知が3件連投されることがありました。
原因は、コールドスタートで応答が3秒を超え、Slack がイベントを再送していたことです。最小インスタンス数0の構成は変えずに、http_timeout の再送だけを無視するミドルウェアを入れて対応しました。
Cloud Functions など、インスタンス数が0まで減る環境でも同じことが起きると思います。
最小インスタンス数を0にしていて、コールドスタートが起きることは知っていたので、起動中に Slack がイベントを再送したのではと疑いました。
環境と前提
- Slack Bolt for JavaScript 4.2.0（TypeScript）
-
ExpressReceiverを使った HTTP モード - Google Cloud Run（リクエストベースの課金。最小インスタンス数は0）
最小インスタンス数を0にしているのは、意図した設定です。この bot は社内用で、常に動いている必要はありません。「使われたときだけ動けばいい」と考えて Cloud Run を選び、費用も抑えたかったので、インスタンスが0まで減る設定にしています。
事象
チャンネルが1つ作られただけなのに、同じ通知が3件投稿されていました。2件はほぼ同時、3件目だけ約1分後です。
発生したのは bot があまり使われていない時間帯で、その日最初のイベントでした。
原因
Events API のドキュメントによると、Slack の再送は次のような仕様です。
- イベントを受け取ったら、3秒以内に HTTP 2xx を返す必要がある。返せなければ配信は失敗とみなされる
- 失敗した場合は、最大3回再送される（1回目：ほぼ即時、2回目：1分後、3回目：5分後）
- 再送のリクエストには、
x-slack-retry-num（1〜3）とx-slack-retry-reason（http_timeout、http_errorなど）のヘッダーが付く
Cloud Run のログでも、最初のリクエストと同時にインスタンスが起動し、応答までに4秒以上かかっていました。その後、数秒後と約1分後にも同じエンドポイントへのリクエストが来ていて、再送の間隔と一致します。
コールドスタートで応答が3秒を超え、Slack が同じイベントを再送し、bot が再送分も通常のイベントとして処理していた、というのが原因でした。
対策
方針：コールドスタートはなくさず、重複だけ防ぐ
コールドスタートをなくすなら、最小インスタンス数を1にする方法があります。ただ、「使われたときだけ動けばいい」という考えでこの構成にしているので、今回は採用しませんでした。代わりに、再送されたイベントを処理しないことで、重複を防ぐことにしました。
http_timeout の再送だけを無視する
ただし、再送をすべて無視するわけにはいきません。初回の処理がエラーで失敗していた場合は、再送を処理しないとイベントを取りこぼしてしまいます。
クラスメソッドさんの記事で紹介されている考え方を参考に、再送の理由で対応を分けました。
| 再送の理由 | 初回のリクエストはどうなっているか | 対応 |
|---|---|---|
http_timeout |
届いていて、応答が遅れただけ。起動後に処理される | 重複になるので無視する |
http_error など |
処理に失敗したか、届いていない可能性がある | 通常どおり処理する |
実装：context から取り出し、app.use で弾く
Bolt for JavaScript では、再送のヘッダーの値を Bolt が context.retryNum / context.retryReason に入れて渡してくれます。
これを、すべてのリクエストが必ず通るグローバルミドルウェア（app.use）で判定しました。
また、実際にどのイベントで再送が起きているのかを確かめたかったので、再送のときは event_id とイベントの種類もログ出力するようにしました。event_id は再送されても同じ値なので、どのイベントの再送なのかを結び付けられます。
// Slack からの再送を判定する
app.use(async ({ context, body, next }) => {
const { event_id, event } = body as {
event_id?: string;
event?: { type?: string };
};
// どのイベントで再送が起きているかを確かめるため、event_id と種類をログに出す
if (context.retryNum) {
app.logger.info(
`Slack retry: event_id=${event_id} type=${event?.type} retryNum=${context.retryNum} retryReason=${context.retryReason}`
);
}
// 3秒超過による再送は初回分が処理されるため無視する。それ以外の再送は通常どおり処理する
if (context.retryNum && context.retryReason === "http_timeout") return;
await next();
});
ミドルウェアで return しても、Slack には正常に受け取ったと返るので、再送はそこで止まります。
まとめ
- コールドスタートで3秒を超えやすい環境（最小インスタンス数0の Cloud Run など）では、Slack の再送によって同じイベントを重複して処理することがある
- 再送の理由が
http_timeoutのものだけを無視すれば、それ以外の理由（http_errorなど）による再送は処理されるので、取りこぼしを避けつつ重複を防げる - Bolt for JavaScript では
context.retryNum/context.retryReasonで再送を判定でき、グローバルミドルウェアにまとめて書ける