-
Type:
Bug
-
Resolution: Done
-
Priority:
Critical - P2
-
Affects Version/s: 1.8.4
-
Component/s: None
-
None
-
Environment:Ubuntu 12.04 LTS x64
JRuby 1.7.2 and TorqueBox 2.3.0
MongoDB 2.4.1 cluster
mongo-ruby-driver 1.8.4
We are periodically getting a slew of this exception from different app servers in our cluster. It comes from any number of app requests and seems to be buried in the guts of the PoolManager. I know there's been a lot of recent work there. I've never seen this before running Mongo 2.4.1 and the driver 1.8.4. We upgraded both at roughly the same time and these errors started a few days later.
(RuntimeError) "can't add a new key into hash during iteration" org/jruby/RubyHash.java:954:in `[]=' /opt/torquebox/current/jruby/lib/ruby/1.9/set.rb:229:in `add' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/util/pool_manager.rb:164:in `connect_to_members' org/jruby/RubyArray.java:1613:in `each' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/util/pool_manager.rb:145:in `connect_to_members' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/util/pool_manager.rb:45:in `connect' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/util/pool_manager.rb:52:in `refresh!' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/mongo_replica_set_client.rb:231:in `hard_refresh!' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/mongo_replica_set_client.rb:217:in `refresh' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/cursor.rb:476:in `send_initial_query' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/cursor.rb:470:in `send_initial_query' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/cursor.rb:467:in `send_initial_query' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/util/logging.rb:33:in `instrument' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/util/logging.rb:65:in `instrument' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/util/logging.rb:32:in `instrument' /data/myapp/releases/20130404023619/config/initializers/newrelic_rpm_instrumentation.rb:191:in `instrument_with_newrelic_trace' /data/myapp/releases/20130404023619/config/initializers/newrelic_rpm_instrumentation.rb:190:in `instrument_with_newrelic_trace' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:240:in `trace_execution_scoped' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:239:in `trace_execution_scoped' /data/myapp/releases/20130404023619/config/initializers/newrelic_rpm_instrumentation.rb:188:in `instrument_with_newrelic_trace' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/cursor.rb:466:in `send_initial_query' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/cursor.rb:451:in `refresh' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/cursor.rb:110:in `next' /data/myapp/shared/bundle/jruby/1.9/gems/mongo-1.8.4/lib/mongo/collection.rb:303:in `find_one' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid/collections/master.rb:25:in `find_one' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid/collections/retry.rb:29:in `retry_on_connection_failure' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid/collections/master.rb:24:in `find_one' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid/collection.rb:60:in `find_one' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:491:in `find_one_with_trace_ActiveRecord_klass_find_one' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:240:in `trace_execution_scoped' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:239:in `trace_execution_scoped' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:486:in `find_one_with_trace_ActiveRecord_klass_find_one' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid/contexts/mongo.rb:205:in `first' org/jruby/RubyBasicObject.java:1659:in `__send__' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid/criteria.rb:44:in `first' /data/myapp/releases/20130404023619/app/models/account.rb:232:in `find_by_subdomain' /data/myapp/releases/20130404023619/app/models/account_domain_router.rb:76:in `account' /data/myapp/releases/20130404023619/app/controllers/api/api_controller.rb:60:in `current_account' /data/myapp/releases/20130404023619/app/controllers/api/api_controller.rb:64:in `require_account' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:454:in `_run__601909761__process_action__933197237__callbacks' org/jruby/RubyBasicObject.java:1659:in `__send__' org/jruby/RubyKernel.java:2086:in `send' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:405:in `__run_callback' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:390:in `_run_process_action_callbacks' org/jruby/RubyBasicObject.java:1665:in `__send__' org/jruby/RubyKernel.java:2090:in `send' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:81:in `run_callbacks' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/abstract_controller/callbacks.rb:17:in `process_action' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_controller/metal/rescue.rb:29:in `process_action' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_controller/metal/instrumentation.rb:30:in `process_action' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/notifications.rb:123:in `instrument' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/notifications/instrumenter.rb:20:in `instrument' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/notifications/instrumenter.rb:19:in `instrument' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/notifications.rb:123:in `instrument' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_controller/metal/instrumentation.rb:29:in `process_action' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_controller/metal/params_wrapper.rb:207:in `process_action' /data/myapp/shared/bundle/jruby/1.9/bundler/gems/mongo-rails-instrumentation-5f092002b7a5/lib/mongo/rails/instrumentation/controller_runtime.rb:13:in `process_action' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:34:in `process_action' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:268:in `perform_action_with_newrelic_trace' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:240:in `trace_execution_scoped' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/method_tracer.rb:239:in `trace_execution_scoped' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:263:in `perform_action_with_newrelic_trace' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/instrumentation/controller_instrumentation.rb:262:in `perform_action_with_newrelic_trace' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/agent/instrumentation/rails3/action_controller.rb:33:in `process_action' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/abstract_controller/base.rb:121:in `process' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/abstract_controller/rendering.rb:45:in `process' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_controller/metal.rb:203:in `dispatch' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_controller/metal/rack_delegation.rb:14:in `dispatch' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_controller/metal.rb:246:in `action' org/jruby/RubyProc.java:249:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/routing/route_set.rb:73:in `dispatch' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/routing/route_set.rb:36:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/routing/mapper.rb:42:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/journey-1.0.4/lib/journey/router.rb:68:in `call' org/jruby/RubyArray.java:1613:in `each' /data/myapp/shared/bundle/jruby/1.9/gems/journey-1.0.4/lib/journey/router.rb:56:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/routing/route_set.rb:601:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/newrelic_rpm-3.5.5.38/lib/new_relic/rack/error_collector.rb:8:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/rack/mongoid/middleware/identity_map.rb:33:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid.rb:133:in `unit_of_work' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/mongoid.rb:132:in `unit_of_work' /data/myapp/shared/bundle/jruby/1.9/gems/mongoid-2.5.1/lib/rack/mongoid/middleware/identity_map.rb:33:in `call' /data/myapp/releases/20130404023619/lib/backpack/middleware/downcase_route.rb:28:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/rack-statsd-0.1.1/lib/rack-statsd.rb:71:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/warden-1.2.1/lib/warden/manager.rb:35:in `call' org/jruby/RubyKernel.java:1174:in `catch' /data/myapp/shared/bundle/jruby/1.9/gems/warden-1.2.1/lib/warden/manager.rb:34:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/best_standards_support.rb:17:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/rack-1.4.5/lib/rack/etag.rb:23:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/rack-1.4.5/lib/rack/conditionalget.rb:25:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/head.rb:14:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/params_parser.rb:21:in `call' /data/myapp/releases/20130404023619/lib/backpack/middleware/web_dav_content_type.rb:27:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/flash.rb:242:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:210:in `context' /data/myapp/shared/bundle/jruby/1.9/gems/rack-1.4.5/lib/rack/session/abstract/id.rb:205:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/cookies.rb:341:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/callbacks.rb:28:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:408:in `_run__784305661__call__1499709935__callbacks' org/jruby/RubyBasicObject.java:1659:in `__send__' org/jruby/RubyKernel.java:2086:in `send' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:405:in `__run_callback' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:390:in `_run_call_callbacks' org/jruby/RubyBasicObject.java:1659:in `__send__' org/jruby/RubyKernel.java:2086:in `send' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/callbacks.rb:81:in `run_callbacks' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/callbacks.rb:27:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/rack-1.4.5/lib/rack/sendfile.rb:102:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/remote_ip.rb:31:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/debug_exceptions.rb:16:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/show_exceptions.rb:56:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/lograge-0.1.2/lib/lograge/rails_ext/rack/logger.rb:14:in `call_app' /data/myapp/shared/bundle/jruby/1.9/gems/railties-3.2.12/lib/rails/rack/logger.rb:16:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/activesupport-3.2.12/lib/active_support/tagged_logging.rb:22:in `tagged' /data/myapp/shared/bundle/jruby/1.9/gems/railties-3.2.12/lib/rails/rack/logger.rb:16:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/request_id.rb:22:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/rack-1.4.5/lib/rack/methodoverride.rb:21:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/rack-1.4.5/lib/rack/runtime.rb:17:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/actionpack-3.2.12/lib/action_dispatch/middleware/static.rb:62:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/railties-3.2.12/lib/rails/engine.rb:479:in `call' /data/myapp/shared/bundle/jruby/1.9/gems/railties-3.2.12/lib/rails/application.rb:223:in `call' org/jruby/RubyBasicObject.java:1665:in `__send__' org/jruby/RubyKernel.java:2090:in `send' /data/myapp/shared/bundle/jruby/1.9/gems/railties-3.2.12/lib/rails/railtie/configurable.rb:30:in `method_missing'