Not all loggers have a formatter

[adibsaad]

good_job/lib/good_job/log_subscriber.rb

Line 198 in 2bb4782

tags_for_logger = if each_logger.formatter.current_tags.include?("ActiveJob")

each_logger.formatter can be nil

Issue mentioned in reidmorrison/rails_semantic_logger#29

[bensheldon]

Thanks for the heads up! That can be feature-tested for in GoodJob.

Looks like tagged logging might also be a problem too.

[adibsaad]

Thanks for the quick response.

Another observation: using the fix I put in that issue, GoodJob starts logging twice, once with its own logger (I'm guessing) and one with Rails.logger

[GoodJob] [88944] GoodJob started scheduler with queues=* max_threads=5.
2022-01-29 18:44:39.517917 I [88944:63220] [GoodJob] [88944] Rails -- GoodJob started scheduler with queues=* max_threads=5.
[GoodJob] GoodJob started cron with 2 jobs.
2022-01-29 18:44:39.954994 I [88944:63220] [GoodJob] Rails -- GoodJob started cron with 2 jobs.
[GoodJob] Notifier subscribed with LISTEN
2022-01-29 18:44:40.078149 I [88944:GoodJob::Notifier-worker-1] [GoodJob] Rails -- Notifier subscribed with LISTEN

[bensheldon]

Looking at this now. My assumption was that any logger that is a tagged logger would have a populated formatter. I can guard against that being nil too.

good_job/lib/good_job/log_subscriber.rb

Lines 197 to 198 in 2bb4782

	if each_logger.respond_to?(:tagged)
	tags_for_logger = if each_logger.formatter.current_tags.include?("ActiveJob")

Also, I was curious why GoodJob has this problem because I borrowed the log tagging structure from ActiveJob. Looks like SemanticLogger monkey patches Rails:

https://github.com/reidmorrison/rails_semantic_logger/blob/e83a306296670f205aa6adae9017528d22a8191c/lib/rails_semantic_logger/extensions/active_job/logging.rb

Here's the original method in ActiveJob that SemanticLogger patched around, which calls the formatter:

https://github.com/rails/rails/blob/de956f57733b309e5f7a0be1e9f86ab3e9160c64/activejob/lib/active_job/logging.rb#L22-L33