good_job related exception at app startup

[wlipa]

This new backtrace is appearing at app startup with the latest honeybadger gem.

$ rails s
=> Booting Puma
=> Rails 7.1.3.4 application starting in development 
=> Run `bin/rails server --help` for more startup options
** [Honeybadger] plugin error name=active_job class=NoMethodError message="undefined method `on_thread_error' for {:preserve_job_records=>false, :logger=>#<ActiveSupport::BroadcastLogger:0x000000010617d430 @broadcasts=[#<ActiveSupport::Logger:0x0000000106560200 @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x00000001063c15c0 @datetime_format=nil>, @formatter=#<ActiveSupport::Logger::SimpleFormatter:0x00000001063c1390 @datetime_format=nil>, @logdev=#<Logger::LogDevice:0x0000000106560250 @shift_period_suffix=nil, @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDOUT>>, @binmode=false, @mon_data=#<Monitor:0x00000001063c1548>, @mon_data_owner_object_id=5920>, @local_level_key=:logger_thread_safe_level_19380>], @progname=\"Broadcast\", @formatter=#<ActiveSupport::Logger::SimpleFormatter:0x00000001063c1390 @datetime_format=nil>>, :execution_mode=>:inline, :on_thread_error=>#<Proc:0x0000000106940190 /Users/wlipa/Code/ruby/xyz/config/initializers/good_job.rb:9 (lambda)>}:Hash"
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugins/active_job.rb:49:in `block (2 levels) in <module:ActiveJob>'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:121:in `instance_eval'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:121:in `call'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:240:in `block in ok?'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:240:in `all?'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:240:in `ok?'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:251:in `load!'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:96:in `block in load!'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:94:in `each_pair'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/plugin.rb:94:in `load!'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/singleton.rb:74:in `load_plugins!'
    /Users/wlipa/.gem/ruby/3.2.0/gems/honeybadger-5.11.0/lib/honeybadger/init/rails.rb:33:in `block in <class:Railtie>'
    /Users/wlipa/.gem/ruby/3.2.0/gems/activesupport-7.1.3.4/lib/active_support/lazy_load_hooks.rb:94:in `block in execute_hook'
    /Users/wlipa/.gem/ruby/3.2.0/gems/activesupport-7.1.3.4/lib/active_support/lazy_load_hooks.rb:87:in `with_execution_control'
    /Users/wlipa/.gem/ruby/3.2.0/gems/activesupport-7.1.3.4/lib/active_support/lazy_load_hooks.rb:92:in `execute_hook'
    /Users/wlipa/.gem/ruby/3.2.0/gems/activesupport-7.1.3.4/lib/active_support/lazy_load_hooks.rb:78:in `block in run_load_hooks'
    /Users/wlipa/.gem/ruby/3.2.0/gems/activesupport-7.1.3.4/lib/active_support/lazy_load_hooks.rb:77:in `each'
    /Users/wlipa/.gem/ruby/3.2.0/gems/activesupport-7.1.3.4/lib/active_support/lazy_load_hooks.rb:77:in `run_load_hooks'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/application/finisher.rb:93:in `block in <module:Finisher>'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/initializable.rb:32:in `instance_exec'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/initializable.rb:32:in `run'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/initializable.rb:61:in `block in run_initializers'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:228:in `block in tsort_each'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:350:in `block (2 levels) in each_strongly_connected_component'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:431:in `each_strongly_connected_component_from'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:349:in `block in each_strongly_connected_component'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:347:in `each'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:347:in `call'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:347:in `each_strongly_connected_component'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:226:in `tsort_each'
    /opt/local/lib/ruby3.2/3.2.0/tsort.rb:205:in `tsort_each'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/initializable.rb:60:in `run_initializers'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/application.rb:426:in `initialize!'
    /Users/wlipa/Code/ruby/xyz/config/environment.rb:5:in `<top (required)>'
    config.ru:5:in `require_relative'
    config.ru:5:in `block in <main>'
    /Users/wlipa/.gem/ruby/3.2.0/gems/rack-3.0.11/lib/rack/builder.rb:103:in `eval'
    /Users/wlipa/.gem/ruby/3.2.0/gems/rack-3.0.11/lib/rack/builder.rb:103:in `new_from_string'
    /Users/wlipa/.gem/ruby/3.2.0/gems/rack-3.0.11/lib/rack/builder.rb:94:in `load_file'
    /Users/wlipa/.gem/ruby/3.2.0/gems/rack-3.0.11/lib/rack/builder.rb:64:in `parse_file'
    /Users/wlipa/.gem/ruby/3.2.0/gems/rackup-2.1.0/lib/rackup/server.rb:354:in `build_app_and_options_from_config'
    /Users/wlipa/.gem/ruby/3.2.0/gems/rackup-2.1.0/lib/rackup/server.rb:263:in `app'
    /Users/wlipa/.gem/ruby/3.2.0/gems/rackup-2.1.0/lib/rackup/server.rb:424:in `wrapped_app'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/commands/server/server_command.rb:76:in `log_to_stdout'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/commands/server/server_command.rb:36:in `start'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/commands/server/server_command.rb:145:in `block in perform'
    <internal:kernel>:90:in `tap'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/commands/server/server_command.rb:136:in `perform'
    /Users/wlipa/.gem/ruby/3.2.0/gems/thor-1.3.1/lib/thor/command.rb:28:in `run'
    /Users/wlipa/.gem/ruby/3.2.0/gems/thor-1.3.1/lib/thor/invocation.rb:127:in `invoke_command'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/command/base.rb:178:in `invoke_command'
    /Users/wlipa/.gem/ruby/3.2.0/gems/thor-1.3.1/lib/thor.rb:527:in `dispatch'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/command/base.rb:73:in `perform'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/command.rb:71:in `block in invoke'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/command.rb:149:in `with_argv'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/command.rb:69:in `invoke'
    /Users/wlipa/.gem/ruby/3.2.0/gems/railties-7.1.3.4/lib/rails/commands.rb:18:in `<top (required)>'
    <internal:/opt/local/lib/ruby3.2/3.2.0/rubygems/core_ext/kernel_require.rb>:38:in `require'
    <internal:/opt/local/lib/ruby3.2/3.2.0/rubygems/core_ext/kernel_require.rb>:38:in `require'
    ./bin/rails:4:in `<main>' level=3 pid=74619
Puma starting in single mode...
* Puma version: 6.4.2 (ruby 3.2.4-p170) ("The Eagle of Durango")

config/good_job.rb:

Rails.application.configure do
  # async is annoyingly chatty on server/console startup
  execution_mode = (Rails.env.development? || Rails.env.test?) ? :inline : :external

  config.good_job = {
    preserve_job_records: false,
    logger: GL,
    execution_mode:,
    on_thread_error: ->(exception) { ErrorLog.report(exception) }
  }
end

[stympy]

Thanks for the report, @wlipa! What version of GoodJob are you using?

[wlipa]

good_job (3.29.2)

[stympy]

Unfortunately, I haven't been able to reproduce this yet. Could you share your Gemfile and GoodJob initializer?

[stympy]

Oh, sorry, it looks like I missed the contents of config/good_job.rb that you shared. I'd suggest following the instructions from the gem by putting your config in config/initializers/good_job.rb and following the block syntax rather than assigning a hash to config.good_job.

[wlipa]

Sorry, I meant config/initializers/good_job.rb. Can you explain what you mean about the instructions to follow the block syntax rather than assign a hash, as they both read as valid and supported when I look at the gem instructions?

[stympy]

I meant use the first form of configuration outlined in the gem instructions, where GoodJob settings are done one at a time rather than the second form, where they are done all at once via hash. Regardless, I have created the good-job-config-tweak branch, which should fix the problem for you, so feel free to try it in your app and let me know how it goes. Assuming it does the job, we can get 5.11.1 released with the fix.

[wlipa]

No backtrace when I use that branch, so looks good.

[stympy]

Thanks! 5.11.1 has been released with this fix.