From 3aacd855cdb5b4543f3b31cd2fa9a5242a8d618e Mon Sep 17 00:00:00 2001 From: Aditya Narsapurkar Date: Sat, 22 Feb 2020 01:45:02 +0530 Subject: [PATCH] parent 6d0895a4894724e1a923a514daad8fb3c9ac2c28 author Aditya Narsapurkar 1582316102 +0530 committer Aditya Narsapurkar 1583159505 +0530 parent 6d0895a4894724e1a923a514daad8fb3c9ac2c28 author Aditya Narsapurkar 1582316102 +0530 committer Aditya Narsapurkar 1583159327 +0530 Randomize jitter - This PR attempts to fix a problem with ActiveJob jitter where the `determine_jitter_for_delay` value may not always be randomized. Especially when the jitter delay multplier is between 1 and 2 it always returns 0. - With this change, we pass a range to `Kernel.rand` beginning with 0 to the `jitter_multiplier`. With positive float values, the return value will be a random float number from the range. - Includes test cases to verify random wait time when the jitter_multiplier is between 1 and 2. - Updated relevant test cases stubbing the `Kernel.rand` method, refactored some by removing unwanted stubs for `Kernel.rand` method where jitter is falsey. Fixed rubocop issue - used assert_not_equal instead of refute_equal in test case Fixed rubocop issue - used assert_not_equal instead of refute_equal in test case Fixed rubocop issue - used assert_not_equal instead of refute_equal in test case Review updates - separated test cases for random wait time with default and exponentially retrying jobs - Another test case added to make sure negative wait time does not affect the randomization Review updates - Instead of using Kernel.rand with range, used simple multiplication with Kernel.rand for calculating delay for jitter - Updates to the tests according to changes --- activejob/lib/active_job/exceptions.rb | 2 +- activejob/test/cases/exceptions_test.rb | 109 ++++++++++++++++++------ 2 files changed, 82 insertions(+), 29 deletions(-) diff --git a/activejob/lib/active_job/exceptions.rb b/activejob/lib/active_job/exceptions.rb index 1f397547ad..d51c4bda4e 100644 --- a/activejob/lib/active_job/exceptions.rb +++ b/activejob/lib/active_job/exceptions.rb @@ -151,7 +151,7 @@ module ActiveJob def determine_jitter_for_delay(delay, jitter) return 0.0 if jitter.zero? - Kernel.rand(delay * jitter) + Kernel.rand * delay * jitter end def executions_for(exceptions) diff --git a/activejob/test/cases/exceptions_test.rb b/activejob/test/cases/exceptions_test.rb index 71d9a20923..5555b51b0a 100644 --- a/activejob/test/cases/exceptions_test.rb +++ b/activejob/test/cases/exceptions_test.rb @@ -96,12 +96,13 @@ class ExceptionsTest < ActiveSupport::TestCase test "long wait job" do travel_to Time.now random_amount = 1 + delay_for_jitter = random_amount * 3600 * ActiveJob::Base.retry_jitter Kernel.stub(:rand, random_amount) do RetryJob.perform_later "LongWaitError", 2, :log_scheduled_at assert_equal [ "Raised LongWaitError for the 1st time", - "Next execution scheduled at #{(Time.now + 3600.seconds + random_amount).to_f}", + "Next execution scheduled at #{(Time.now + 3600.seconds + delay_for_jitter).to_f}", "Successfully completed job" ], JobBuffer.values end @@ -111,19 +112,20 @@ class ExceptionsTest < ActiveSupport::TestCase travel_to Time.now random_amount = 2 + delay_for_jitter = -> (delay) { random_amount * delay * ActiveJob::Base.retry_jitter } Kernel.stub(:rand, random_amount) do RetryJob.perform_later "ExponentialWaitTenAttemptsError", 5, :log_scheduled_at assert_equal [ "Raised ExponentialWaitTenAttemptsError for the 1st time", - "Next execution scheduled at #{(Time.now + 3.seconds + random_amount).to_f}", + "Next execution scheduled at #{(Time.now + 3.seconds + delay_for_jitter.(1)).to_f}", "Raised ExponentialWaitTenAttemptsError for the 2nd time", - "Next execution scheduled at #{(Time.now + 18.seconds + random_amount).to_f}", + "Next execution scheduled at #{(Time.now + 18.seconds + delay_for_jitter.(16)).to_f}", "Raised ExponentialWaitTenAttemptsError for the 3rd time", - "Next execution scheduled at #{(Time.now + 83.seconds + random_amount).to_f}", + "Next execution scheduled at #{(Time.now + 83.seconds + delay_for_jitter.(81)).to_f}", "Raised ExponentialWaitTenAttemptsError for the 4th time", - "Next execution scheduled at #{(Time.now + 258.seconds + random_amount).to_f}", + "Next execution scheduled at #{(Time.now + 258.seconds + delay_for_jitter.(256)).to_f}", "Successfully completed job" ], JobBuffer.values end @@ -135,7 +137,9 @@ class ExceptionsTest < ActiveSupport::TestCase travel_to Time.now - Kernel.stub(:rand, ->(arg) { arg }) do + random_amount = 1 + + Kernel.stub(:rand, random_amount) do RetryJob.perform_later "ExponentialWaitTenAttemptsError", 5, :log_scheduled_at assert_equal [ @@ -154,36 +158,83 @@ class ExceptionsTest < ActiveSupport::TestCase ActiveJob::Base.retry_jitter = old_jitter end + 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 + test "retry jitter disabled with nil" do travel_to Time.now - Kernel.stub(:rand, ->(arg) { arg }) do - RetryJob.perform_later "DisabledJitterError", 3, :log_scheduled_at + RetryJob.perform_later "DisabledJitterError", 3, :log_scheduled_at - 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 - end + 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 end test "retry jitter disabled with zero" do travel_to Time.now - Kernel.stub(:rand, ->(arg) { arg }) do - RetryJob.perform_later "ZeroJitterError", 3, :log_scheduled_at + RetryJob.perform_later "ZeroJitterError", 3, :log_scheduled_at - 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 - end + 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 end test "custom wait retrying job" do @@ -214,13 +265,15 @@ class ExceptionsTest < ActiveSupport::TestCase Kernel.stub(:rand, random_amount) do RetryJob.perform_later exceptions_to_raise, 5, :log_scheduled_at + delay_for_jitter = -> (delay) { random_amount * delay * ActiveJob::Base.retry_jitter } + assert_equal [ "Raised ExponentialWaitTenAttemptsError for the 1st time", - "Next execution scheduled at #{(Time.now + 3.seconds + random_amount).to_f}", + "Next execution scheduled at #{(Time.now + 3.seconds + delay_for_jitter.(1)).to_f}", "Raised CustomWaitTenAttemptsError for the 2nd time", "Next execution scheduled at #{(Time.now + 2.seconds).to_f}", "Raised ExponentialWaitTenAttemptsError for the 3rd time", - "Next execution scheduled at #{(Time.now + 18.seconds + random_amount).to_f}", + "Next execution scheduled at #{(Time.now + 18.seconds + delay_for_jitter.(16)).to_f}", "Raised CustomWaitTenAttemptsError for the 4th time", "Next execution scheduled at #{(Time.now + 4.seconds).to_f}", "Successfully completed job"