Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve enqueue_retry.active_job message #33972

Merged
merged 1 commit into from Oct 30, 2018

Conversation

bogdanvlviv
Copy link
Contributor

@bogdanvlviv bogdanvlviv commented Sep 24, 2018

Since #33751 enqueue_retry.active_job instrumentation was added 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 #33751 (comment)

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 #33897 (comment)

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?

r? @kaspth

Since rails#33751 was added `enqueue_retry.active_job` instrumentation to
the `retry_on` method, then rails#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 rails#33751 (comment)

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 rails#33897 (comment)

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?
@rafaelfranca
Copy link
Member

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?

It is hard to judge that without knowing what that entails. Which information was present in that part of the message that you think it is not useful? Is the exception cause usually blank or is it easy to know what is the cause of the exception? If not how can someone see the cause of the exception easily? Maybe we should keep that part of the message but with a debug level?

@bogdanvlviv
Copy link
Contributor Author

bogdanvlviv commented Oct 4, 2018

My judgement was like kind of question since it was based on the test asserting a message "Stopped retrying RetryJob due to a DefaultsError, which reoccurred on 3 attempts. The original exception was #<DefaultsError: DefaultsError>."

def test_retry_stopped_logging_without_block
perform_enqueued_jobs do
begin
RetryJob.perform_later "DefaultsError", 6
rescue DefaultsError
assert_match(/Stopped retrying RetryJob due to a DefaultsError, which reoccurred on \d+ attempts\. The original exception was #<DefaultsError: DefaultsError>\./, @logger.messages)
end
end

Seems like enough only to the first part of the message to understand by which kind of exception it was caused - "Stopped retrying RetryJob due to a DefaultsError, which reoccurred on 3 attempts".
The second part is "The original exception was #<DefaultsError: DefaultsError>.".
Unfortunately, I don't have the example that would emphasize that we need the second part of the message. If you have the example, please share.

@bogdanvlviv
Copy link
Contributor Author

Let me know if there is anything I should change/fix.

@rafaelfranca rafaelfranca merged commit f487654 into rails:master Oct 30, 2018
@bogdanvlviv bogdanvlviv deleted the follow-up-33897 branch October 30, 2018 20:57
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

4 participants