Logging - rselk/sidekiq GitHub Wiki

Sidekiq is a multi-threaded system which means you have a lot of things happening concurrently. To make for easier debugging in that type of environment, Sidekiq uses a custom logger which outputs additional information:

UTC Timestamp------- PID-- ThreadID----- LLvl  YourKlass- JobID--------
2012-03-02T19:40:45Z 32515 TID-oveahmcxw INFO: HardWorker JID-oveaivtrg start
2012-03-02T19:40:45Z 32515 TID-oveajt7ro INFO: HardWorker JID-oveaish94 start    
2012-03-02T19:40:55Z 32515 TID-oveahmcxw INFO: HardWorker JID-oveaivtrg done: 10.003 sec
2012-03-02T19:40:55Z 32515 TID-oveajt7ro INFO: HardWorker JID-oveaish94 done: 10.002 sec

All timestamps are in UTC. Timezones suck.

Writing to the log

Workers can use logger.

class YourWorker
  include Sidekiq::Worker

  def perform
    logger.info "Things are happening."
    logger.debug "Here's some info: #{hash.inspect}"
  end
end

Finding items in the log

If you have an error and need to examine the logs, you can use awk/grep/ack to focus on the events in a particular thread or particular message.

Example - Display all log messages for the HardWorker class:

awk '{ if ($5 == "HardWorker") print $0 }' sidekiq.log

Log File

To log to a file rather than STDOUT, specify a log file -L on the CLI:

bundle exec sidekiq ... -L log/sidekiq.log

Or use the logfile: option in config/sidekiq.yml:

---
:verbose: false
:pidfile: ./tmp/pids/sidekiq.pid
:logfile: ./log/sidekiq.log
:concurrency:  25

Syslog

Redirect Sidekiq's output to the logger UNIX command to send it to syslog with a 'sidekiq' tag.

bundle exec sidekiq 2>&1 | logger -t sidekiq

(If you're running the command inside a rake task, also don't forget to add an "&" at the end of the line, otherwise the command won't return to the shell)

Turning Off Logging In The Test Environment

Sidekiq's logger= defaults to a null Logger, so this is all you have to do:

require 'sidekiq/testing'
Sidekiq::Logging.logger = nil

Default logger and verboseness

Sidekiq defaults to using Ruby's standard library Logger. Log levels thus follow the stdlib documentation.

In production environments, a log level of INFO may be too verbose for your needs. For quieter logs that use less disk space, you can change the log level to only show WARN and higher:

Sidekiq::Logging.logger.level = Logger::WARN

Customize Logger

Log4r example

Sidekiq::Logging.logger = Log4r::Logger.new 'sidekiq'
Sidekiq::Logging.logger.level = Log4r::INFO

To output to syslog, add:

Sidekiq::Logging.logger.outputters = Log4r::SyslogOutputter.new 'sidekiq', ident: 'worker-name'

Customize Logger Format

Default format:

 "#{time.utc.iso8601} #{Process.pid} TID-#{Thread.current.object_id.to_s(36)}#{context} #{severity}: #{message}\n" 

Use your own formatter:

Sidekiq.logger.formatter = MyFormatter.new