🗂

開発者が陥りやすい ActiveJob の retry_on のオプション attempts の誤解を解く

2024/01/31に公開

こんにちは、masaki です。
今日は Ruby on Rails の ActiveJob における retry_onattempts オプションについて話します。
この機能は非同期ジョブのリトライ回数をどう扱うかに関わるものですが、誤解されやすい挙動になっています。
この記事では retry_onattempts の実際の挙動を詳しく解説し、よくある誤解を解き明かします。

attempts オプションの一般的な誤解

ActiveJobretry_on は、指定した例外をキャッチしてリトライします。
retry_on を使っている以下の実装で、ジョブは 何回 リトライされるでしょうか?

class SomethingJob < ApplicationJob
  retry_on SomethingError, attempts: 3
  
  def perform
    raise SomethingError
  end
end

3回だと思いましたか?
答えは「2回リトライされる」です。

私はこの定義を初めて見たときに「3回リトライされる」と思いました。
attempts は「試み」や「試行」という意味です。
この定義を見て「3回リトライされる」と思ったのは私だけではないと思います。

ソースコードによる解説

なぜそうなるのか attempts が実装されている retry_on の実装を見てみましょう。
retry_onActiveJob::Exceptions モジュールに定義されています。
以下は 2024 年 1 月 31 日時点で最新のバージョン 7.1.3 のコードです。

https://github.com/rails/rails/blob/v7.1.3/activejob/lib/active_job/exceptions.rb#L62-L86

attempts を実装している 71 行目から 84 行目に注目します。

          if attempts == :unlimited || executions < attempts
	    # ジョブをリトライする
          else
	    # ジョブのリトライをストップする。ブロックが渡されていればブロックを実行する。
          end

attemptsexecutions(実行回数) 未満のときだけリトライする」というロジックになっています。
言い換えると「リトライ回数は ( attempts - 1 ) である」ということです。
例えば attempts3 を指定した場合、リトライ回数は2回である、ということです。

attempts オプションの実際のリトライ挙動

実際に「リトライ回数は ( attempts - 1 ) である」という挙動になるのか検証しました。

  • 検証コード
class TestJob < ApplicationJob
  class TestError < StandardError; end

  retry_on TestError, attempts: 3 do
    Rails.logger.info '=== Finished retry_on TestError ==='
  end

  def perform
    $times ||= 0
    $times += 1
    Rails.logger.info "=== Performed TestJob #{$times} times ==="
    raise TestError
  end
end

rails console を起動し、TestJob.perform_later を実行します。
実行後、出力されたログは以下のとおりです。

Performing TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) from Sidekiq(default) enqueued at 2023-12-06T00:54:25Z
=== Performed TestJob 1 times ===
Enqueued TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) to Sidekiq(default) at 2023-12-06 00:54:29 UTC
Retrying TestJob in 3 seconds, due to a TestJob::TestError.
Performed TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) from Sidekiq(default) in 29.87ms
Performing TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) from Sidekiq(default) enqueued at 2023-12-06T00:54:26Z
=== Performed TestJob 2 times ===
Enqueued TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) to Sidekiq(default) at 2023-12-06 00:54:32 UTC
Retrying TestJob in 3 seconds, due to a TestJob::TestError.
Performed TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) from Sidekiq(default) in 6.22ms
Performing TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) from Sidekiq(default) enqueued at 2023-12-06T00:54:29Z
=== Performed TestJob 3 times ===
=== Finished retry_on TestError ===
Stopped retrying TestJob due to a TestJob::TestError, which reoccurred on 3 attempts.
Performed TestJob (Job ID: fad1212e-c63b-47e2-b3cf-b4ac6298a3ba) from Sidekiq(default) in 6.59ms

※ ログを見やすくするために不要なデータを削除しています。

Performed TestJob 3 times と出力されました。
3 には最初のジョブの実行も含まれるため、リトライされたのは「2回」です。
「リトライ回数は ( attempts - 1 ) である」と前述したとおりの結果になりました。

attempts が 0 のとき

念のため「attempts が 0」のときを検証したところ、リトライ回数は 0 でした。

Performing TestJob (Job ID: bb154ebd-da69-419c-9c3b-29881d3d7522) from Sidekiq(default) enqueued at 2023-12-06T00:57:10Z
=== Performed TestJob 1 times ===
=== Finished retry_on TestError ===
Stopped retrying TestJob due to a TestJob::TestError, which reoccurred on 1 attempts.
Performed TestJob (Job ID: bb154ebd-da69-419c-9c3b-29881d3d7522) from Sidekiq(default) in 12.65ms

attempts が 1」のときもリトライ回数は 0 になりました。

Performing TestJob (Job ID: cf3cef37-1394-4345-9551-a9f78b87f54b) from Sidekiq(default) enqueued at 2023-12-06T00:59:05Z
=== Performed TestJob 1 times ===
=== Finished retry_on TestError ===
Stopped retrying TestJob due to a TestJob::TestError, which reoccurred on 1 attempts.
Performed TestJob (Job ID: cf3cef37-1394-4345-9551-a9f78b87f54b) from Sidekiq(default) in 22.56ms

ドキュメントの明確化に向けた進展

ActiveJobretry_onattempts について、最近の Pull Request で説明が追加されました。
これは、attempts オプションの挙動に関する誤解を解消するための一歩です。

  • Pull Requestの内容: rails/rails#49394
    • 追記内容: "The number of attempts includes the original job execution."
    • 和訳: "attempts の数には、オリジナルのジョブの実行回数も含まれる。"

現時点では、この更新は最新の安定バージョンである 7.1.3 のドキュメント にはまだ反映されていませんが、将来的にはドキュメントにも組み込まれる可能性が高いです。

実装とドキュメントのバランス

Pull Request( rails/rails#49394 ) の本文には、「非互換になるため実装の修正はせず、説明を修正した」との記載があります。
私の意見としては、attempts が直感的に理解しやすいように、つまり「attempts = リトライ回数」となるように実装自体を修正することを望んでいます。
しかし、既存のコードベースへの影響を考慮すると、変更は問題を引き起こす可能性があるため、簡単に変更できることではないと思っています。

まとめ

この記事を通じて、Ruby on Rails の ActiveJob における retry_on メソッドの attempts オプションの挙動について解説しました。
ポイントは以下の通りです。

  • retry_onattempts オプションは、最初の実行を含めた回数である
  • 実際のリトライ回数は、attempts - 1 である
  • この挙動に関する誤解が少なくなるようドキュメントの更新が行われる予定である

システムの安定性と効率を保つためには、ジョブのリトライ回数と間隔を適切に設定することが重要です。
エラーのリトライ回数を正確に制御し、システムのリソースを無駄に消費することがない効率的なジョブのリトライ戦略を立てるようにしましょう。

SocialPLUS Tech Blog

Discussion