How to suppress job scheduler logs?

[christianrolle]

The jobs logging seems to be pretty verbose. I see a lot of logs related to the jobs scheduler, like:

GoodJob::Lockable Unlock Session (0.4ms)  SELECT pg_advisory_unlock_all()::text AS unlocked
GoodJob::Job Load (1.8ms)  SELECT "good_jobs".* FROM "good_jobs" WHERE "good_jobs"."id" IN (WITH "rows" AS  ( SELECT "good_jobs"."id" FROM "good_jobs" WHERE "good_jobs"."finished_at" IS NULL AND ("good_jobs"."scheduled_at" <= '2021-11-17 16:02:56.879079' OR "good_jobs"."scheduled_at" IS NULL) ORDER BY priority DESC NULLS LAST ) SELECT "rows"."id" FROM "rows" WHERE pg_try_advisory_lock(('x' || substr(md5('good_jobs' || "rows"."id"::text), 1, 16))::bit(64)::bigint) LIMIT $1) ORDER BY priority DESC NULLS LAST  [["LIMIT", 1]]

Since this is logged once per second it is a bit noisy and I'd like to suppress those kinda logs.
Any hint is appreciated.

[bensheldon]

@christianrolle Because GoodJob uses ActiveRecord, these logs would need to be figured out how to be silenced at the Rails level. I'd appreciate it if you were able to dig into how ActiveRecord query logging works.

I'm also curious why they're being logged once per second for you. I assume this is happening in the Development environment. The current default development execution mode is async and disabled polling. Is the application overriding the settings for config.good_job.poll_interval/GOOD_JOB_POLL_INTERVAL?

[christianrolle]

@bensheldon
The same behavior at staging/ production.
Alright. Will try hard to dive into AR logging.

[JonathanFrias]

You can silence logs for any arbitrary block of code like so:

def without_ar_logging
  logger = ActiveRecord::Base.logger
  ActiveRecord::Base.logger = nil
  yield
  ActiveRecord::Base.logger = logger
end

without_ar_logging { Job.first } # => No log line

[bensheldon]

Thanks @JonathanFrias for sharing that. I wanted to check if ActiveRecord::Base.logger is threadsafe; unfortunately, it is not. That means that setting ActiveRecord::Base.logger = nil would impact all threads, potentially during a call in which one expected a query to be logged.

I am not optimistic that there's a technical solution here. I wanted to back up to:

• Why is the query being made every second? (that would require overriding the default poll interval)
• Why are debug-level logs enabled in production? (those logs will be very verbose regardless of GoodJob)

[christianrolle]

@bensheldon turns out the mentioned polling logs came from a development system and not from a staging/production system as I thought. And that makes sense to me. Haven't seen the source. So I'd like to close this.

[aried3r]

I believe ActiveRecord::Base.logger.silence {} should be thread safe if it's an ActiveSupport::Logger since rails/rails#20507 but I'm not 100% certain.

https://github.com/rails/rails/blob/v7.0.0.alpha2/activesupport/lib/active_support/logger_silence.rb

[zarqman]

ActiveRecord::Base.logger.silence is thread-safe. But, as I recall, it will apply to all ActiveSupport::Logger instances for the current thread, and not just the logger instance it's called against. That is, it'll silence everything, not just ActiveRecord.