Initial pass at getting a worker logger. Not quite happy with the API yet.

Changes.md

@@ -1,6 +1,8 @@
 1.2.1
 -----------
 
+- Sidekiq::Worker now has access to Sidekiq's standard logger
+- Fix issue with non-StandardErrors leading to Processor exhaustion
 - Fix issue with Fetcher slowing Sidekiq shutdown
 - Print backtraces for all threads upon INFO signal [#183]
 - Overhaul retries Web UI with new index page and bulk operations [#184]

lib/sidekiq.rb

@@ -1,4 +1,5 @@
 require 'sidekiq/version'
+require 'sidekiq/logger'
 require 'sidekiq/client'
 require 'sidekiq/worker'
 require 'sidekiq/redis_connection'

lib/sidekiq/cli.rb

@@ -10,7 +10,7 @@ trap 'TERM' do
 end
 
 trap 'USR1' do
-  Sidekiq::Util.logger.info "Received USR1, no longer accepting new work"
+  Sidekiq::Logger.logger.info "Received USR1, no longer accepting new work"
   mgr = Sidekiq::CLI.instance.manager
   mgr.stop! if mgr
 end
@@ -47,13 +47,13 @@ module Sidekiq
 
     def parse(args=ARGV)
       @code = nil
-      Sidekiq::Util.logger
+      Sidekiq::Logger.logger
 
       cli = parse_options(args)
       config = parse_config(cli)
       options.merge!(config.merge(cli))
 
-      Sidekiq::Util.logger.level = Logger::DEBUG if options[:verbose]
+      Sidekiq::Logger.logger.level = ::Logger::DEBUG if options[:verbose]
       Celluloid.logger = nil
 
       validate!
@@ -134,7 +134,7 @@ module Sidekiq
         end
 
         o.on "-v", "--verbose", "Print more verbose output" do
-          Sidekiq::Util.logger.level = Logger::DEBUG
+          Sidekiq::Logger.logger.level = ::Logger::DEBUG
         end
 
         o.on '-e', '--environment ENV', "Application environment" do |arg|

lib/sidekiq/logger.rb

@@ -0,0 +1,32 @@
+require 'time'
+require 'logger'
+
+module Sidekiq
+  module Logger
+
+    class Pretty < ::Logger::Formatter
+      # Provide a call() method that returns the formatted message.
+      def call(severity, time, program_name, message)
+        "#{time.utc.iso8601} #{Process.pid} TID-#{Thread.current.object_id.to_s(36)} #{severity}: #{message}\n"
+      end
+    end
+
+    def self.logger
+      @logger ||= begin
+        log = ::Logger.new(STDOUT)
+        log.level = ::Logger::INFO
+        log.formatter = Pretty.new
+        log
+      end
+    end
+
+    def self.logger=(log)
+      @logger = (log ? log : ::Logger.new('/dev/null'))
+    end
+
+    def logger
+      Sidekiq::Logger.logger
+    end
+
+  end
+end

lib/sidekiq/middleware/server/logging.rb

@@ -2,6 +2,7 @@ module Sidekiq
   module Middleware
     module Server
       class Logging
+
         def call(*args)
           static = "#{args[0].class.to_s} MSG-#{args[0].object_id.to_s(36)}" if logger.info?
           start = Time.now
@@ -18,7 +19,7 @@ module Sidekiq
         end
 
         def logger
-          Sidekiq::Util.logger
+          Sidekiq::Logger.logger
         end
       end
     end

lib/sidekiq/util.rb

@@ -1,6 +1,3 @@
-require 'time'
-require 'logger'
-
 module Sidekiq
   ##
   # This module is part of Sidekiq core and not intended for extensions.
@@ -9,26 +6,6 @@ module Sidekiq
 
     EXPIRY = 24 * 60 * 60
 
-    class Pretty < Logger::Formatter
-      # Provide a call() method that returns the formatted message.
-      def call(severity, time, program_name, message)
-        "#{time.utc.iso8601} #{Process.pid} TID-#{Thread.current.object_id.to_s(36)} #{severity}: #{message}\n"
-      end
-    end
-
-    def self.logger
-      @logger ||= begin
-        log = Logger.new(STDOUT)
-        log.level = Logger::INFO
-        log.formatter = Pretty.new
-        log
-      end
-    end
-
-    def self.logger=(log)
-      @logger = (log ? log : Logger.new('/dev/null'))
-    end
-
     def constantize(camel_cased_word)
       names = camel_cased_word.split('::')
       names.shift if names.empty? || names.first.empty?
@@ -49,7 +26,7 @@ module Sidekiq
     end
 
     def logger
-      Sidekiq::Util.logger
+      Sidekiq::Logger.logger
     end
 
     def redis(&block)

lib/sidekiq/worker.rb

@@ -24,6 +24,10 @@ module Sidekiq
       base.extend(ClassMethods)
     end
 
+    def logger
+      Sidekiq::Logger.logger
+    end
+
     module ClassMethods
       def perform_async(*args)
         Sidekiq::Client.push('class' => self, 'args' => args)

test/helper.rb

@@ -10,7 +10,7 @@ require 'minitest/autorun'
 
 require 'sidekiq'
 require 'sidekiq/util'
-Sidekiq::Util.logger.level = Logger::ERROR
+Sidekiq::Logger.logger.level = Logger::ERROR
 
 require 'sidekiq/redis_connection'
 REDIS = Sidekiq::RedisConnection.create(:url => "redis://localhost/15", :namespace => 'testy')

test/test_cli.rb

@@ -51,11 +51,11 @@ class TestCli < MiniTest::Unit::TestCase
     end
 
     it 'sets verbose' do
-      old = Sidekiq::Util.logger.level
+      old = Sidekiq::Logger.logger.level
       @cli.parse(['sidekiq', '-v', '-r', './test/fake_env.rb'])
-      assert_equal Logger::DEBUG, Sidekiq::Util.logger.level
+      assert_equal ::Logger::DEBUG, Sidekiq::Logger.logger.level
       # If we leave the logger at DEBUG it'll add a lot of noise to the test output
-      Sidekiq::Util.logger.level = old
+      Sidekiq::Logger.logger.level = old
     end
 
     describe 'with pidfile' do