semantic_logger: Sidekiq logging is missing context information

Following the readme I`ve added semantic logger to Sidekiq.

Sidekiq::Logging.logger = SemanticLogger[Sidekiq] if defined?(Sidekiq)

And it occurred that i`ve lost the most valuable data - worker class name.

The log before:

2017-02-12T19:18:43.908Z 22548 TID-osbolpr4g SomeWorker JID- INFO: start 2017-02-12T19:18:43.912Z 22548 TID-osbolpr4g SomeWorker JID- INFO: done: 0.003 sec

The log after:

{"name":"Sidekiq","pid":19857,"thread":"47328718486600","level":"info","level_index":2,"host":"web01","application":"Semantic Logger","message":"start","timestamp":"2017-02-12T19:32:00.599277Z"} {"name":"Sidekiq","pid":19857,"thread":"47328718486600","level":"info","level_index":2,"host":"web01","application":"Semantic Logger","message":"done: 0.002 sec","timestamp":"2017-02-12T19:32:00.601137Z"}

Is there a known way to capture the name of the calling worker class. Or maybe we should provider some facilities for such a broad use-case?

About this issue

Original URL
State: closed
Created 7 years ago
Comments: 17 (11 by maintainers)

Most upvoted comments

For anyone else finding this thread, none of the solutions offered here or https://github.com/rocketjob/semantic_logger/issues/80 worked for me.

Semantic logger was preventing Sidekiq from outputting anything at all.

I added Sidekiq.logger = Logger.new(STDOUT) in initializers/sidekiq.rb to force Sidekiq to use the default logger to fix the issue.

prdanelli on Apr 4, 2018

p.s. I hope that any rivalry between Sidekiq and RocketJob can be put aside for the purpose of better logging, irrespective of which product / logger is used 😉

gingerlime on Mar 10, 2017

Yes, indeed. I was thinking it might be nice to use such a tagged logger for Sidekiq by default.

bobvanderlinden on Oct 4, 2019

Based on @gingerlime 's idea, I was able to customize the logging via overwriting Sidekiq::JobLogger:

class CustomSidekiqJobLogger < Sidekiq::JobLogger
  def call(item, queue, &block)
    logger.tagged(*context_tags(item)) do
      super(item, queue, &block)
    end
  end

  private

  def context_tags(item)
    [
      item['jid'],
      item['class']
    ]
  end

  def logger
    Rails.logger
  end
end

Sidekiq.configure_server do |config|
  config.options[:job_logger] = CustomSidekiqJobLogger
end

lacco on Jan 26, 2018

@prikha @reidmorrison sorry to bother you guys, but I’m looking at some examples, but can’t quite wrap my head around it fully.

If I look at the JSON formatter, then the usage section says I should assign the formatter to the sidekiq logger. The formatter itself inherits from Sidekiq’s Pretty formatter, which outputs everything as a string.

However, when I try to use the standard pretty formatter by assigning it, SemanticLogger either doesn’t use it, or ignores it? I don’t see all the info I’d expect in my logs

# config/initializers/sidekiq.rb
Sidekiq.logger.formatter = Sidekiq::Logging::Pretty.new

log output:

2017-04-05 11:51:54.650201 I [4391:47191573070460] Sidekiq -- start
2017-04-05 11:51:55.381212 I [4391:47191573070460] Sidekiq -- done: 0.731 sec

Without SemanticLogger

2017-04-05T09:16:01.343Z 18637 TID-1f5h70 ClassName JID-936bd16c703db2ffbc9b2b5a INFO: start
2017-04-05T09:16:05.392Z 18637 TID-1f5h70 ClassName JID-936bd16c703db2ffbc9b2b5a INFO: done: 4.049 sec

I can create a middleware like @prikha suggested, or using Rails tags similar to this?

But I just wonder where’s the conflict, or why the full log record isn’t logged correctly by default? when I’m using the logging-rails gem, and lograge, it “just works” with those. So why can’t this happen with Semantic Logger?

… sorry if it’s a silly question, but I’m genuinely confused about how this all fits together, or doesn’t as the case might be 😉

gingerlime on Apr 5, 2017