How to include Sidekiq job IDs in Rails logs

Posted . Visible to the public.

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.

Arne Hartherz
Last edit
Emanuel
License
Source code in this card is licensed under the MIT License.
Posted by Arne Hartherz to makandra dev (2020-09-22 13:57)