タイムアウトを 3 回直しても止まらなかった:真犯人は、同じ鍵の中で動いていた 2 つ目の処理だった
トレカダッシュ 開発の記録 / 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 件ずつ API を叩く。
- 楽天の API には、1.5 秒の間隔の制限がある。
- 時間の上限が、一切ない。
1 つ目の処理(在庫のチェック)に、いくら上限を掛けても、2 つ目が、480 秒まで走り切っていました。ログには、1 つ目の完了のメッセージが出るので、「正常に終わっているのに、タイムアウトする」ように見えていたのです。
2 つ目にも、「残り時間」の上限を掛けました。打ち切っても、毎分実行されるので、取りこぼしにはなりません。デプロイして 15 分で、タイムアウトは0 件でした。
おまけ:毎回エラーになっていた、あるサイト
ついでに見つかった、別の不具合です。あるゲーム会社の通販サイトは、素の取得だと、リダイレクトの無限ループ(maximum redirect reached)になり、再検証のたびに、エラーのログが出ていました(1 日に十数回)。取得サービスの「昇格の記憶」では、強い設定が必要と、すでに判定済みのサイトでした。
直し方は、昇格の記憶に残っているホストは、素の取得を試さず、最初から取得サービス経由にすることでした。ホスト名を並べる方式は、採りませんでした。昇格の記憶は、実際の失敗から、自動でたまるので、新しいサイトが増えても、追加の作業が要りません。
分かったこと
タイムアウトを追うときは、まず、その関数が何を呼んでいるかを、全部数える。
- 1 つのスケジュール関数の中に、処理が 2 つ以上あることがある。3 回とも、1 つ目だけを見ていました。
- 上限は、1 件ぶんの処理全体に掛ける。詰まりそうな 1 か所だけでは、足りません。
- 「正常に終わっているのに、タイムアウト」は、別の処理を疑う。完了のメッセージは、1 つ目のものかもしれません。
- 区間ごとの所要時間を、ログに出す。次は、一発で分かります。
- 手で書く一覧より、実際の失敗からたまる記憶を使う。新しいサイトに、自動で効きます。
この話に出てくるもの
- トレカダッシュ — トレカの抽選・予約・先着の情報を集める iPhone アプリ
- 監査 61 本を総点検して見つけた 4 つ — 同じ鍵の期限の話
- 同時実行の枠を増やす前に見るもの — 枠と待ちの話
- 「次回へ」と出続けていた 25 本の点検は、一度も走っていなかった — 時間予算の別の失敗
ほかの記録
- ログに秘密のトークンが平文で残っていた:呼び忘れようがない唯一の出口で伏せる — 通信の部品のエラーメッセージに URL がそのまま入り、取得サービスのトークンがログに出ていた。前に作った伏字の関数は、明示的に呼ぶ場所にしか効かず、呼び元は 50 か所以上。ログの唯一の出口で伏せる形に直した。
- 失敗を捨てると、画面は嘘をつく:「○件登録しました」と出て 1 件も入っていなかったカレンダー、固まる文字認識、店名を積み忘れた通知 — try? で失敗を捨てていたため、カレンダーに 0 件なのに「登録しました」と出て二度と登録できなくなった。文字認識の失敗で画面が固まった。通知バッファに店名を積み忘れて「店名なし」になった。
- 候補は見つかっていたのに、答えを読む所で毎回落ちていた:200 トークンで切れた URL と、ハイフンで 400 になる検索 — 公式の告知ページを選ぶ AI の返事が 200 トークンで途中で切れて毎回失敗していた。直しても 0 件だったのは、店の告知が個別の商品名を書かないため、AI が指示に忠実に拒否していたから。楽天の検索は、ハイフンの位置で 400 になった。
コメント
感想や、記事の間違いの指摘は、ここへ。書くには、GitHub のアカウントが要ります。
押すと、giscus(giscus.app)と GitHub に接続します。押さなければ、接続しません。詳しくはあつかいに書いています。