Again the lifecycle strikes

lib/gouda.rb

@@ -81,6 +81,20 @@ def self.logger
     Rails.try(:logger) || ActiveJob::Base.try(:logger) || @fallback_gouda_logger
   end
 
+  def self.suppressing_sql_logs(&)
+    # This is used for frequently-called methods that poll the DB. If logging is done at a low level (DEBUG)
+    # those methods print a lot of SQL into the logs, on every poll. While that is useful if
+    # you collect SQL queries from the logs, in most cases - especially if this is used
+    # in a side-thread inside Puma - the output might be quite annoying. So silence the
+    # logger when we poll, but just to INFO. Omitting DEBUG-level messages gets rid of the SQL.
+    if Gouda::Workload.logger
+      Gouda::Workload.logger.silence(Logger::INFO, &)
+    else
+      # In tests (and at earlier stages of the Rails boot cycle) the global ActiveRecord logger may be nil
+      yield
+    end
+  end
+
   def self.instrument(channel, options, &block)
     ActiveSupport::Notifications.instrument("#{channel}.gouda", options, &block)
   end

lib/gouda/worker.rb

@@ -84,12 +84,7 @@ def initialize(queue_constraint = Gouda::AnyQueue)
 
     def call
       Gouda.config.app_executor.wrap do
-        # This method is called frequently. If logging is done at a low level (DEBUG or other)
-        # this will print a lot of SQL into the logs, on every poll. While that is useful if
-        # you collect SQL queries from the logs, in most cases - especially if this is used
-        # in a side-thread inside Puma - the output might be quite annoying. So silence the
-        # logger when we poll, but just to INFO. Omitting DEBUG-level messages gets rid of the SQL.
-        Gouda::Workload.logger.silence(Logger::INFO) { Gouda::Workload.waiting_to_start(queue_constraint: @queue_constraint).none? }
+        Gouda.suppressing_sql_logs { Gouda::Workload.waiting_to_start(queue_constraint: @queue_constraint).none? }
       end
     rescue
       # It is possible that in this scenario we do not have a database set up yet, for example,
@@ -164,7 +159,7 @@ def self.worker_loop(n_threads:, check_shutdown: TrapShutdownCheck.new, queue_co
         # a stale timestamp can indicate to us that the job was orphaned and is marked as "executing"
         # even though the worker it was running on has failed for whatever reason.
         # Later on we can figure out what to do with those jobs (re-enqueue them or toss them)
-        Gouda::Workload.logger.silence(Logger::INFO) do # these updates will also be very frequent with long-running jobs, and they generate SQL
+        Gouda.suppressing_sql_logs do # these updates will also be very frequent with long-running jobs
           Gouda::Workload.where(id: executing_workload_ids.to_a, state: "executing").update_all(executing_on: worker_id, last_execution_heartbeat_at: Time.now.utc)
         end
 

lib/gouda/workload.rb

@@ -115,15 +115,9 @@ def self.checkout_and_lock_one(executing_on:, queue_constraint: Gouda::AnyQueue)
       payload[:retried_checkouts_due_to_concurrent_exec] = 0
       uncached do # Necessary because we SELECT with a clock_timestamp() which otherwise gets cached by ActiveRecord query cache
         transaction do
-          # This method is called frequently. If logging is done at a low level (DEBUG or other)
-          # this will print a lot of SQL into the logs, on every poll. While that is useful if
-          # you collect SQL queries from the logs, in most cases - especially if this is used
-          # in a side-thread inside Puma - the output might be quite annoying. So silence the
-          # logger when we poll, but just to INFO. Omitting DEBUG-level messages gets rid of the SQL.
-          # Now, it might be prudent to add an envvar for enabling this output (to debug Gouda itself,
-          # or to debug Gouda inside of an application) - we can think about it later.
-          job = logger.silence(Logger::INFO) { jobs.first }
+          job = Gouda.suppressing_sql_logs { jobs.first } # Silence SQL output as this gets called very frequently
           job&.update!(state: "executing", executing_on: executing_on, last_execution_heartbeat_at: Time.now.utc, execution_started_at: Time.now.utc)
+          job
         rescue ActiveRecord::RecordNotUnique
           # It can happen that due to a race the `execution_concurrency_key NOT IN` does not capture
           # a job which _just_ entered the "executing" state, apparently after we do our SELECT. This will happen regardless