From f59fa08332c13c32cb14d3d6f1603ddf22aa6a87 Mon Sep 17 00:00:00 2001
From: YiiChou <me@ichou.cn>
Date: Fri, 6 May 2022 22:56:09 +0800
Subject: [PATCH] Record the original exception info when job can be retried
 (#29)

If a failed job is able to be retried, Sidekiq will

1. catch the original exception
2. append the exception message to the job and push it into retry queue
3. raise a new exception `Sidekiq::JobRetry::Skip`

when `Sidekiq::LogstashJobLogger` tries to parse the failed job by #log_job_exception,
the received exception is `Sidekiq::JobRetry::Skip` and
the recorded `error_message`, `error` and `error_backtrace` are wrong.
---
 lib/sidekiq/logging/shared.rb |  2 ++
 spec/sidekiq/logstash_spec.rb | 24 ++++++++++++++++++++++++
 spec/workers/spec_worker.rb   |  2 +-
 3 files changed, 27 insertions(+), 1 deletion(-)

diff --git a/lib/sidekiq/logging/shared.rb b/lib/sidekiq/logging/shared.rb
index a786b66..4156103 100644
--- a/lib/sidekiq/logging/shared.rb
+++ b/lib/sidekiq/logging/shared.rb
@@ -49,6 +49,8 @@ def log_job_exception(job, started_at, exc)
 
         payload['message'] += ": fail: #{payload['duration']} sec"
         payload['job_status'] = 'fail'
+
+        exc = exc.cause || exc if exc.is_a? Sidekiq::JobRetry::Handled
         payload['error_message'] = exc.message
         payload['error'] = exc.class
         payload['error_backtrace'] = %('#{exc.backtrace.join("\n")}')
diff --git a/spec/sidekiq/logstash_spec.rb b/spec/sidekiq/logstash_spec.rb
index d4e613b..9e61d44 100644
--- a/spec/sidekiq/logstash_spec.rb
+++ b/spec/sidekiq/logstash_spec.rb
@@ -100,6 +100,30 @@ def process(worker, params = [], encrypt: false)
     end
   end
 
+  context 'when job raises a error' do
+    it 'logs the exception with job retry' do
+      mock_redis = double(:Redis)
+      allow(Sidekiq).to receive(:redis).and_yield(mock_redis)
+
+      expect(mock_redis).to receive(:zadd).with('retry', any_args).once
+      expect { process(SpecWorker, [true]) }.to raise_error(RuntimeError)
+
+      expect(log_messages.last['error_message']).to eq('You know nothing, Jon Snow.')
+      expect(log_messages.last['error']).to eq('RuntimeError')
+      expect(log_messages.last['error_backtrace'].split("\n").first).to include('workers/spec_worker.rb:7')
+    end
+
+    it 'logs the exception without job retry' do
+      allow(SpecWorker).to receive(:get_sidekiq_options).and_return({ 'retry' => false, 'queue' => 'default' })
+
+      expect { process(SpecWorker, [true]) }.to raise_error(RuntimeError)
+
+      expect(log_messages.last['error_message']).to eq('You know nothing, Jon Snow.')
+      expect(log_messages.last['error']).to eq('RuntimeError')
+      expect(log_messages.last['error_backtrace'].split("\n").first).to include('workers/spec_worker.rb:7')
+    end
+  end
+
   context 'with job_start_log enabled' do
     before do
       Sidekiq::Logstash.configure do |config|
diff --git a/spec/workers/spec_worker.rb b/spec/workers/spec_worker.rb
index fb25f3d..39e6547 100644
--- a/spec/workers/spec_worker.rb
+++ b/spec/workers/spec_worker.rb
@@ -4,6 +4,6 @@ class SpecWorker
   include Sidekiq::Worker
 
   def perform(fail = false, _params = {})
-    raise RuntimeError if fail
+    raise 'You know nothing, Jon Snow.' if fail
   end
 end