From b0f2f5e348a409d52f126c446951fa4397a56302 Mon Sep 17 00:00:00 2001
From: bogdanvlviv <bogdanvlviv@gmail.com>
Date: Tue, 25 Sep 2018 00:54:05 +0300
Subject: [PATCH] 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?
---
 activejob/lib/active_job/logging.rb  | 12 ++++++++----
 activejob/test/cases/logging_test.rb | 10 +++++-----
 2 files changed, 13 insertions(+), 9 deletions(-)

diff --git a/activejob/lib/active_job/logging.rb b/activejob/lib/active_job/logging.rb
index 0abee4ed98..416be83c24 100644
--- a/activejob/lib/active_job/logging.rb
+++ b/activejob/lib/active_job/logging.rb
@@ -93,8 +93,12 @@ module ActiveJob
           ex = event.payload[:error]
           wait = event.payload[:wait]
 
-          error do
-            "Retrying #{job.class} in #{wait.inspect} seconds, due to a #{ex&.class.inspect}. The original exception was #{ex&.cause.inspect}."
+          info do
+            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
 
@@ -103,7 +107,7 @@ module ActiveJob
           ex = event.payload[:error]
 
           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
 
@@ -112,7 +116,7 @@ module ActiveJob
           ex = event.payload[:error]
 
           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
 
diff --git a/activejob/test/cases/logging_test.rb b/activejob/test/cases/logging_test.rb
index b5bf40c83b..48ef39aaca 100644
--- a/activejob/test/cases/logging_test.rb
+++ b/activejob/test/cases/logging_test.rb
@@ -169,19 +169,19 @@ class LoggingTest < ActiveSupport::TestCase
   def test_enqueue_retry_logging
     perform_enqueued_jobs do
       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
 
   def test_enqueue_retry_logging_on_retry_job
     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
 
   def test_retry_stopped_logging
     perform_enqueued_jobs do
       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
 
@@ -190,7 +190,7 @@ class LoggingTest < ActiveSupport::TestCase
       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)
+        assert_match(/Stopped retrying RetryJob due to a DefaultsError, which reoccurred on \d+ attempts\./, @logger.messages)
       end
     end
   end
@@ -198,7 +198,7 @@ class LoggingTest < ActiveSupport::TestCase
   def test_discard_logging
     perform_enqueued_jobs do
       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