配備のたびに、日次の処理が丸ごと走り直していた:48 時間で 477 回、その日の Gemini 費用の 46.6%

English version

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

iOS アプリ「トレカダッシュ」の裏側では、定期的に動く処理がたくさん動いています。その中に、「1 日に 1 回だけ動くはず」の処理がありました。ところが、ある日のログを数えると、その処理が 43 回動いていました。

この記事は、そこから見つかった、「配備(コードを入れ替えて再起動すること)のたびに、日次の処理が丸ごと走り直していた」不具合の記録です。

数字は、2026 年 9 月 1 日の作業の記録から書いています。

48 時間で、477 回の追い実行

処理の実行は、時刻になると動く仕組み(cron)で決まっています。再起動すると、その瞬間にあった予定は、消えます。そこで、起動したときに「前回の実行が古すぎる処理」を探して、取りこぼしとして追いかけて動かす仕組みを入れていました。この追い実行の判断は、「前回の実行時刻が、間隔の 1.05 倍より古いか」でした。

この日の 48 時間で数えると、追い実行は477 回ありました。中でも、記事に商品の紐付けを直す日次の処理は、1 日 1 回のはずが43 回動いていて、その日の Gemini(AI)の費用の46.6%、呼び出しにして 1,295 回を占めていました。やっていたのは、同じ記事に、もう一度 AI で値段を付けているだけで、得られるものは何もありません。

原因:「終わった」という記録が、残っていなかった

この処理は、時間の上限(540 秒)を超えると、「タイムアウトした」と記録されます。ただし、JavaScript には、動いている処理を途中で止める仕組みがないので、タイムアウトと記録されたあとも、本体は最後まで動き続けます。

問題は、「最後の実行時刻」の書き込みが、成功して終わったときだけだったことです。タイムアウトした回は、本体が最後まで終わっても、実行時刻が書かれません。すると、再起動のたびに、こう判断されます。

  1. この処理の最後の実行は、記録が無い(または古い)。
  2. 間隔の 1.05 倍より古いから、取りこぼしだ。
  3. いま走らせよう。

日次の処理が、再起動のたびに、丸ごと走っていました。配備を 1 日に何度かするだけで、日に 43 回です。

直し方:「タイムアウトを記録した」と「走らなかった」は別のこと

タイムアウトと記録されても、本体が最後まで終わったなら、その回は走ったものとして記録するようにしました。失敗して終わったときだけは、記録しません。

この直しは、時間の上限を下げる対策と、必ず対にしておく必要がありました。上限だけを下げても、実行時刻が残らなければ、追い実行は止まりません。

逆の問題:追いかけすぎても、足りなくても困る

この追い実行には、反対の問題もありました。8 月 31 日、私の配備が、朝 8 時ちょうどに重なりました。時刻に動く仕組みは、「その瞬間」にしか発火しないので、8 時のダイジェスト通知が、1 通も送られませんでした。

ダイジェストは、1 日に 5 回(6・8・12・18・21 時)です。平均の間隔は 4.8 時間で、追い実行の下限(6 時間)に届かず、「待てば次が来る」と見なされていました。ところが、利用者にとっては、その時刻を選んでいた人の 1 日ぶんが、消えたのです。

直し方は、利用者への届け物に関わる処理だけ、起動時に「直前の 55 分の予定を取りこぼしていないか」を見て、1 回流す形でした。予定から 10 分たつまでは、まだ走っていないだけかもしれないので、待ちます。

ここで、全部の処理に広げては、いけません。実データで数えたら、再起動のたびに 33 件が「取りこぼし」と判定され、ほとんどは再起動で中断されただけでした。全部を追いかけると、取得サービスや API の上限を、無駄に食います。足す基準は、「取りこぼすと、利用者への届け物が消えるか」です。

分かったこと

「記録が無い」は、「走らなかった」とは限らない。

この話に出てくるもの

ほかの記録

コメント

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

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