Use exception handler for logging for fetch exception

Extends the `ExceptionHandler` to support multiple log levels and
additional context text in order to use it when the `Processor`
encounters an exception when fetching new work. The added options ensure
that the new behavior is fairly close to the old behavior (same log
level, same fetch error message).

Fixes mperham/sidekiq#3673

lib/sidekiq/exception_handler.rb

@@ -5,20 +5,26 @@ module Sidekiq
   module ExceptionHandler
 
     class Logger
-      def call(ex, ctxHash)
-        Sidekiq.logger.warn(Sidekiq.dump_json(ctxHash)) if !ctxHash.empty?
-        Sidekiq.logger.warn "#{ex.class.name}: #{ex.message}"
-        Sidekiq.logger.warn ex.backtrace.join("\n") unless ex.backtrace.nil?
+      def call(ex, ctxHash, options={})
+        # In practice, this will only be called on exceptions so this increase
+        # in complexity in selecting log level is low compared to expense of
+        # the logging messages themselves.
+        options = options || {}
+        level = options.fetch(:level, :warn)
+        Sidekiq.logger.send(level, options[:message]) if options.key?(:message)
+        Sidekiq.logger.send(level, Sidekiq.dump_json(ctxHash)) if !ctxHash.empty?
+        Sidekiq.logger.send(level, "#{ex.class.name}: #{ex.message}")
+        Sidekiq.logger.send(level, ex.backtrace.join("\n")) unless ex.backtrace.nil?
       end
 
       # Set up default handler which just logs the error
       Sidekiq.error_handlers << Sidekiq::ExceptionHandler::Logger.new
     end
 
-    def handle_exception(ex, ctxHash={})
+    def handle_exception(ex, ctxHash={}, options={})
       Sidekiq.error_handlers.each do |handler|
         begin
-          handler.call(ex, ctxHash)
+          handler.call(ex, ctxHash, options)
         rescue => ex
           Sidekiq.logger.error "!!! ERROR HANDLER THREW AN ERROR !!!"
           Sidekiq.logger.error ex

lib/sidekiq/processor.rb

@@ -110,10 +110,7 @@ module Sidekiq
     def handle_fetch_exception(ex)
       if !@down
         @down = Time.now
-        logger.error("Error fetching job: #{ex}")
-        ex.backtrace.each do |bt|
-          logger.error(bt)
-        end
+        handle_exception(ex, {}, level: :error, message: 'Error fetching job:')
       end
       sleep(1)
       nil

test/test_processor.rb

@@ -69,8 +69,8 @@ class TestProcessor < Sidekiq::Test
     describe 'exception handling' do
       let(:errors) { [] }
       let(:error_handler) do
-        proc do |exception, context|
-          errors << { exception: exception, context: context }
+        proc do |exception, context, options={}|
+          errors << { exception: exception, context: context, options: options }
         end
       end
 
@@ -128,6 +128,19 @@ class TestProcessor < Sidekiq::Test
         assert_equal msg, errors.first[:context][:jobstr]
         assert_equal job_hash, errors.first[:context][:job]
       end
+
+      it 'handles exceptions raised during fetch' do
+        fetch_stub = lambda { raise StandardError, "fetch exception" }
+        # swallow logging because actually care about the added exception handler
+        capture_logging do
+          @processor.instance_variable_get('@strategy').stub(:retrieve_work, fetch_stub) do
+            @processor.process_one
+          end
+        end
+
+        assert_instance_of StandardError, errors.last[:exception]
+        assert_equal :error, errors.last[:options][:level]
+      end
     end
 
     describe 'acknowledgement' do