NoMethodError: undefined method `current_tags' for nil:NilClass

[rgaufman]

good_job is working correctly for me when running specs, but when starting in production, I see this:

May 11 13:27:49 bundle[3862293]: ! Unable to load application: NoMethodError: undefined method `current_tags' for nil:NilClass
May 11 13:27:49 bundle[3862293]:         logger.formatter.current_tags.include?("ActiveJob")
May 11 13:27:49 bundle[3862293]:                         ^^^^^^^^^^^^^
May 11 13:27:49 bundle[3862293]: bundler: failed to load command: puma (/data/deployer/timeagent/vendor/bundle/ruby/3.1.0/bin/puma)
May 11 13:27:49 bundle[3862293]: /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activejob-7.0.3/lib/active_job/logging.rb:32:in `logger_tagged_by_active_job?': undefined method `current_tags' for nil:NilClass (NoMethodError)
May 11 13:27:49 bundle[3862293]:         logger.formatter.current_tags.include?("ActiveJob")
May 11 13:27:49 bundle[3862293]:                         ^^^^^^^^^^^^^
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activejob-7.0.3/lib/active_job/logging.rb:24:in `tag_logger'
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activejob-7.0.3/lib/active_job/logging.rb:14:in `block (2 levels) in <module:Logging>'
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.3/lib/active_support/callbacks.rb:127:in `instance_exec'
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.3/lib/active_support/callbacks.rb:127:in `block in run_callbacks'
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activesupport-7.0.3/lib/active_support/callbacks.rb:138:in `run_callbacks'
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activejob-7.0.3/lib/active_job/enqueuing.rb:63:in `enqueue'
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/vendor/bundle/ruby/3.1.0/gems/activejob-7.0.3/lib/active_job/enqueuing.rb:30:in `perform_later'
May 11 13:27:49 bundle[3862293]:         from /data/deployer/timeagent/config/initializers/good_job.rb:1:in `good_job_tasks'

This happens whenever I try to run perform_later on any job.

Any ideas what could be wrong?

EDIT: I also tried to explicitly specify the logger, but this didn't help:

    config.active_job.queue_adapter = :good_job
    config.good_job = {
      preserve_job_records: true,
      retry_on_unhandled_error: false,
      on_thread_error: ->(exception) { Airbrake.notify(exception) },
      execution_mode: :external,
      queues: '*',
      max_threads: 5,
      poll_interval: 30,
      shutdown_timeout: 25,
      enable_cron: true,
      logger: Rails.logger
    }

[rgaufman]

Seems possibly related to this? < reidmorrison/rails_semantic_logger#29

[bensheldon]

@rgaufman thanks for opening the issue! That stacktrace looks like the error is happening within ActiveJob, rather than GoodJob (We did previously address that other rails_semantic_logger issue here)

I found this other issue that maybe is a better match: reidmorrison/rails_semantic_logger#11

[rgaufman]

I added this to an initialiser and the problem went away :)

formatter = ActiveSupport::Logger::SimpleFormatter.new
formatter.extend ActiveSupport::TaggedLogging::Formatter
Rails.logger.formatter = formatter