Logging

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

Sidekiq::Worker provides #logger which returns Sidekiq.logger. So that gives you some more options:

class YourWorker
  include Sidekiq::Worker
  def perform
    logger.info("Things are happening.")
    Sidekiq.logger.info("Same thing ...")
  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 the config.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