Sidekiq fails to start when RAILS_ENV=production is set after upgrading to Rails 7 and using turbo-rails-1.0.0

[nickjj]

Edit: The scope of this issue has changed to affect every Active Job running through Sidekiq and it also affects all environments. The first reply to this issue has more details. I left the original issue here for extra context which is still worth reading.

Sidekiq starts successfully with RAILS_ENV=development, but fails to start with RAILS_ENV=production.

Here's the stack trace:

worker_1    | 2021-12-18T15:43:09.829Z pid=1 tid=2ut INFO: Booting Sidekiq 6.3.1 with redis options {:url=>"redis://redis:6379/1"}
worker_1    | /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader/helpers.rb:95:in `require': cannot load such file -- /usr/local/bundle/gems/turbo-rails-1.0.0/app/channels/turbo/streams (LoadError)
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader/helpers.rb:95:in `const_get'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader/helpers.rb:95:in `cget'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader.rb:239:in `block (2 levels) in eager_load'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader/helpers.rb:26:in `block in ls'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader/helpers.rb:18:in `each_child'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader/helpers.rb:18:in `ls'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader.rb:227:in `block in eager_load'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader.rb:212:in `synchronize'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader.rb:212:in `eager_load'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader.rb:312:in `each'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/loader.rb:312:in `eager_load_all'
worker_1    |   from /usr/local/bundle/gems/railties-7.0.0/lib/rails/application/finisher.rb:79:in `block in <module:Finisher>'
worker_1    |   from /usr/local/bundle/gems/railties-7.0.0/lib/rails/initializable.rb:32:in `instance_exec'
worker_1    |   from /usr/local/bundle/gems/railties-7.0.0/lib/rails/initializable.rb:32:in `run'
worker_1    |   from /usr/local/bundle/gems/railties-7.0.0/lib/rails/initializable.rb:61:in `block in run_initializers'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:228:in `block in tsort_each'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:350:in `block (2 levels) in each_strongly_connected_component'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:431:in `each_strongly_connected_component_from'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:349:in `block in each_strongly_connected_component'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:347:in `each'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:347:in `call'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:347:in `each_strongly_connected_component'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:226:in `tsort_each'
worker_1    |   from /usr/local/lib/ruby/3.0.0/tsort.rb:205:in `tsort_each'
worker_1    |   from /usr/local/bundle/gems/railties-7.0.0/lib/rails/initializable.rb:60:in `run_initializers'
worker_1    |   from /usr/local/bundle/gems/railties-7.0.0/lib/rails/application.rb:369:in `initialize!'
worker_1    |   from /app/config/environment.rb:5:in `<top (required)>'
worker_1    |   from <internal:/usr/local/lib/ruby/3.0.0/rubygems/core_ext/kernel_require.rb>:148:in `require'
worker_1    |   from <internal:/usr/local/lib/ruby/3.0.0/rubygems/core_ext/kernel_require.rb>:148:in `require'
worker_1    |   from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/kernel.rb:35:in `require'
worker_1    |   from /usr/local/bundle/gems/sidekiq-6.3.1/lib/sidekiq/cli.rb:273:in `boot_application'
worker_1    |   from /usr/local/bundle/gems/sidekiq-6.3.1/lib/sidekiq/cli.rb:37:in `run'
worker_1    |   from /usr/local/bundle/gems/sidekiq-6.3.1/bin/sidekiq:31:in `<top (required)>'
worker_1    |   from /usr/local/bundle/bin/sidekiq:25:in `load'
worker_1    |   from /usr/local/bundle/bin/sidekiq:25:in `<main>'
hellorails_worker_1 exited with code 1

If I exec into the worker container I'm able to stat /usr/local/bundle/gems/turbo-rails-1.0.0/app/channels/turbo/streams which returns back that the directory does exist as seen below:

ruby@97b98bc1dd6b:/app$ stat /usr/local/bundle/gems/turbo-rails-1.0.0/app/channels/turbo/streams
  File: /usr/local/bundle/gems/turbo-rails-1.0.0/app/channels/turbo/streams
  Size: 4096            Blocks: 8          IO Block: 4096   directory
Device: bdh/189d        Inode: 290588      Links: 2
Access: (0755/drwxr-xr-x)  Uid: ( 1000/    ruby)   Gid: ( 1000/    ruby)
Access: 2021-12-18 15:26:58.040000000 +0000
Modify: 2021-12-18 15:26:29.950000000 +0000
Change: 2021-12-18 15:26:55.900000000 +0000
 Birth: 2021-12-18 15:26:55.900000000 +0000

What's weird is the error mentions cannot load such file but that path it not a file, it's a directory on disk.

What's also interesting is the web, worker and cable containers that run all use an identical Dockerfile and the only difference is the command that gets run (such as puma or sidekiq). Both the web and cable containers come up fine. It's only worker that fails.

Running the same stat command in the web and cable containers produce the same output.

[nickjj]

The scope of this issue has changed since its creation.

It's now an issue with RAILS_ENV=development too but only when a job is about to execute through Active Job. Executing a job through Active Job with a :sidekiq back-end will throw this error:

worker_1 | 2021-12-18T18:54:20.325Z pid=1 tid=d35 WARN: LoadError: cannot load such file -- /usr/local/bundle/gems/turbo-rails-1.0.0/app/channels/turbo/streams

Perhaps this has to do with lazy loading modules in development vs pre-loading modules in production? At least it happens in both environments now. Question is whether this is a turbo-rails, sidekiq, Rails 7 or a user issue.

From my end all I did was execute a default Rails 7 mailer through Active Job using deliver_later. It's also worth pointing out if I create a new Sidekiq job in app/workers and execute the job directly with Sidekiq without Active Job then the job runs successfully, so now things are maybe scoped tighter to being related to Active Job.

[arbythree]

Same problem here. Any known workaround?

[nickjj]

I think the best we can hope for now is to mention it's happening in hotwired/turbo-rails#285 and monitor that issue until a resolution is found. Attempting to fix this one is above my pay grade.

[jmaino]

Same problem w/ an older application I'm trying to move to Rails7.
I did enable the Rails autoloader log and I can see it 'autovivifying' one of my dirs under sidekiq's docker container.
But, I'm also seeing the exact symptom
2021-12-27T14:50:46.829Z pid=1 tid=1uy1 WARN: LoadError: cannot load such file -- /app/app/adapters/test
where the mysterious thing is that the above is a dir and not a file, just like the original post. In my case, the above dir is one of my own additions for the application - not related to turbo-rails or any other gem. All fine in Rails 6.1.4.4

I did spot this, this morning - thinking it may have resolved things
fxn/zeitwerk#198

But, even after getting zeitwerk 2.5.2 installed, it does not resolve the symptom for me (even if I turn off bootsnap in my case).

Alike the OP, I can successfully find and call my class from IRB - and the dir can be found from bash within the docker container that is running sidekiq - so it's there.

[nickjj]

I also upgraded zeitwerk to 2.5.2 but I'm seeing the same issue as with 2.5.1. Thanks for linking that. I'm not sure if that issue is 100% related but hopefully having it linked will help address this one.

[nickjj]

This is currently fixed on the main branch based on ed7e99c.

I'm still going to leave this open until it's properly fixed in the related repo(s) since the current fix might be a workaround, although it feels completely reasonable to do. I'm not sure what would cause needing to do this now but not in previous versions of Rails or Zeitwerk.

[nickjj]

The root cause has been found by the creator of Zeitwerk. He wrote up a great explanation of everything here: hotwired/turbo-rails#285 (comment)

The TL;DR is it's not a bug, it's more so a documentation issue with Bundler and that using the bundle exec sidekiq approach as per the commit in the previous comment is the way to go regardless of it working previously.

Rails also been patched for 7.0.1 which will delay loading Zeitwerk just a little bit to make things work how they did before but technically you should use bundle exec. In this repo's case the implications of not using bundle exec never came up because we're always running Sidekiq that's a part of this Gemfile since everything is running in Docker.