Ruby 2.7 으로 올린 뒤 사이드킥이 정상적으로 동작하지 않는 문제가 발생하여 확인해보았다.
monitor_mode: false
로 설정할 경우 정상 동작할 것으로 예상된다.> bundle exec sidekiq -e bravo
undefined method `delete' for nil:NilClass
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activerecord-6.0.3.2/lib/active_record/railtie.rb:179:in `block (2 levels) in <class:Railtie>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:71:in `class_eval'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:71:in `block in execute_hook'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:61:in `with_execution_control'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:66:in `execute_hook'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:52:in `block in run_load_hooks'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:51:in `each'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/lazy_load_hooks.rb:51:in `run_load_hooks'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activerecord-6.0.3.2/lib/active_record/base.rb:327:in `<module:ActiveRecord>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activerecord-6.0.3.2/lib/active_record/base.rb:27:in `<main>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.5/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22:in `require'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.5/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22:in `block in require_with_bootsnap_lfi'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.5/lib/bootsnap/load_path_cache/loaded_features_index.rb:92:in `register'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.5/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:21:in `require_with_bootsnap_lfi'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.5/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:30:in `require'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/zeitwerk-2.3.1/lib/zeitwerk/kernel.rb:34:in `require'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `block in require'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:291:in `load_dependency'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `require'
/Users/zero/Workspaces/project/config/initializers/sidekiq.rb:7:in `block (2 levels) in <main>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/sidekiq-5.2.7/lib/sidekiq.rb:75:in `configure_server'
/Users/zero/Workspaces/project/config/initializers/sidekiq.rb:4:in `block in <main>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/railtie.rb:216:in `instance_eval'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/railtie.rb:216:in `configure'
/Users/zero/Workspaces/project/config/initializers/sidekiq.rb:3:in `<main>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.5/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:54:in `load'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bootsnap-1.4.5/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:54:in `load'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:318:in `block in load'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:291:in `load_dependency'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:318:in `load'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/engine.rb:666:in `block in load_config_initializer'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/notifications.rb:182:in `instrument'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/engine.rb:665:in `load_config_initializer'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/engine.rb:625:in `block (2 levels) in <class:Engine>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/engine.rb:624:in `each'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/engine.rb:624:in `block in <class:Engine>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/initializable.rb:32:in `instance_exec'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/initializable.rb:32:in `run'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/initializable.rb:61:in `block in run_initializers'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:228:in `block in tsort_each'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:350:in `block (2 levels) in each_strongly_connected_component'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:422:in `block (2 levels) in each_strongly_connected_component_from'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:431:in `each_strongly_connected_component_from'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:421:in `block in each_strongly_connected_component_from'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/initializable.rb:50:in `each'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/initializable.rb:50:in `tsort_each_child'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:415:in `call'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:415:in `each_strongly_connected_component_from'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:349:in `block in each_strongly_connected_component'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:347:in `each'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:347:in `call'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:347:in `each_strongly_connected_component'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:226:in `tsort_each'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/2.7.0/tsort.rb:205:in `tsort_each'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/initializable.rb:60:in `run_initializers'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/railties-6.0.3.2/lib/rails/application.rb:363:in `initialize!'
/Users/zero/Workspaces/project/config/environment.rb:5:in `<top (required)>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `require'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `block in require'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:291:in `load_dependency'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/activesupport-6.0.3.2/lib/active_support/dependencies.rb:324:in `require'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/sidekiq-5.2.7/lib/sidekiq/cli.rb:288:in `boot_system'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/sidekiq-5.2.7/lib/sidekiq/cli.rb:46:in `run'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/sidekiq-5.2.7/bin/sidekiq:12:in `<top (required)>'
/Users/zero/.asdf/installs/ruby/2.7.1/bin/sidekiq:23:in `load'
/Users/zero/.asdf/installs/ruby/2.7.1/bin/sidekiq:23:in `<top (required)>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/cli/exec.rb:63:in `load'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/cli/exec.rb:63:in `kernel_load'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/cli/exec.rb:28:in `run'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/cli.rb:476:in `exec'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor/invocation.rb:127:in `invoke_command'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor.rb:399:in `dispatch'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/cli.rb:30:in `dispatch'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/vendor/thor/lib/thor/base.rb:476:in `start'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/cli.rb:24:in `start'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/exe/bundle:46:in `block in <top (required)>'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/lib/bundler/friendly_errors.rb:123:in `with_friendly_errors'
/Users/zero/.asdf/installs/ruby/2.7.1/lib/ruby/gems/2.7.0/gems/bundler-2.1.4/exe/bundle:34:in `<top (required)>'
/Users/zero/.asdf/installs/ruby/2.7.1/bin/bundle:23:in `load'
/Users/zero/.asdf/installs/ruby/2.7.1/bin/bundle:23:in `<main>'
발생한 코드는 Rails 6의 Release 노트에서 변경된 코드이며 내용은 아래와 같다
Deprecate config.active_record.sqlite3.represent_boolean_as_integer (commit)
변경된 코드를 보면 설정을 재 참조가 불가능하게 삭제해버리는데 사이드킥이 실행되면서 두 번 실행하게 되고 두번째 참조일때 참조값 config.sqlite3
가 nil 이 되면서 발생한다.
activerecord 에 대해서 2번 이상 로드를 진행하면서 발생하고 있었다.
각각의 루비 버전으로 테스트를 진행하였다.
주요 동작에 대해서만 정리하였다.
active_record.set_configs
이벤트에 한번 도달한다.active_record.set_configs
이벤트에 한번 도달한다.active_record.set_configs
이벤트에 도달하여 삭제된 config.sqlite3 를 접근하여 에러가 발생하지만 뉴렐릭이 에러 핸들링이 되어 시스템이 죽지는 않았음 (뉴렐릭 로그 참조)active_record.set_configs
이벤트에 도달하여 삭제된 config.sqlite3 를 접근하여 에러가 발생하며 아예 프로세스가 죽어버림INFO : Starting the New Relic agent version 6.12.0.367 in "bravo" environment.
INFO : To prevent agent startup add a NEW_RELIC_AGENT_ENABLED=false environment variable or modify the "bravo" section of your newrelic.yml.
INFO : Reading configuration from config/newrelic.yml (/Users/zero/Workspaces/project)
INFO : Environment: bravo
INFO : Dispatcher: sidekiq
INFO : Application: Community API (Bravo)
INFO : Installing ActiveStorage 5 instrumentation
INFO : Installing Redis Instrumentation
INFO : Installing notifications based Active Record instrumentation
ERROR : Error while installing active_record_notifications instrumentation:
ERROR : NoMethodError: undefined method `delete' for nil:NilClass
INFO : Installing Sidekiq instrumentation
INFO : Installing Rails 3+ middleware instrumentation
INFO : Installing Net instrumentation
INFO : Installing deferred Rack::Builder instrumentation
INFO : Installing Rack::Builder middleware instrumentation
INFO : Installing ActiveJob instrumentation
INFO : Installing notifications based Action Controller instrumentation
INFO : Installing notification based Action View instrumentation
INFO : Installing notifications based Action Cable instrumentation
INFO : Finished instrumentation
INFO : Starting Agent shutdown
INFO : Reporting to: https://rpm.newrelic.com/accounts/1134941/applications/852446559
즉 원인은 APP_CONFIG가 ActiveRecord 로드 시점에 읽을 수 없어서 YAML 파일을 파싱을 하지 못해 읽을 수 없었던 게 주된 원인이다.
동일하게 Ruby 2.6.5 버전에서도 로드가 실패하지만 재실행 되지 않아서 에러가 발생하지 않는데 이 근본적인 동작 차이는 자세히 확인하기 어려워 시간이 될때 확인해보고자 한다.
다만 sidekiq 가동 시점에 Cannot load database configuration
상태가 발생하였다는 것은 기존에 발생했던 no connection pool
에러도 이와 연관이 있지 않을까? 에 대해서 의심을 할 수 있게 된다.