1
0
Fork 0
mirror of https://github.com/rails/rails.git synced 2022-11-09 12:12:34 -05:00

Improve enqueue_retry.active_job message

Since #33751 was added `enqueue_retry.active_job` instrumentation to
the `retry_on` method, then #33897 moved the instrumentation to `retry_job`
method in order to ensure that this method publish `enqueue_retry.active_job`
notification too.
See related discussion https://github.com/rails/rails/pull/33751#discussion_r214140008

Since `enqueue_retry.active_job` moved to `retry_job`, there is no guarantee
that payload of `enqueue_retry.active_job` would have `:error`.
See test `LoggingTest#test_enqueue_retry_logging_on_retry_job` as
example of that case.

Related to https://github.com/rails/rails/pull/33897#discussion_r219707024

I think we can improve notification of `enqueue_retry.active_job`:

- If there is no `event.payload[:error]`, then publish like
  "Retrying RescueJob in 3 seconds." only.
- If `event.payload[:wait]` is `nil`, then publish
  "Retrying RescueJob in 0 seconds." instead of "Retrying RescueJob in nil seconds."
- If there is `event.payload[:error]`, then publish
  "Retrying RescueJob in 3 seconds, due to a DefaultsError.".
- Change the type of the message from `error` to `info.`

Also, this commit removes part of messages - "The original exception was #{ex.cause.inspect}."
of `enqueue_retry.active_job`, `retry_stopped.active_job`, and `discard.active_job` since I
haven't found it useful. Please let me know whether you agree with that?
This commit is contained in:
bogdanvlviv 2018-09-25 00:54:05 +03:00
parent 06274428e5
commit b0f2f5e348
No known key found for this signature in database
GPG key ID: E4ACD76A6DB6DFDD
2 changed files with 13 additions and 9 deletions

View file

@ -93,8 +93,12 @@ module ActiveJob
ex = event.payload[:error] ex = event.payload[:error]
wait = event.payload[:wait] wait = event.payload[:wait]
error do info do
"Retrying #{job.class} in #{wait.inspect} seconds, due to a #{ex&.class.inspect}. The original exception was #{ex&.cause.inspect}." if ex
"Retrying #{job.class} in #{wait.to_i} seconds, due to a #{ex.class}."
else
"Retrying #{job.class} in #{wait.to_i} seconds."
end
end end
end end
@ -103,7 +107,7 @@ module ActiveJob
ex = event.payload[:error] ex = event.payload[:error]
error do error do
"Stopped retrying #{job.class} due to a #{ex.class}, which reoccurred on #{job.executions} attempts. The original exception was #{ex.cause.inspect}." "Stopped retrying #{job.class} due to a #{ex.class}, which reoccurred on #{job.executions} attempts."
end end
end end
@ -112,7 +116,7 @@ module ActiveJob
ex = event.payload[:error] ex = event.payload[:error]
error do error do
"Discarded #{job.class} due to a #{ex.class}. The original exception was #{ex.cause.inspect}." "Discarded #{job.class} due to a #{ex.class}."
end end
end end

View file

@ -169,19 +169,19 @@ class LoggingTest < ActiveSupport::TestCase
def test_enqueue_retry_logging def test_enqueue_retry_logging
perform_enqueued_jobs do perform_enqueued_jobs do
RetryJob.perform_later "DefaultsError", 2 RetryJob.perform_later "DefaultsError", 2
assert_match(/Retrying RetryJob in \d+ seconds, due to a DefaultsError\. The original exception was nil\./, @logger.messages) assert_match(/Retrying RetryJob in 3 seconds, due to a DefaultsError\./, @logger.messages)
end end
end end
def test_enqueue_retry_logging_on_retry_job def test_enqueue_retry_logging_on_retry_job
perform_enqueued_jobs { RescueJob.perform_later "david" } perform_enqueued_jobs { RescueJob.perform_later "david" }
assert_match(/Retrying RescueJob in nil seconds, due to a nil\. The original exception was nil\./, @logger.messages) assert_match(/Retrying RescueJob in 0 seconds\./, @logger.messages)
end end
def test_retry_stopped_logging def test_retry_stopped_logging
perform_enqueued_jobs do perform_enqueued_jobs do
RetryJob.perform_later "CustomCatchError", 6 RetryJob.perform_later "CustomCatchError", 6
assert_match(/Stopped retrying RetryJob due to a CustomCatchError, which reoccurred on \d+ attempts\. The original exception was #<CustomCatchError: CustomCatchError>\./, @logger.messages) assert_match(/Stopped retrying RetryJob due to a CustomCatchError, which reoccurred on \d+ attempts\./, @logger.messages)
end end
end end
@ -190,7 +190,7 @@ class LoggingTest < ActiveSupport::TestCase
begin begin
RetryJob.perform_later "DefaultsError", 6 RetryJob.perform_later "DefaultsError", 6
rescue DefaultsError rescue DefaultsError
assert_match(/Stopped retrying RetryJob due to a DefaultsError, which reoccurred on \d+ attempts\. The original exception was #<DefaultsError: DefaultsError>\./, @logger.messages) assert_match(/Stopped retrying RetryJob due to a DefaultsError, which reoccurred on \d+ attempts\./, @logger.messages)
end end
end end
end end
@ -198,7 +198,7 @@ class LoggingTest < ActiveSupport::TestCase
def test_discard_logging def test_discard_logging
perform_enqueued_jobs do perform_enqueued_jobs do
RetryJob.perform_later "DiscardableError", 2 RetryJob.perform_later "DiscardableError", 2
assert_match(/Discarded RetryJob due to a DiscardableError\. The original exception was nil\./, @logger.messages) assert_match(/Discarded RetryJob due to a DiscardableError\./, @logger.messages)
end end
end end
end end