タイムアウトを 3 回直しても止まらなかった:真犯人は、同じ鍵の中で動いていた 2 つ目の処理だった

English version

トレカダッシュ 開発の記録 / 2026年8月

iOS アプリ「トレカダッシュ」の、楽天ブックスの在庫を確かめる処理が、1 日に 17 回、タイムアウトしていました。タイムアウトは、処理が時間の上限(480 秒)までに終わらないことです。

この不具合を、3 回、直しました。それでも、止まりませんでした。真犯人は、3 回とも、見ていない場所にいました。この記事は、その調べ方の記録です。

この記事は、2026 年 8 月 25 日の作業の記録から書いています。

1 回目:取得に、タイムアウトが無かった

最初に見つけたのは、「取得に、時間の上限が無い」ことでした。外部のサイトからの返事が、永遠に来ないと、処理が永遠に待ちます。取得に、上限を付けました。ところが、1 日 17 回のタイムアウトは、止まりませんでした。

2 回目:「購入可能になった品の審査」で詰まっていた

次に疑ったのは、購入できるようになった品の、転売価格の審査でした。外部の API への問い合わせを含むので、ここで詰まる経路が残っていました。審査で見送った場合は、通知が 0 件のままなので、症状からは気づけません。

1 件ぶんの処理を、まるごと 1 つの関数(processOne())に切り出し、残り時間を上限にした Promise.race(先に終わったほうを取る)で包みました。デプロイして 7 分で、タイムアウトは 0 件。「確認: 12 件(時間切れのため、続きは次回)」と、正常に完了していました。

教訓は、「詰まりそうな 1 か所」だけに上限を付けても、足りないことでした。時間の予算は、ループの頭でしか見ていません。1 件の処理のどこかに、上限の無い待ちが 1 つでも残っていれば、そのまま、強制的な上限まで走り切ります。上限は、1 件ぶんの処理全体に掛けます。

ところが、タイムアウトは、止まっていませんでした。

3 回目:真犯人は、同じ鍵の中の、2 つ目の処理

3 回直しても止まらなかった理由は、上限を掛けた場所が、どれも本命ではなかったことでした。

真犯人は、同じ「二重実行を防ぐ鍵」の中で動いている、2 つ目の処理(runRevalidateRakutenBooksAvailability)でした。

1 つ目の処理(在庫のチェック)に、いくら上限を掛けても、2 つ目が、480 秒まで走り切っていました。ログには、1 つ目の完了のメッセージが出るので、「正常に終わっているのに、タイムアウトする」ように見えていたのです。

2 つ目にも、「残り時間」の上限を掛けました。打ち切っても、毎分実行されるので、取りこぼしにはなりません。デプロイして 15 分で、タイムアウトは0 件でした。

おまけ:毎回エラーになっていた、あるサイト

ついでに見つかった、別の不具合です。あるゲーム会社の通販サイトは、素の取得だと、リダイレクトの無限ループ(maximum redirect reached)になり、再検証のたびに、エラーのログが出ていました(1 日に十数回)。取得サービスの「昇格の記憶」では、強い設定が必要と、すでに判定済みのサイトでした。

直し方は、昇格の記憶に残っているホストは、素の取得を試さず、最初から取得サービス経由にすることでした。ホスト名を並べる方式は、採りませんでした。昇格の記憶は、実際の失敗から、自動でたまるので、新しいサイトが増えても、追加の作業が要りません。

分かったこと

タイムアウトを追うときは、まず、その関数が何を呼んでいるかを、全部数える。

この話に出てくるもの

ほかの記録

コメント

感想や、記事の間違いの指摘は、ここへ。書くには、GitHub のアカウントが要ります。

押すと、giscus(giscus.app)と GitHub に接続します。押さなければ、接続しません。詳しくはあつかいに書いています。