From 59696e4e06d24c3eb4554fbd70800c0968551bd7 Mon Sep 17 00:00:00 2001
From: iChou <me@ichou.cn>
Date: Wed, 4 May 2022 17:36:46 +0800
Subject: [PATCH] FIX: record the original exception info when job can be
 retried

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 | 20 ++++++++++++++++++++
 spec/workers/spec_worker.rb   |  2 +-
 3 files changed, 23 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..f11fd38 100644
--- a/spec/sidekiq/logstash_spec.rb
+++ b/spec/sidekiq/logstash_spec.rb
@@ -100,6 +100,26 @@ def process(worker, params = [], encrypt: false)
     end
   end
 
+  context 'when job raises a error' do
+    it 'logs the exception with job retry' do
+      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..21fe6e9 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 RuntimeError, 'You know nothing, Jon Snow.' if fail
   end
 end