Zero processes in development with async mode

[amo13]

I have tried for a while to find out what went wrong, but I need to ask for help here since I was not able to find out.
I start my development rails server with rails s. My config contains

# application.rb
config.active_job.queue_adapter = :good_job

# initializers/good_job.rb
  config.good_job.preserve_job_records = true
  config.good_job.retry_on_unhandled_error = false
  config.good_job.queues = '*'
  config.good_job.max_threads = 5
  config.good_job.poll_interval = 30 # seconds
  config.good_job.shutdown_timeout = 25 # seconds
  config.good_job.enable_cron = true
  config.good_job.cron = {
    ...
  }
  config.good_job.queue_select_limit = 1000
  config.good_job.smaller_number_is_higher_priority = true
  config.good_job.on_thread_error = -> (exception) {
    Sentry.capture_exception(exception)
  }
  # Do not log arguments passed to jobs to prevent logging user passwords
  config.active_job.log_arguments = false

I have read the hint on the readme saying "Because of Rails deferred autoloading, jobs enqueued via the rails console may not begin executing on a separate server process until the Rails application is fully initialized by loading a web page once." So, after rails s, I load the root page before reloading the goodjob GUI at /good_job. But the latter shows that zero processes are running. And due enqueued jobs only appear as Queued. I also tried running the server with GOOD_JOB_EXECUTION_MODE=async rails server to make sure goodjob uses async mode, but no luck.

What did I miss?

[amo13]

Re-enqueuing a cron entry did start a worker process, but the cron entries fail to enqueue themselves and start before the worker process is started.

[bensheldon]

When you say they fail to enqueue, what happens? Is there any exception that is raised?

[amo13]

Oh, that was very bad wording, I'm sorry... with "fail to" I meant "they do not". There is no exception raised or anything. But your answer below helped a lot, thank you!

[bensheldon]

Thanks for sharing these details:

So, after rails s, I load the root page before reloading the goodjob GUI at /good_job. But the latter shows that zero processes are running. And due enqueued jobs only appear as Queued.

I do think that should be sufficient, but having GoodJob detect it's in a webserver is very tricky.

If you're using Puma, it's best to be explicit about starting GoodJob in your config/puma.rb file. Here are some examples: https://github.com/bensheldon/good_job#execute-jobs-async--in-process

Otherwise, you can do some puts debugging on Rails initializers. Here's what GoodJob waits for during initialization:

good_job/lib/good_job/engine.rb

Lines 51 to 69 in ae74482

	initializer "good_job.start_async" do
	# This hooks into the hookable places during Rails boot, which is unfortunately not Rails.application.initialized?
	# If an Adapter is initialized during boot, we want to want to start async executors once the framework dependencies have loaded.
	# When exactly that happens is out of our control because gems or application code may touch things earlier than expected.
	# For example, as of Rails 6.1, if an ActiveRecord model is touched during boot, that triggers ActiveRecord to load,
	# which touches DestroyAssociationAsyncJob, which loads ActiveJob, which may initialize a GoodJob::Adapter, all of which
	# happens _before_ ActiveRecord finishes loading. GoodJob will deadlock if an async executor is started in the middle of
	# ActiveRecord loading.
	config.after_initialize do
	ActiveSupport.on_load(:active_record) do
	ActiveSupport.on_load(:active_job) do
	GoodJob._framework_ready = true
	GoodJob._start_async_adapters
	end
	GoodJob._start_async_adapters
	end
	GoodJob._start_async_adapters
	end
	end

Here's how it initializes Active Job / Adapters:

good_job/lib/good_job/dependencies.rb

Lines 18 to 26 in ae74482

	def _start_async_adapters
	return unless async_ready?
	ActiveJob::Base.queue_adapter # Ensure Active Job is initialized
	GoodJob::Adapter.instances
	.select(&:execute_async?)
	.reject(&:async_started?)
	.each(&:start_async)
	end

And here's how it determines if it's inside a webserver:

good_job/lib/good_job/dependencies.rb

Lines 18 to 26 in ae74482

	def _start_async_adapters
	return unless async_ready?
	ActiveJob::Base.queue_adapter # Ensure Active Job is initialized
	GoodJob::Adapter.instances
	.select(&:execute_async?)
	.reject(&:async_started?)
	.each(&:start_async)
	end

[amo13]

Okey, I think I've got it now, thank you so much for your help with this! The correct puma configuration seemed to be what I was missing. Now when I start the server in development, I have two goodjob processes running from the beginning.

Upon startup, I see 3 messages about Puma not being configured to run in cluster mode, right before the message saying "Puma starting in cluster mode". Looks odd to me:

=> Booting Puma
=> Rails 7.1.2 application starting in development 
=> Run `bin/rails server --help` for more startup options
Warning: You specified code to run in a `before_fork` block, but Puma is not configured to run in cluster mode (worker count > 0 ), so your `before_fork` block did not run
Warning: You specified code to run in a `on_worker_boot` block, but Puma is not configured to run in cluster mode (worker count > 0 ), so your `on_worker_boot` block did not run
Warning: You specified code to run in a `on_worker_shutdown` block, but Puma is not configured to run in cluster mode (worker count > 0 ), so your `on_worker_shutdown` block did not run
[518483] Puma starting in cluster mode...
[518483] * Puma version: 6.4.0 (ruby 3.2.2-p53) ("The Eagle of Durango")
[518483] *  Min threads: 5
[518483] *  Max threads: 5
[518483] *  Environment: development
[518483] *   Master PID: 518483
[518483] *      Workers: 2
[518483] *     Restarts: (✔) hot (✖) phased
[518483] * Preloading application
[518483] * Listening on http://127.0.0.1:3000
[518483] * Listening on http://[::1]:3000
[518483] Use Ctrl-C to stop
[GoodJob] [518489] GoodJob 3.21.1 started scheduler with queues=* max_threads=5.
[GoodJob] [518492] GoodJob 3.21.1 started scheduler with queues=* max_threads=5.
[GoodJob] GoodJob started cron with 5 jobs.
[518483] - Worker 0 (PID: 518489) booted in 0.05s, phase: 0
[GoodJob] GoodJob started cron with 5 jobs.
[518483] - Worker 1 (PID: 518492) booted in 0.05s, phase: 0
...

...but hey, it looks like it works :)

Thank you for your hints and help!!