Job uninitialized error (seemingly randomly)

rubyonrails-talk
1

Hi,

I’m finding that when triggering a controller action that schedules a job, when i check Mission Control Jobs I get an error like:

|Type|NameError|
|Message|uninitialized constant ImportGalleryStructureJob|

I find this mostly happens on the first try after a deploy, but actually when i went to replicate to post on here, it happens everytime i trigger the action that schedules the job. The job definitely exists and has run previously.

Any ideas?

EDIT:

This is really bugging me. I’m now not thinking it’s after a deploy. Basically I have an action in the Avo gem that does this:

AssignObjectsToPhotosJob.perform_later(record.photos.to_a)

When i select in Avo a number of records to run that action on, I see the jobs get scheduled in Mission Control jobs. Sometimes it does them all no problem, but other times, some of them appear as failed, with the following error:

[NameError: uninitialized constant AssignObjectsToPhotosJob](https://mysite.co.uk/jobs/applications/mysite/jobs/5a2f1653-aa91-4f3c-972c-bf229caaf424?server_id=solid_queue#error)

Why can the job not be found sometimes and be absolutely perfectly ok on others?

I’m sooo confused!

2

So you have seen errors for two constants? Errors for ImportGalleryStructureJob and errors for AssignObjectsToPhotosJob? Have you seen others? In your app, this only happens in production?

3

Yes, it doesn;t appear to matter which job it is. Sometimes it just says it’s an uninitialized constant. I can click retry and sometimes it fails straight away with the same error and other times it completes successfully.

and yes, only in Production. It’s like it just can’t find a job with that name. I’m very confused by it.

4

This is really strange, jobs work routinely well.

Does your configuration for production mode have eager loading enabled?

5

Where would I check for that?

6

Check if config/environments/production.rb has

config.eager_load = true

which is the default.

7

Yes it does. Just checked that file.

8

Awesome. Two more questions:

  1. Does the error message have a stack trace to know where is the constant being missed?
  2. Which is the exact command the application executes to process jobs?
9

I’ll get the answers and update you a bit later as i don’t have them to hand right now. Appreciate your help!

10

I encountered something like this before myself! One thing to check is that there’s a configuration config.rake_eager_load which defaults to false and overrides the config.eager_load value. So if you are starting your job process with rake you might want to try setting rake_eager_load as well in production.

11

@ziggycalyx could you elaborate? Did that happen to you using Zeitwerk?

I ask because in theory eager loading does not matter for this problem, since the autoloaders are configured anyway. That is, constants should be found with eager loading disabled the same way they are in development mode. Only the file system is not watched, and reloading is disabled.

12

This was a few weeks ago, using the latest version of rails with zeitwerk and delayed_job. Now, I’ll concede, I was not going about it in the most scientific way, as I was working on a few things at the same time, and the problem went away without me figuring out exactly what caused it. I suspect it may been because the delayed_job service was not restarting correctly after deploying new code, but while experimenting with running jobs, I was surprised to find different behavior between bin/delayed_job and rake jobs:work with regards to eager loading.

Let me see if I can reproduce the issue again.

13

I am coming across perhaps the same error and I wondered if anyone found a resolution for it.

For myself, I have a job called EmailEventLoggingJob and I use solid_queue. This job runs as I expect in development. I can also call it with perform_now from a console in production without issue. In production when it is being executed asynchronously it raises an error: uninitialized constant EmailEventLoggingJob.

The mission control logs for spit out a backtrace of:

/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/inflector/methods.rb:290:in `constantize'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/core_ext/string/inflections.rb:74:in `constantize'
/usr/local/bundle/ruby/3.2.0/gems/activejob-7.1.3.2/lib/active_job/core.rb:65:in `deserialize'
/usr/local/bundle/ruby/3.2.0/gems/activejob-7.1.3.2/lib/active_job/execution.rb:29:in `block in execute'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:121:in `block in run_callbacks'
/usr/local/bundle/ruby/3.2.0/gems/activejob-7.1.3.2/lib/active_job/railtie.rb:67:in `block (4 levels) in <class:Railtie>'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/reloader.rb:77:in `block in wrap'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/execution_wrapper.rb:88:in `wrap'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/reloader.rb:74:in `wrap'
/usr/local/bundle/ruby/3.2.0/gems/activejob-7.1.3.2/lib/active_job/railtie.rb:66:in `block (3 levels) in <class:Railtie>'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `instance_exec'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:130:in `block in run_callbacks'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/callbacks.rb:141:in `run_callbacks'
/usr/local/bundle/ruby/3.2.0/gems/activejob-7.1.3.2/lib/active_job/execution.rb:28:in `execute'
/usr/local/bundle/ruby/3.2.0/gems/solid_queue-0.3.1/app/models/solid_queue/claimed_execution.rb:67:in `execute'
/usr/local/bundle/ruby/3.2.0/gems/solid_queue-0.3.1/app/models/solid_queue/claimed_execution.rb:41:in `perform'
/usr/local/bundle/ruby/3.2.0/gems/solid_queue-0.3.1/lib/solid_queue/pool.rb:23:in `block (2 levels) in post'
/usr/local/bundle/ruby/3.2.0/gems/activesupport-7.1.3.2/lib/active_support/execution_wrapper.rb:92:in `wrap'
/usr/local/bundle/ruby/3.2.0/gems/solid_queue-0.3.1/lib/solid_queue/app_executor.rb:7:in `wrap_in_app_executor'
/usr/local/bundle/ruby/3.2.0/gems/solid_queue-0.3.1/lib/solid_queue/pool.rb:22:in `block in post'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `block in synchronize'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:22:in `execute'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/ivar.rb:170:in `safe_execute'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/future.rb:55:in `block in execute'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:359:in `run_task'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:350:in `block (3 levels) in create_worker'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:341:in `loop'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:341:in `block (2 levels) in create_worker'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `catch'
/usr/local/bundle/ruby/3.2.0/gems/concurrent-ruby-1.2.3/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `block in create_worker'

The backtrace doesn’t strike me as obviously odd. Just that when it goes to constantize “EmailEventLoggingJob”, it fails to discover the job. I also created a dummy job “SpecialJob” which also fails.

I have generally haven’t altered the default Rails 7.1 configs. I have:

  • eager_loader = true
  • active_job.queue_adapter = :solid_queue
  • autoload_lib(ignore: %w(assets tasks))
  • load_defaults 7.1

I have tried explicitly adding the jobs directory to the load config.eager_load_paths += %W(#{config.root}/app/jobs) but this had no impact.

One of the oddities in this is that the emails I have set to deliver_later work and I can see the jobs executing in mission control.

My last thought on this is that i did fiddle with the cable.yml to set the prod adapter to async. Given the emails are working fine and the job itself is being enqueued, I figured this non-ideal setup wasn’t the source of the issue. But if not, then it isn’t clear to me where I am missing something.

Any thoughts?

14

@matthewd probably unrelated, but if reloading is disabled, does it make sense that we see reloader callbacks being executed in that stacktrace?

15

Just coming here to report that I have the same error right now, and it’s so confusing.

I am using the latest version of solid queue, 0.4.1, and Rails 7.1.3.4

The error is very random, but it mostly errors, sometimes the job executes successfully.

I have created an issue on solid queue here if you’d like to check NameError uninitialized constant X, but works several minutes later on retry · Issue #276 · rails/solid_queue · GitHub

16

This one is super puzzling, I don’t know why it could happen. Solid Queue doesn’t do anything special with the job class, not even attempt to constantize it… it just keeps it in the serialized job data and as a string, and pass it over to Active Job to execute. That’s where the deserialization happens. On retry, if the retry is done via Mission Control, a new job is enqueued exactly like the first one, and executed in the same way, so it’s really puzzling why it’d succeed then… :thinking:

17

Looks like these come from here, so reloader.wrap will always be called, but I assume this would just yield the block if it’s disabled?

18

On retry, if the retry is done via Mission Control, a new job is enqueued exactly like the first one, and executed in the same way, so it’s really puzzling why it’d succeed then… :thinking:

And the fact that it works perfectly when I use deliver_now instead of deliver_later is puzzling as well!