When logging in Rails, you can use the
log_tags configuration option
Show archive.org snapshot
to add extra information to each line, like :request_id or :subdomain. However, those are only valid inside a request context and have no effect when your application is logging from inside a Sidekiq process.
This includes custom as well as any framework logs, like query logging from ActiveRecord.
Since Sidekiq Workers run inside threads of a single process, running multiple jobs in parallel will produce log entries which are mixed together. Welcome to debugging hell.
You want something like Rails' :request_id tagging. This can easily be achieved through a
Sidekiq middleware
Show archive.org snapshot
as follows.
class RailsLoggerSidekiqServerMiddleware
def call(worker, job_options, queue)
tags = [worker.class.name, worker.jid]
Rails.logger.tagged(*tags) { yield }
end
end
Sidekiq.configure_server do |config|
config.server_middleware do |chain|
chain.add RailsLoggerSidekiqServerMiddleware
end
end
Note that the 2nd argument is a Hash including all job options. If you need to add more information, you can easily do that.
Example
class MyWorker
include Sidekiq::Worker
def perform
User.delete_all
end
end
Before:
User Destroy (0.5ms) DELETE FROM "users"
After:
[MyWorker] [83a25516db80a19fdb79b6c9] User Destroy (0.5ms) DELETE FROM "users"
In case the Sidekiq jobs are triggered from a request it also might be a good idea to serialize the request id and reuse it in the job. That way you can trace a request from the Rails application up to the Sidekiq executing.
