Occasional deadlocks between Dependencies::Interlock and db adapter lock #34310
Description
In our rspec test environment, some feature specs occasionally hang. Generating stack traces using the sigdump gem and ActionDispatch::DebugLocks I was able to narrow it down to roughly the following.
There are two request threads, A and B, and another thread accessing the database C. When requests start they call ActiveSupport::Dependencies.interlock.start_sharing and if they need to autoload any files, they upgrade to interlock.exclusive. When threads use the database, they call AbstractAdapter#log which acquires a separate lock for the database connection (which is a LoadInterlockAwareMonitor). Then I have the following:
| Thread A | Thread B | Thread C |
|---|---|---|
| gets interlock share lock | ||
| gets interlock share lock | ||
| gets db connection lock | ||
calls AbstractAdapter#log |
||
| notes it can't get db lock right away (blocked on C) | ||
| releases interlock share and waits on db lock | ||
| tries to autoload a model | ||
| upgrades to an exclusive interlock | ||
| releases the db connection lock | ||
| takes the db lock | ||
| tries to reclaim interlock share lock | ||
| blocked on thread A which has exclusive lock | ||
| requires a db query to load schema | ||
calls AbstractAdapter#log |
||
| notes it can't get db lock right away (blocked on B) | ||
| does not release interlock as exclusive and waits on db lock | ||
| waits on db connection lock |
And then A and B wait forever. Also of note, rspec cleanup requires rolling back a transaction which requires the db connection lock so rspec also hangs forever.
Steps to reproduce
It's hard to actually reproduce this as it's so timing based but I created this unit test 7ab4f35. I also added the full ActionDispatch::DebugLocks output at the end.
Expected behavior
All requests complete
Actual behavior
The test suite hangs
System configuration
Rails version: 5.1.6 (the test also reproduces against master)
Ruby version: 2.3.6 (the test also reproduces against 2.5.1)
ActionDispatch::DebugLocks output
Thread 0 [0xa06e4b0 sleep] No lock (yielded share)
Waiting in yield_shares
may be pre-empted for: "load", share
blocked by: 1
/usr/local/lib/ruby/2.3.0/monitor.rb:111:in sleep' /usr/local/lib/ruby/2.3.0/monitor.rb:111:in wait'
/usr/local/lib/ruby/2.3.0/monitor.rb:111:in wait' /usr/local/lib/ruby/2.3.0/monitor.rb:123:in wait_while'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:221:in wait_for' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:189:in block in yield_shares'
/usr/local/lib/ruby/2.3.0/monitor.rb:214:in mon_synchronize' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:187:in yield_shares'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:45:in permit_concurrent_loads' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:13:in mon_enter'
/usr/local/lib/ruby/2.3.0/monitor.rb:212:in mon_synchronize' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:612:in block in log'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in instrument' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:604:in log'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:614:in exec_no_cache' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:603:in execute_and_clear'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql/database_statements.rb:79:in exec_query' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:371:in select'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/database_statements.rb:42:in select_all' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract/query_cache.rb:97:in select_all'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/relation/calculations.rb:176:in pluck' <app code which queries the database> /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:413:in instance_exec'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:413:in block in make_lambda' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:197:in block (2 levels) in halting'
/usr/local/bundle/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:12:in block (2 levels) in <module:Callbacks>' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:198:in block in halting'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:507:in block in invoke_before' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:507:in each'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:507:in invoke_before' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:130:in run_callbacks'
/usr/local/bundle/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:19:in process_action' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/rescue.rb:20:in process_action'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:32:in block in process_action' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in block in instrument'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in instrument' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in instrument'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:30:in process_action' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/params_wrapper.rb:252:in process_action'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/railties/controller_runtime.rb:22:in process_action' /usr/local/bundle/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:124:in process'
/usr/local/bundle/gems/actionview-5.1.6/lib/action_view/rendering.rb:30:in process' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal.rb:189:in dispatch'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal.rb:253:in dispatch' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:49:in dispatch'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:31:in serve' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:16:in block in class:Constraints'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:46:in serve' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:50:in block in serve'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in each' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in serve'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:844:in call' /usr/local/bundle/gems/warden-1.2.7/lib/warden/manager.rb:36:in block in call'
/usr/local/bundle/gems/warden-1.2.7/lib/warden/manager.rb:35:in catch' /usr/local/bundle/gems/warden-1.2.7/lib/warden/manager.rb:35:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/etag.rb:25:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/head.rb:12:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in context'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/cookies.rb:613:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:26:in block in call' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:97:in run_callbacks'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:24:in call' /usr/local/bundle/gems/bugsnag-6.7.3/lib/bugsnag/integrations/rack.rb:46:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/debug_exceptions.rb:59:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/show_exceptions.rb:31:in call'
/usr/local/bundle/gems/railties-5.1.6/lib/rails/rack/logger.rb:36:in call_app' /usr/local/bundle/gems/railties-5.1.6/lib/rails/rack/logger.rb:24:in block in call'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/tagged_logging.rb:69:in block in tagged' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/tagged_logging.rb:26:in tagged'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/tagged_logging.rb:69:in tagged' /usr/local/bundle/gems/railties-5.1.6/lib/rails/rack/logger.rb:24:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/remote_ip.rb:79:in call' /usr/local/bundle/gems/request_store-1.4.1/lib/request_store/middleware.rb:19:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/request_id.rb:25:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/method_override.rb:22:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/runtime.rb:22:in call' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/executor.rb:12:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in call' /usr/local/bundle/gems/rack-utf8_sanitizer-1.4.0/lib/rack/utf8_sanitizer.rb:20:in call'
/usr/local/bundle/gems/secure_headers-6.0.0.alpha02/lib/secure_headers/middleware.rb:13:in call' /usr/local/bundle/gems/railties-5.1.6/lib/rails/engine.rb:522:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/urlmap.rb:68:in block in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in each'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in call' /usr/local/bundle/gems/capybara-3.7.2/lib/capybara/server/middleware.rb:48:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/handler/webrick.rb:86:in service' /usr/local/lib/ruby/2.3.0/webrick/httpserver.rb:140:in service'
/usr/local/lib/ruby/2.3.0/webrick/httpserver.rb:96:in run' /usr/local/lib/ruby/2.3.0/webrick/server.rb:314:in block in start_thread'
Thread 1 [0x331cad8 sleep] Exclusive (yielded share)
blocking: 0
/usr/local/lib/ruby/2.3.0/monitor.rb:187:in lock' /usr/local/lib/ruby/2.3.0/monitor.rb:187:in mon_enter'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:13:in block in mon_enter' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:46:in block in permit_concurrent_loads'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:185:in yield_shares' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:45:in permit_concurrent_loads'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/load_interlock_aware_monitor.rb:13:in mon_enter' /usr/local/lib/ruby/2.3.0/monitor.rb:212:in mon_synchronize'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:612:in block in log' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in instrument'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:604:in log' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql/database_statements.rb:59:in query'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/postgresql_adapter.rb:765:in column_definitions' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/abstract_adapter.rb:167:in columns'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/schema_cache.rb:67:in columns' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/connection_adapters/schema_cache.rb:73:in columns_hash'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/model_schema.rb:471:in load_schema!' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/attributes.rb:233:in load_schema!'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/attribute_decorators.rb:50:in load_schema!' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/model_schema.rb:464:in block in load_schema'
/usr/local/lib/ruby/2.3.0/monitor.rb:214:in mon_synchronize' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/model_schema.rb:461:in load_schema'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/model_schema.rb:353:in attribute_types' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/attribute_methods.rb:164:in attribute_names'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/attribute_methods.rb:62:in block in define_attribute_methods' /usr/local/lib/ruby/2.3.0/mutex_m.rb:74:in synchronize'
/usr/local/lib/ruby/2.3.0/mutex_m.rb:74:in mu_synchronize' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/attribute_methods.rb:59:in define_attribute_methods'
/usr/local/bundle/gems/bootsnap-1.3.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:21:in require' /usr/local/bundle/gems/bootsnap-1.3.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:21:in block in require_with_bootsnap_lfi'
/usr/local/bundle/gems/bootsnap-1.3.0/lib/bootsnap/load_path_cache/loaded_features_index.rb:65:in register' /usr/local/bundle/gems/bootsnap-1.3.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:20:in require_with_bootsnap_lfi'
/usr/local/bundle/gems/bootsnap-1.3.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:29:in require' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:292:in block in require'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:258:in load_dependency' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:292:in require'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:379:in block in require_or_load' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:36:in block in load_interlock'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:12:in block in loading' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/concurrency/share_lock.rb:149:in exclusive'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies/interlock.rb:11:in loading' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:36:in load_interlock'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:357:in require_or_load' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:511:in load_missing_constant'
/usr/local/bundle/gems/bootsnap-1.3.0/lib/bootsnap/load_path_cache/core_ext/active_support.rb:43:in load_missing_constant' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:202:in const_missing'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/inflector/methods.rb:271:in const_get' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/inflector/methods.rb:271:in block in constantize'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/inflector/methods.rb:267:in each' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/inflector/methods.rb:267:in inject'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/inflector/methods.rb:267:in constantize' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/inflector/methods.rb:312:in safe_constantize'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:589:in safe_get' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/dependencies.rb:620:in safe_constantize'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/inheritance.rb:159:in block in compute_type' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/inheritance.rb:158:in each'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/inheritance.rb:158:in compute_type' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:408:in compute_class'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:404:in klass' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:621:in automatic_inverse_of'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:609:in block in inverse_name' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:609:in fetch'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:609:in inverse_name' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:523:in has_inverse?'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:236:in check_validity_of_inverse!' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/reflection.rb:474:in check_validity!'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/associations/association.rb:25:in initialize' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/associations.rb:265:in new'
/usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/associations.rb:265:in association' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/associations/builder/association.rb:111:in integration'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/basic_implicit_render.rb:4:in send_action' /usr/local/bundle/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:186:in process_action'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/rendering.rb:30:in process_action' /usr/local/bundle/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:20:in block in process_action'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:131:in run_callbacks' /usr/local/bundle/gems/actionpack-5.1.6/lib/abstract_controller/callbacks.rb:19:in process_action'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/rescue.rb:20:in process_action' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:32:in block in process_action'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in block in instrument' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications/instrumenter.rb:21:in instrument'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/notifications.rb:166:in instrument' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/instrumentation.rb:30:in process_action'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal/params_wrapper.rb:252:in process_action' /usr/local/bundle/gems/activerecord-5.1.6/lib/active_record/railties/controller_runtime.rb:22:in process_action'
/usr/local/bundle/gems/actionpack-5.1.6/lib/abstract_controller/base.rb:124:in process' /usr/local/bundle/gems/actionview-5.1.6/lib/action_view/rendering.rb:30:in process'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal.rb:189:in dispatch' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_controller/metal.rb:253:in dispatch'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:49:in dispatch' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:31:in serve'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:16:in block in <class:Constraints>' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/mapper.rb:46:in serve'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:50:in block in serve' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in each'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/journey/router.rb:33:in serve' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/routing/route_set.rb:844:in call'
/usr/local/bundle/gems/warden-1.2.7/lib/warden/manager.rb:36:in block in call' /usr/local/bundle/gems/warden-1.2.7/lib/warden/manager.rb:35:in catch'
/usr/local/bundle/gems/warden-1.2.7/lib/warden/manager.rb:35:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/etag.rb:25:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/conditional_get.rb:38:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/head.rb:12:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:232:in context' /usr/local/bundle/gems/rack-2.0.5/lib/rack/session/abstract/id.rb:226:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/cookies.rb:613:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:26:in block in call'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/callbacks.rb:97:in run_callbacks' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/callbacks.rb:24:in call'
/usr/local/bundle/gems/bugsnag-6.7.3/lib/bugsnag/integrations/rack.rb:46:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/debug_exceptions.rb:59:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/show_exceptions.rb:31:in call' /usr/local/bundle/gems/railties-5.1.6/lib/rails/rack/logger.rb:36:in call_app'
/usr/local/bundle/gems/railties-5.1.6/lib/rails/rack/logger.rb:24:in block in call' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/tagged_logging.rb:69:in block in tagged'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/tagged_logging.rb:26:in tagged' /usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/tagged_logging.rb:69:in tagged'
/usr/local/bundle/gems/railties-5.1.6/lib/rails/rack/logger.rb:24:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/remote_ip.rb:79:in call'
/usr/local/bundle/gems/request_store-1.4.1/lib/request_store/middleware.rb:19:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/request_id.rb:25:in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/method_override.rb:22:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/runtime.rb:22:in call'
/usr/local/bundle/gems/activesupport-5.1.6/lib/active_support/cache/strategy/local_cache_middleware.rb:27:in call' /usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/executor.rb:12:in call'
/usr/local/bundle/gems/actionpack-5.1.6/lib/action_dispatch/middleware/static.rb:125:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/sendfile.rb:111:in call'
/usr/local/bundle/gems/rack-utf8_sanitizer-1.4.0/lib/rack/utf8_sanitizer.rb:20:in call' /usr/local/bundle/gems/secure_headers-6.0.0.alpha02/lib/secure_headers/middleware.rb:13:in call'
/usr/local/bundle/gems/railties-5.1.6/lib/rails/engine.rb:522:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/urlmap.rb:68:in block in call'
/usr/local/bundle/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in each' /usr/local/bundle/gems/rack-2.0.5/lib/rack/urlmap.rb:53:in call'
/usr/local/bundle/gems/capybara-3.7.2/lib/capybara/server/middleware.rb:48:in call' /usr/local/bundle/gems/rack-2.0.5/lib/rack/handler/webrick.rb:86:in service'
/usr/local/lib/ruby/2.3.0/webrick/httpserver.rb:140:in service' /usr/local/lib/ruby/2.3.0/webrick/httpserver.rb:96:in run'
/usr/local/lib/ruby/2.3.0/webrick/server.rb:314:in `block in start_thread'