2017-07-09 13:49:52 -04:00
|
|
|
# frozen_string_literal: true
|
2017-07-10 09:40:03 -04:00
|
|
|
|
2016-08-06 12:41:18 -04:00
|
|
|
require "helper"
|
|
|
|
require "jobs/retry_job"
|
2018-07-25 04:30:38 -04:00
|
|
|
require "models/person"
|
2018-02-02 11:50:57 -05:00
|
|
|
require "minitest/mock"
|
2016-07-29 16:54:55 -04:00
|
|
|
|
2019-01-07 08:36:56 -05:00
|
|
|
class ExceptionsTest < ActiveSupport::TestCase
|
2016-07-29 16:54:55 -04:00
|
|
|
setup do
|
|
|
|
JobBuffer.clear
|
2019-01-07 08:36:56 -05:00
|
|
|
skip if adapter_skips_scheduling?(ActiveJob::Base.queue_adapter)
|
2016-07-29 16:54:55 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
test "successfully retry job throwing exception against defaults" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "DefaultsError", 5
|
2016-07-29 16:59:40 -04:00
|
|
|
|
2019-01-07 08:36:56 -05:00
|
|
|
assert_equal [
|
|
|
|
"Raised DefaultsError for the 1st time",
|
|
|
|
"Raised DefaultsError for the 2nd time",
|
|
|
|
"Raised DefaultsError for the 3rd time",
|
|
|
|
"Raised DefaultsError for the 4th time",
|
|
|
|
"Successfully completed job" ], JobBuffer.values
|
2016-07-29 16:54:55 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
test "successfully retry job throwing exception against higher limit" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "ShortWaitTenAttemptsError", 9
|
|
|
|
assert_equal 9, JobBuffer.values.count
|
2016-07-29 16:54:55 -04:00
|
|
|
end
|
2016-07-29 16:59:40 -04:00
|
|
|
|
2019-01-04 19:54:38 -05:00
|
|
|
test "keeps the same attempts counter for several exceptions listed in the same retry_on declaration" do
|
2018-11-23 14:31:14 -05:00
|
|
|
exceptions_to_raise = %w(FirstRetryableErrorOfTwo FirstRetryableErrorOfTwo FirstRetryableErrorOfTwo
|
|
|
|
SecondRetryableErrorOfTwo SecondRetryableErrorOfTwo)
|
|
|
|
|
|
|
|
assert_raises SecondRetryableErrorOfTwo do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later(exceptions_to_raise, 5)
|
2019-01-04 19:54:38 -05:00
|
|
|
|
|
|
|
assert_equal [
|
|
|
|
"Raised FirstRetryableErrorOfTwo for the 1st time",
|
|
|
|
"Raised FirstRetryableErrorOfTwo for the 2nd time",
|
|
|
|
"Raised FirstRetryableErrorOfTwo for the 3rd time",
|
|
|
|
"Raised SecondRetryableErrorOfTwo for the 4th time",
|
|
|
|
"Raised SecondRetryableErrorOfTwo for the 5th time",
|
|
|
|
], JobBuffer.values
|
2018-11-23 14:31:14 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2019-01-04 19:54:38 -05:00
|
|
|
test "keeps a separate attempts counter for each individual retry_on declaration" do
|
|
|
|
exceptions_to_raise = %w(DefaultsError DefaultsError DefaultsError DefaultsError
|
|
|
|
FirstRetryableErrorOfTwo FirstRetryableErrorOfTwo FirstRetryableErrorOfTwo)
|
2018-11-23 14:31:14 -05:00
|
|
|
|
|
|
|
assert_nothing_raised do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later(exceptions_to_raise, 10)
|
2019-01-04 19:54:38 -05:00
|
|
|
|
|
|
|
assert_equal [
|
|
|
|
"Raised DefaultsError for the 1st time",
|
|
|
|
"Raised DefaultsError for the 2nd time",
|
|
|
|
"Raised DefaultsError for the 3rd time",
|
|
|
|
"Raised DefaultsError for the 4th time",
|
|
|
|
"Raised FirstRetryableErrorOfTwo for the 5th time",
|
|
|
|
"Raised FirstRetryableErrorOfTwo for the 6th time",
|
|
|
|
"Raised FirstRetryableErrorOfTwo for the 7th time",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
2018-11-23 14:31:14 -05:00
|
|
|
end
|
|
|
|
end
|
|
|
|
|
2016-07-29 16:54:55 -04:00
|
|
|
test "failed retry job when exception kept occurring against defaults" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "DefaultsError", 6
|
|
|
|
assert_equal "Raised DefaultsError for the 5th time", JobBuffer.last_value
|
|
|
|
rescue DefaultsError
|
|
|
|
pass
|
2016-07-29 16:54:55 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
test "failed retry job when exception kept occurring against higher limit" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "ShortWaitTenAttemptsError", 11
|
|
|
|
assert_equal "Raised ShortWaitTenAttemptsError for the 10th time", JobBuffer.last_value
|
|
|
|
rescue ShortWaitTenAttemptsError
|
|
|
|
pass
|
2016-07-29 16:54:55 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
test "discard job" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "DiscardableError", 2
|
|
|
|
assert_equal "Raised DiscardableError for the 1st time", JobBuffer.last_value
|
2016-07-29 16:54:55 -04:00
|
|
|
end
|
2016-08-02 15:28:16 -04:00
|
|
|
|
2017-09-16 14:59:32 -04:00
|
|
|
test "custom handling of discarded job" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "CustomDiscardableError", 2
|
|
|
|
assert_equal "Dealt with a job that was discarded in a custom way. Message: CustomDiscardableError", JobBuffer.last_value
|
2017-09-16 14:59:32 -04:00
|
|
|
end
|
|
|
|
|
2016-08-01 19:51:11 -04:00
|
|
|
test "custom handling of job that exceeds retry attempts" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "CustomCatchError", 6
|
|
|
|
assert_equal "Dealt with a job that failed to retry in a custom way after 6 attempts. Message: CustomCatchError", JobBuffer.last_value
|
2016-08-01 19:51:11 -04:00
|
|
|
end
|
2016-08-01 19:44:29 -04:00
|
|
|
|
2016-08-02 17:26:56 -04:00
|
|
|
test "long wait job" do
|
|
|
|
travel_to Time.now
|
2018-02-02 11:50:57 -05:00
|
|
|
random_amount = 1
|
2020-02-21 15:15:02 -05:00
|
|
|
delay_for_jitter = random_amount * 3600 * ActiveJob::Base.retry_jitter
|
2016-08-06 13:55:02 -04:00
|
|
|
|
2018-02-02 11:50:57 -05:00
|
|
|
Kernel.stub(:rand, random_amount) do
|
|
|
|
RetryJob.perform_later "LongWaitError", 2, :log_scheduled_at
|
|
|
|
assert_equal [
|
|
|
|
"Raised LongWaitError for the 1st time",
|
2020-02-21 15:15:02 -05:00
|
|
|
"Next execution scheduled at #{(Time.now + 3600.seconds + delay_for_jitter).to_f}",
|
2018-02-02 11:50:57 -05:00
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
|
|
|
end
|
2016-08-01 19:44:29 -04:00
|
|
|
end
|
|
|
|
|
2018-02-02 11:50:57 -05:00
|
|
|
test "exponentially retrying job includes jitter" do
|
2016-08-01 19:44:29 -04:00
|
|
|
travel_to Time.now
|
|
|
|
|
2018-02-02 11:50:57 -05:00
|
|
|
random_amount = 2
|
2020-02-21 15:15:02 -05:00
|
|
|
delay_for_jitter = -> (delay) { random_amount * delay * ActiveJob::Base.retry_jitter }
|
2019-01-07 08:36:56 -05:00
|
|
|
|
2018-02-02 11:50:57 -05:00
|
|
|
Kernel.stub(:rand, random_amount) do
|
|
|
|
RetryJob.perform_later "ExponentialWaitTenAttemptsError", 5, :log_scheduled_at
|
|
|
|
|
|
|
|
assert_equal [
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 1st time",
|
2020-02-21 15:15:02 -05:00
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds + delay_for_jitter.(1)).to_f}",
|
2018-02-02 11:50:57 -05:00
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 2nd time",
|
2020-02-21 15:15:02 -05:00
|
|
|
"Next execution scheduled at #{(Time.now + 18.seconds + delay_for_jitter.(16)).to_f}",
|
2018-02-02 11:50:57 -05:00
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 3rd time",
|
2020-02-21 15:15:02 -05:00
|
|
|
"Next execution scheduled at #{(Time.now + 83.seconds + delay_for_jitter.(81)).to_f}",
|
2018-02-02 11:50:57 -05:00
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 4th time",
|
2020-02-21 15:15:02 -05:00
|
|
|
"Next execution scheduled at #{(Time.now + 258.seconds + delay_for_jitter.(256)).to_f}",
|
2018-02-02 11:50:57 -05:00
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
|
|
|
end
|
2016-08-01 19:44:29 -04:00
|
|
|
end
|
|
|
|
|
2019-12-12 19:42:58 -05:00
|
|
|
test "retry jitter uses value from ActiveJob::Base.retry_jitter by default" do
|
|
|
|
old_jitter = ActiveJob::Base.retry_jitter
|
|
|
|
ActiveJob::Base.retry_jitter = 4.0
|
2019-12-09 14:48:14 -05:00
|
|
|
|
|
|
|
travel_to Time.now
|
|
|
|
|
2020-02-21 15:15:02 -05:00
|
|
|
random_amount = 1
|
|
|
|
|
|
|
|
Kernel.stub(:rand, random_amount) do
|
2019-12-09 14:48:14 -05:00
|
|
|
RetryJob.perform_later "ExponentialWaitTenAttemptsError", 5, :log_scheduled_at
|
|
|
|
|
|
|
|
assert_equal [
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 1st time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 7.seconds).to_f}",
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 2nd time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 82.seconds).to_f}",
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 3rd time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 407.seconds).to_f}",
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 4th time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 1282.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
|
|
|
end
|
|
|
|
ensure
|
2019-12-12 19:42:58 -05:00
|
|
|
ActiveJob::Base.retry_jitter = old_jitter
|
2019-12-09 14:48:14 -05:00
|
|
|
end
|
|
|
|
|
2020-02-21 15:15:02 -05:00
|
|
|
test "random wait time for default job when retry jitter delay multiplier value is between 1 and 2" do
|
|
|
|
old_jitter = ActiveJob::Base.retry_jitter
|
|
|
|
ActiveJob::Base.retry_jitter = 0.6
|
|
|
|
|
|
|
|
travel_to Time.now
|
|
|
|
|
|
|
|
RetryJob.perform_later "DefaultsError", 2, :log_scheduled_at
|
|
|
|
|
|
|
|
assert_not_equal [
|
|
|
|
"Raised DefaultsError for the 1st time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
|
|
|
ensure
|
|
|
|
ActiveJob::Base.retry_jitter = old_jitter
|
|
|
|
end
|
|
|
|
|
|
|
|
test "random wait time for exponentially retrying job when retry jitter delay multiplier value is between 1 and 2" do
|
|
|
|
old_jitter = ActiveJob::Base.retry_jitter
|
|
|
|
ActiveJob::Base.retry_jitter = 1.2
|
|
|
|
|
|
|
|
travel_to Time.now
|
|
|
|
|
|
|
|
RetryJob.perform_later "ExponentialWaitTenAttemptsError", 2, :log_scheduled_at
|
|
|
|
|
|
|
|
assert_not_equal [
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 1st time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
|
|
|
ensure
|
|
|
|
ActiveJob::Base.retry_jitter = old_jitter
|
|
|
|
end
|
|
|
|
|
|
|
|
test "random wait time for negative jitter value" do
|
|
|
|
old_jitter = ActiveJob::Base.retry_jitter
|
|
|
|
ActiveJob::Base.retry_jitter = -1.2
|
|
|
|
|
|
|
|
travel_to Time.now
|
|
|
|
|
|
|
|
RetryJob.perform_later "ExponentialWaitTenAttemptsError", 2, :log_scheduled_at
|
|
|
|
|
|
|
|
assert_not_equal [
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 1st time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
|
|
|
ensure
|
|
|
|
ActiveJob::Base.retry_jitter = old_jitter
|
|
|
|
end
|
|
|
|
|
2019-12-17 13:23:52 -05:00
|
|
|
test "retry jitter disabled with nil" do
|
|
|
|
travel_to Time.now
|
|
|
|
|
2020-02-21 15:15:02 -05:00
|
|
|
RetryJob.perform_later "DisabledJitterError", 3, :log_scheduled_at
|
2019-12-17 13:23:52 -05:00
|
|
|
|
2020-02-21 15:15:02 -05:00
|
|
|
assert_equal [
|
|
|
|
"Raised DisabledJitterError for the 1st time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds).to_f}",
|
|
|
|
"Raised DisabledJitterError for the 2nd time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
2019-12-17 13:23:52 -05:00
|
|
|
end
|
|
|
|
|
|
|
|
test "retry jitter disabled with zero" do
|
|
|
|
travel_to Time.now
|
|
|
|
|
2020-02-21 15:15:02 -05:00
|
|
|
RetryJob.perform_later "ZeroJitterError", 3, :log_scheduled_at
|
2019-12-17 13:23:52 -05:00
|
|
|
|
2020-02-21 15:15:02 -05:00
|
|
|
assert_equal [
|
|
|
|
"Raised ZeroJitterError for the 1st time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds).to_f}",
|
|
|
|
"Raised ZeroJitterError for the 2nd time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
2019-12-17 13:23:52 -05:00
|
|
|
end
|
|
|
|
|
2016-08-01 19:44:29 -04:00
|
|
|
test "custom wait retrying job" do
|
|
|
|
travel_to Time.now
|
|
|
|
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "CustomWaitTenAttemptsError", 5, :log_scheduled_at
|
|
|
|
|
|
|
|
assert_equal [
|
|
|
|
"Raised CustomWaitTenAttemptsError for the 1st time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 2.seconds).to_f}",
|
|
|
|
"Raised CustomWaitTenAttemptsError for the 2nd time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 4.seconds).to_f}",
|
|
|
|
"Raised CustomWaitTenAttemptsError for the 3rd time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 6.seconds).to_f}",
|
|
|
|
"Raised CustomWaitTenAttemptsError for the 4th time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 8.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
2016-08-01 19:44:29 -04:00
|
|
|
end
|
2018-06-25 18:16:58 -04:00
|
|
|
|
2019-04-12 11:24:05 -04:00
|
|
|
test "use individual execution timers when calculating retry delay" do
|
|
|
|
travel_to Time.now
|
|
|
|
|
|
|
|
exceptions_to_raise = %w(ExponentialWaitTenAttemptsError CustomWaitTenAttemptsError ExponentialWaitTenAttemptsError CustomWaitTenAttemptsError)
|
|
|
|
|
2018-02-02 11:50:57 -05:00
|
|
|
random_amount = 1
|
2019-04-12 11:24:05 -04:00
|
|
|
|
2018-02-02 11:50:57 -05:00
|
|
|
Kernel.stub(:rand, random_amount) do
|
|
|
|
RetryJob.perform_later exceptions_to_raise, 5, :log_scheduled_at
|
|
|
|
|
2020-02-21 15:15:02 -05:00
|
|
|
delay_for_jitter = -> (delay) { random_amount * delay * ActiveJob::Base.retry_jitter }
|
|
|
|
|
2018-02-02 11:50:57 -05:00
|
|
|
assert_equal [
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 1st time",
|
2020-02-21 15:15:02 -05:00
|
|
|
"Next execution scheduled at #{(Time.now + 3.seconds + delay_for_jitter.(1)).to_f}",
|
2018-02-02 11:50:57 -05:00
|
|
|
"Raised CustomWaitTenAttemptsError for the 2nd time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 2.seconds).to_f}",
|
|
|
|
"Raised ExponentialWaitTenAttemptsError for the 3rd time",
|
2020-02-21 15:15:02 -05:00
|
|
|
"Next execution scheduled at #{(Time.now + 18.seconds + delay_for_jitter.(16)).to_f}",
|
2018-02-02 11:50:57 -05:00
|
|
|
"Raised CustomWaitTenAttemptsError for the 4th time",
|
|
|
|
"Next execution scheduled at #{(Time.now + 4.seconds).to_f}",
|
|
|
|
"Successfully completed job"
|
|
|
|
], JobBuffer.values
|
|
|
|
end
|
2019-04-12 11:24:05 -04:00
|
|
|
end
|
|
|
|
|
2018-06-25 18:16:58 -04:00
|
|
|
test "successfully retry job throwing one of two retryable exceptions" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "SecondRetryableErrorOfTwo", 3
|
2018-06-25 18:16:58 -04:00
|
|
|
|
2019-01-07 08:36:56 -05:00
|
|
|
assert_equal [
|
|
|
|
"Raised SecondRetryableErrorOfTwo for the 1st time",
|
|
|
|
"Raised SecondRetryableErrorOfTwo for the 2nd time",
|
|
|
|
"Successfully completed job" ], JobBuffer.values
|
2018-06-25 18:16:58 -04:00
|
|
|
end
|
|
|
|
|
|
|
|
test "discard job throwing one of two discardable exceptions" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later "SecondDiscardableErrorOfTwo", 2
|
|
|
|
assert_equal [ "Raised SecondDiscardableErrorOfTwo for the 1st time" ], JobBuffer.values
|
2018-06-25 18:16:58 -04:00
|
|
|
end
|
2018-07-25 04:30:38 -04:00
|
|
|
|
|
|
|
test "successfully retry job throwing DeserializationError" do
|
2019-01-07 08:36:56 -05:00
|
|
|
RetryJob.perform_later Person.new(404), 5
|
|
|
|
assert_equal ["Raised ActiveJob::DeserializationError for the 5 time"], JobBuffer.values
|
2018-07-25 04:30:38 -04:00
|
|
|
end
|
2019-01-07 08:36:56 -05:00
|
|
|
|
2019-04-22 14:39:23 -04:00
|
|
|
test "running a job enqueued by AJ 5.2" do
|
|
|
|
job = RetryJob.new("DefaultsError", 6)
|
|
|
|
job.exception_executions = nil # This is how jobs from Rails 5.2 will look
|
|
|
|
|
|
|
|
assert_raises DefaultsError do
|
|
|
|
job.enqueue
|
|
|
|
end
|
|
|
|
|
|
|
|
assert_equal 5, JobBuffer.values.count
|
|
|
|
end
|
|
|
|
|
|
|
|
test "running a job enqueued and attempted under AJ 5.2" do
|
|
|
|
job = RetryJob.new("DefaultsError", 6)
|
|
|
|
|
|
|
|
# Fake 4 previous executions under AJ 5.2
|
|
|
|
job.exception_executions = nil
|
|
|
|
job.executions = 4
|
|
|
|
|
|
|
|
assert_raises DefaultsError do
|
|
|
|
job.enqueue
|
|
|
|
end
|
|
|
|
|
|
|
|
assert_equal ["Raised DefaultsError for the 5th time"], JobBuffer.values
|
|
|
|
end
|
|
|
|
|
2019-01-07 08:36:56 -05:00
|
|
|
private
|
|
|
|
def adapter_skips_scheduling?(queue_adapter)
|
|
|
|
[
|
|
|
|
ActiveJob::QueueAdapters::InlineAdapter,
|
|
|
|
ActiveJob::QueueAdapters::AsyncAdapter,
|
|
|
|
ActiveJob::QueueAdapters::SneakersAdapter
|
|
|
|
].include?(queue_adapter.class)
|
|
|
|
end
|
2016-08-02 15:28:16 -04:00
|
|
|
end
|