Rails 6.1 & async - queue_parser': undefined method first' for "*":String (NoMethodError)

[tedt10e]

Hello Ben,

There is an issue starting up the server with Rails 6.1 (both 6.1.0 & 6.1.1) for async.
config.active_job.queue_adapter = GoodJob::Adapter.new(execution_mode: :async, max_threads: 5, poll_interval: 30)

This is not specific to JRuby.
I've tested with ruby-2.5.7, ruby-2.7.2 and the results are the same.
It is working fine with Rails 6.0.3.4.

I've made a rails app for testing. https://github.com/tedhexaflow/good_job_start_up
I've also tested with https://github.com/bensheldon/good_job/tree/main/spec/test_app, and the results are the same.

Can you please have a look and let me know if you need more information.

Thanks.
Ted

=> Booting Puma
=> Rails 6.1.1 application starting in development
=> Run bin/rails server --help for more startup options
Exiting
Traceback (most recent call last):
72: from bin/rails:4:in <main>' 71: from bin/rails:4:in require'
70: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/commands.rb:18:in <top (required)>' 69: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/command.rb:50:in invoke'
68: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/command/base.rb:69:in perform' 67: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/thor-1.0.1/lib/thor.rb:392:in dispatch'
66: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/thor-1.0.1/lib/thor/invocation.rb:127:in invoke_command' 65: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/thor-1.0.1/lib/thor/command.rb:27:in run'
64: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/commands/server/server_command.rb:135:in perform' 63: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/commands/server/server_command.rb:135:in tap'
62: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/commands/server/server_command.rb:144:in block in perform' 61: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/commands/server/server_command.rb:37:in start'
60: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/commands/server/server_command.rb:77:in log_to_stdout' 59: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.3/lib/rack/server.rb:422:in wrapped_app'
58: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.3/lib/rack/server.rb:249:in app' 57: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.3/lib/rack/server.rb:349:in build_app_and_options_from_config'
56: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.3/lib/rack/builder.rb:66:in parse_file' 55: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.3/lib/rack/builder.rb:105:in load_file'
54: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.3/lib/rack/builder.rb:116:in new_from_string' 53: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/rack-2.2.3/lib/rack/builder.rb:116:in eval'
52: from config.ru:5:in block in <main>' 51: from config.ru:5:in require_relative'
50: from /Users/tedhexaflow/Codes/open_source/good_job_start_up/config/environment.rb:5:in <top (required)>' 49: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/application.rb:384:in initialize!'
48: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/initializable.rb:60:in run_initializers' 47: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:205:in tsort_each'
46: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:226:in tsort_each' 45: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:347:in each_strongly_connected_component'
44: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:347:in call' 43: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:347:in each'
42: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:349:in block in each_strongly_connected_component' 41: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:415:in each_strongly_connected_component_from'
40: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:415:in call' 39: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/initializable.rb:50:in tsort_each_child'
38: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/initializable.rb:50:in each' 37: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:421:in block in each_strongly_connected_component_from'
36: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:431:in each_strongly_connected_component_from' 35: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:422:in block (2 levels) in each_strongly_connected_component_from'
34: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:350:in block (2 levels) in each_strongly_connected_component' 33: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/2.5.0/tsort.rb:228:in block in tsort_each'
32: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/initializable.rb:61:in block in run_initializers' 31: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/initializable.rb:32:in run'
30: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/initializable.rb:32:in instance_exec' 29: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/engine.rb:570:in block in class:Engine'
28: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/engine.rb:570:in each' 27: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/engine.rb:571:in block (2 levels) in class:Engine'
26: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activesupport-6.1.1/lib/active_support/dependencies.rb:332:in require' 25: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activesupport-6.1.1/lib/active_support/dependencies.rb:299:in load_dependency'
24: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activesupport-6.1.1/lib/active_support/dependencies.rb:332:in block in require' 23: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/zeitwerk-2.4.2/lib/zeitwerk/kernel.rb:34:in require'
22: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/zeitwerk-2.4.2/lib/zeitwerk/kernel.rb:34:in require' 21: from /Users/tedhexaflow/Codes/open_source/good_job_start_up/config/environments/development.rb:3:in <top (required)>'
20: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/railtie.rb:234:in configure' 19: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/railties-6.1.1/lib/rails/railtie.rb:234:in instance_eval'
18: from /Users/tedhexaflow/Codes/open_source/good_job_start_up/config/environments/development.rb:4:in block in <top (required)>' 17: from /Users/tedhexaflow/Codes/open_source/good_job_start_up/config/environments/development.rb:4:in new'
16: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/good_job-1.4.1/lib/good_job/adapter.rb:47:in initialize' 15: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/good_job-1.4.1/lib/good_job/scheduler.rb:39:in from_configuration'
14: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/good_job-1.4.1/lib/good_job/scheduler.rb:39:in map' 13: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/good_job-1.4.1/lib/good_job/scheduler.rb:43:in block in from_configuration'
12: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/scoping/named.rb:176:in block in scope' 11: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation.rb:411:in _exec_scope'
10: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation.rb:811:in _scoping' 9: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation.rb:411:in block in _exec_scope'
8: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation.rb:411:in instance_exec' 7: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/good_job-1.4.1/lib/good_job/job.rb:98:in block in class:Job'
6: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation/delegation.rb:108:in method_missing' 5: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation.rb:406:in scoping'
4: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation.rb:811:in _scoping' 3: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation.rb:406:in block in scoping'
2: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation/delegation.rb:108:in block in method_missing' 1: from /Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/activerecord-6.1.1/lib/active_record/relation/delegation.rb:108:in public_send'
/Users/tedhexaflow/.asdf/installs/ruby/2.5.7/lib/ruby/gems/2.5.0/gems/good_job-1.4.1/lib/good_job/job.rb:33:in queue_parser': undefined method first' for "*":String (NoMethodError)

[bensheldon]

Hi Ted! Thank you for opening this issue. This is weird, and also frustrating that it's only happening on Rails 6.1.

The String#first method is added via ActiveSupport. This error makes me think that the GoodJob::Adapter is being initialized before Rails (and ActiveSupport) have fully initialized... which is much too early for GoodJob.

I really appreciate you creating an example application. I'm going to poke at it and see if I can trace the initialization order of things, and if that is the problem (which has also been on my mind in #194 and #89), I will have GoodJob defer when it starts.

[bensheldon]

I just released the changes of #199 in GoodJob v1.5.0. This should be fixed now, though the configuration of GoodJob has changed.

• Don't use config.active_job.queue_adapter = GoodJob::Adapter.new....
• Instead use something like config.good_job.execution_mode = :async

Documentation here: https://github.com/bensheldon/good_job#configuration-options

[tedt10e]

Thanks Ben.

Will do a test and keep you update.

[tedt10e]

I've just tested it on the local machine in production mode, and working great.
The startup time is also back to normal.
I'll try to deploy to tomcat and will keep you posted.

[tedt10e]

Hello @bensheldon
Tested with tomcat too and working smoothly.
Thank you so much 💛💚❤️

[bensheldon]

Yay! 🎉 Thank you for partnering with me on this!