Intermittant "uninitialized constant RunCaseJob" error when triggering job

[epugh]

Periodically I get this error:

Here is the raw data:

  {
  "id": 268,
  "queue_name": "bulk_processing",
  "class_name": "RunCaseJob",
  "arguments": {
    "job_class": "RunCaseJob",
    "job_id": "9fcfc846-a982-4ac8-b2e1-11878b2d97af",
    "provider_job_id": null,
    "queue_name": "bulk_processing",
    "priority": null,
    "arguments": [
      {
        "_aj_globalid": "gid://quepid/Case/6789"
      },
      {
        "_aj_globalid": "gid://quepid/Try/63146"
      }
    ],
    "executions": 0,
    "exception_executions": {},
    "locale": "en",
    "timezone": "UTC",
    "enqueued_at": "2024-12-30T16:08:10.153536324Z",
    "scheduled_at": "2024-12-30T16:08:10.150847860Z"
  },
  "priority": 0,
  "active_job_id": "9fcfc846-a982-4ac8-b2e1-11878b2d97af",
  "scheduled_at": "2024-12-30T16:08:10.150Z",
  "finished_at": null,
  "concurrency_key": null,
  "created_at": "2024-12-30T16:08:10.410Z",
  "updated_at": "2024-12-30T16:08:10.410Z"
}

If I retry the job (using mission control) it will give the same error. However, if I resubmit a new RunCaseJob with the same arguments, then that second one runs.

If you are curious, the PR that adds solid_queue to my open source app is here: o19s/quepid#1039

Thanks for any ideas!

[Kaakati]

Same happening with me, I have an OTPMailer that SolidQueue says method not found, and another Job that says uninitialized constant.

[epugh]

It seems to happen when I directly use perform_later, however I have a nightly recurring job that doesn't seem to have the same issue. I'm wondering if it's some sort of order of loading classes?

[rosa]

Hey @epugh, thanks for the link to the app and the PR. That's very strange! I wonder if, given that this branch hasn't been merged yet, is possible you're enqueuing that job and it's being picked up by a worker that doesn't have that branch's code?

@Kaakati, could you provide more details about the errors you're getting? With backtraces if possible, and the lines of code that might be relevant.

[jbennett]

Hmm, I am seeing this too in a new Rails 8 app. This works in dev but gives a name error in staging/production. Similar to @epugh this works for perform_now but not for perform_later. I'm calling my job with: MyJob.perform_later(active_record_object)

The error in solid queue is:

{
  "exception_class": "NameError",
  "message": "uninitialized constant MyJob",
  "backtrace": [
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/inflector/methods.rb:290:in `constantize'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/core_ext/string/inflections.rb:74:in `constantize'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/core.rb:63:in `deserialize'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/execution.rb:28:in `block in execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:120:in `block in run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/railtie.rb:95:in `block (4 levels) in <class:Railtie>'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/reloader.rb:77:in `block in wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/execution_wrapper.rb:87:in `wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/reloader.rb:74:in `wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/railtie.rb:94:in `block (3 levels) in <class:Railtie>'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `instance_exec'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `block in run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:140:in `run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/execution.rb:27:in `execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/app/models/solid_queue/claimed_execution.rb:95:in `execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/app/models/solid_queue/claimed_execution.rb:61:in `perform'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/lib/solid_queue/pool.rb:23:in `block (2 levels) in post'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/execution_wrapper.rb:91:in `wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/lib/solid_queue/app_executor.rb:7:in `wrap_in_app_executor'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/lib/solid_queue/pool.rb:22:in `block in post'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `block in synchronize'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:22:in `execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/ivar.rb:170:in `safe_execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/future.rb:55:in `block in execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:359:in `run_task'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:350:in `block (3 levels) in create_worker'",
    "<internal:kernel>:187:in `loop'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:341:in `block (2 levels) in create_worker'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `catch'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `block in create_worker'"
  ]
}

I am also sometimes getting an error from a recurring job:

{
  "exception_class": "NameError",
  "message": "uninitialized constant SolidQueue::RecurringJob::Legacy",
  "backtrace": [
    "(eval at /usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/app/jobs/solid_queue/recurring_job.rb:7):1:in `perform'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/app/jobs/solid_queue/recurring_job.rb:7:in `eval'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/app/jobs/solid_queue/recurring_job.rb:7:in `perform'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/execution.rb:68:in `block in _perform_job'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:120:in `block in run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/i18n-1.14.6/lib/i18n.rb:353:in `with_locale'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/translation.rb:9:in `block (2 levels) in <module:Translation>'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `instance_exec'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `block in run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/core_ext/time/zones.rb:65:in `use_zone'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/timezones.rb:9:in `block (2 levels) in <module:Timezones>'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `instance_exec'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `block in run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:140:in `run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/execution.rb:67:in `_perform_job'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/instrumentation.rb:32:in `_perform_job'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/execution.rb:51:in `perform_now'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/instrumentation.rb:26:in `block in perform_now'",
    "/usr/local/bundle/ruby/3.3.0/gems/activerecord-8.0.0/lib/active_record/railties/job_runtime.rb:13:in `block in instrument'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/instrumentation.rb:40:in `block in instrument'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/notifications.rb:210:in `block in instrument'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/notifications/instrumenter.rb:58:in `instrument'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/notifications.rb:210:in `instrument'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/instrumentation.rb:39:in `instrument'",
    "/usr/local/bundle/ruby/3.3.0/gems/activerecord-8.0.0/lib/active_record/railties/job_runtime.rb:11:in `instrument'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/instrumentation.rb:26:in `perform_now'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/logging.rb:32:in `block in perform_now'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/tagged_logging.rb:143:in `block in tagged'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/tagged_logging.rb:38:in `tagged'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/tagged_logging.rb:143:in `tagged'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/broadcast_logger.rb:241:in `method_missing'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/logging.rb:39:in `tag_logger'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/logging.rb:32:in `perform_now'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/execution.rb:29:in `block in execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:120:in `block in run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/railtie.rb:95:in `block (4 levels) in <class:Railtie>'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/reloader.rb:77:in `block in wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/execution_wrapper.rb:87:in `wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/reloader.rb:74:in `wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/railtie.rb:94:in `block (3 levels) in <class:Railtie>'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `instance_exec'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:129:in `block in run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/callbacks.rb:140:in `run_callbacks'",
    "/usr/local/bundle/ruby/3.3.0/gems/activejob-8.0.0/lib/active_job/execution.rb:27:in `execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/app/models/solid_queue/claimed_execution.rb:95:in `execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/app/models/solid_queue/claimed_execution.rb:61:in `perform'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/lib/solid_queue/pool.rb:23:in `block (2 levels) in post'",
    "/usr/local/bundle/ruby/3.3.0/gems/activesupport-8.0.0/lib/active_support/execution_wrapper.rb:91:in `wrap'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/lib/solid_queue/app_executor.rb:7:in `wrap_in_app_executor'",
    "/usr/local/bundle/ruby/3.3.0/gems/solid_queue-1.1.0/lib/solid_queue/pool.rb:22:in `block in post'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:24:in `block in execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `block in synchronize'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/synchronization/mutex_lockable_object.rb:48:in `synchronize'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/safe_task_executor.rb:22:in `execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/ivar.rb:170:in `safe_execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/future.rb:55:in `block in execute'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:359:in `run_task'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:350:in `block (3 levels) in create_worker'",
    "<internal:kernel>:187:in `loop'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:341:in `block (2 levels) in create_worker'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `catch'",
    "/usr/local/bundle/ruby/3.3.0/gems/concurrent-ruby-1.3.4/lib/concurrent-ruby/concurrent/executor/ruby_thread_pool_executor.rb:340:in `block in create_worker'"
  ]
}

[rosa]

@jbennett, does it happen consistently in staging/production for MyJob? Where is MyJob defined? As for the recurring job, could you copy the entry for that in recurring.yml?

[jbennett]

This looks to be happening consistently. The job file is located at app/jobs/update_coordinate_job.rb with class UpdateCoordinateJob < ApplicationJob.

The recurring job is:

production:
  daily_sync:
    command: Legacy.import_all
    schedule: every day at 3am

I did try changing the command to ::Legacy.import_all which changed the error to uninitialized constant Legacy. It's almost like SolidQueue doesn't have access to any of the application classes

[rosa]

Huh, that's so odd! How are you deploying the code to production and how are you starting solid queue?

[jbennett]

This is a staging server but it's running with a production environment/configuration being deploy via Kamal. It using using a single server setup with the solid queue in puma plugin with the environment variable for that turned on.

[rosa]

Oh, interesting! @jbennett, can you reproduce this if you run Solid Queue via bin/jobs instead of via the Puma plugin? And with the Puma plugin, are you preloading your app?

[epugh]

I wanted to follow up as I gave my team the demo of the branch that uses Solid Queue, and looking forward to merging and deploying it once we get past this issue.

I checked and my puma.rb doesn't specify preloading, so I believe it is as the default as I am on puma 6.5.

My set up is also NOT running solid queue in the puma plugin.

The staging version of Quepid is running on Heroku, and the defined start script was bundle exec rake solid_queue:start. I am going to change that to use the bin/jobs instead to see what happens.

The job that is failing is defined as RunJudgeJudyJob

If you are curious @rosa and want an account on the staging server to see "Mission Control" (it's all public/opensource) I can send you a link.

[rosa]

@epugh, does the RunJudgeJudyJob fail consistently? Or is it just sometimes?

If you are curious @rosa and want an account on the staging server to see "Mission Control" (it's all public/opensource) I can send you a link.

If it fails consistently, maybe that helps debugging 🤔 I haven't been able to reproduce this.

[jbennett]

I deploy to the production environment a couple days ago and it has been reliable. Only difference I can really see is running separately via bin/jobs vs in puma on staging.

I'm seeing anything to avoid preloading or eager loading. Anything else I could be looking for in that direction?

[epugh]

Likewise is that I've been using bin/jobs recently... And things have been reliable... I did also set all the settings back to the defaults..

I'll keep you posted on this!

[madejejej]

I'm hitting the same issue, but with the Puma plugin. I have a simple deployment with one process that runs Puma, one dispatcher and one worker process with 2 threads.

I see intermittent job failures with the same issue as everyone above - a job class seems to be an uninitialized constant.

However, when I retry the job a few times, it passes. But jobs of the same class might fail later on.

The weird thing that I'm seeing is that Mission Control sees two worker processes (with different hostnames!), even though I explicitly set workers.processes to 1:

All periodic jobs run successfully and never fail.

When I login to the production console, I can successfully run all the jobs marked failed by Solid Queue (using perform_now).

edit: It turned out that I had a stale web app container running on production for some reason, so what I saw might be a bug in Kamal, not Solid Queue.