Uploaded image for project: 'Ruby Driver'
  1. Ruby Driver
  2. RUBY-578

Intermittent (RuntimeError) "can't add a new key into hash during iteration" in PoolManager#connect_to_members

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Critical - P2 Critical - P2
    • 1.8.6
    • Affects Version/s: 1.8.4
    • Component/s: None
    • Labels:
      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'
      

            Assignee:
            emily.stolfo Emily Stolfo
            Reporter:
            dougtmayer Doug Mayer
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: