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

ArgumentError when max_message_size is nil and a message is deserialized

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Minor - P4 Minor - P4
    • 2.2.2
    • Affects Version/s: 2.2.1
    • Component/s: None
    • Labels:
      None

      We upgraded a cluster to 3.0.8 today and under heavy load the mongoS CPU skyrocketed, which caused a bunch of failures for us. Until we got the mongoS under control, we had thousands of failures from processes which seemed to be talking to that mongoS. I've attached a stack trace.

      What are your thoughts here? I've considered doing something like raising an OperationFailure with a magic reconnect string like "query failed" if the deserialize_header method ends up returning an empty array, which should rescan and reconnect.

      Jan 07 13:10:26 production.log: [ 6:10:26.455541342] (25416) [ERROR] Uncaught exception: ArgumentError: comparison of Fixnum with nil failed (comparison of Fixnum with nil failed)
      Jan 07 13:10:26 production.log: [ 6:10:26.456353665] (25416) [INFO] Stack trace of preceding exception:
      Jan 07 13:10:26 production.log: [ 6:10:26.456826961] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/protocol/message.rb:117:in `>'
      Jan 07 13:10:26 production.log: [ 6:10:26.457341328] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/protocol/message.rb:117:in `deserialize'
      Jan 07 13:10:26 production.log: [ 6:10:26.457783375] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connectable.rb:107:in `block in read'
      Jan 07 13:10:26 production.log: [ 6:10:26.458217886] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connectable.rb:91:in `ensure_connected'
      Jan 07 13:10:26 production.log: [ 6:10:26.458624425] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connectable.rb:106:in `read'
      Jan 07 13:10:26 production.log: [ 6:10:26.458946512] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:180:in `deliver'
      Jan 07 13:10:26 production.log: [ 6:10:26.459239606] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:124:in `block in dispatch'
      Jan 07 13:10:26 production.log: [ 6:10:26.459529114] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/monitoring/publishable.rb:47:in `publish_command'
      Jan 07 13:10:26 production.log: [ 6:10:26.459854535] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:123:in `dispatch'
      Jan 07 13:10:26 production.log: [ 6:10:26.460184791] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/auth/cr.rb:57:in `login'
      Jan 07 13:10:26 production.log: [ 6:10:26.460463864] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:100:in `authenticate!'
      Jan 07 13:10:26 production.log: [ 6:10:26.460726332] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:65:in `connect!'
      Jan 07 13:10:26 production.log: [ 6:10:26.460997762] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connectable.rb:89:in `ensure_connected'
      Jan 07 13:10:26 production.log: [ 6:10:26.461285063] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:205:in `write'
      Jan 07 13:10:26 production.log: [ 6:10:26.461602737] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:179:in `deliver'
      Jan 07 13:10:26 production.log: [ 6:10:26.461893333] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:124:in `block in dispatch'
      Jan 07 13:10:26 production.log: [ 6:10:26.462198144] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/monitoring/publishable.rb:47:in `publish_command'
      Jan 07 13:10:26 production.log: [ 6:10:26.462451279] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:123:in `dispatch'
      Jan 07 13:10:26 production.log: [ 6:10:26.462706619] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/auth/cr.rb:57:in `login'
      Jan 07 13:10:26 production.log: [ 6:10:26.462995311] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection.rb:100:in `authenticate!'
      Jan 07 13:10:26 production.log: [ 6:10:26.463274500] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/context.rb:66:in `block in with_connection'
      Jan 07 13:10:26 production.log: [ 6:10:26.463537944] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/connection_pool.rb:108:in `with_connection'
      Jan 07 13:10:26 production.log: [ 6:10:26.463779126] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/server/context.rb:63:in `with_connection'
      Jan 07 13:10:26 production.log: [ 6:10:26.463854208] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/operation/executable.rb:34:in `execute'
      Jan 07 13:10:26 production.log: [ 6:10:26.463898893] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/collection/view/iterable.rb:79:in `send_initial_query'
      Jan 07 13:10:26 production.log: [ 6:10:26.463946978] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/collection/view/iterable.rb:41:in `block in each'
      Jan 07 13:10:26 production.log: [ 6:10:26.463985731] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/retryable.rb:48:in `call'
      Jan 07 13:10:26 production.log: [ 6:10:26.464022837] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/retryable.rb:48:in `read_with_retry'
      Jan 07 13:10:26 production.log: [ 6:10:26.464058912] (25416) [INFO] /var/www/platform/shared/dashboard/bundle/ruby/2.2.0/bundler/gems/mongo-ruby-driver-e081de005a92/lib/mongo/collection/view/iterable.rb:39:in `each'

            Assignee:
            emily.stolfo Emily Stolfo
            Reporter:
            jonhyman Jon Hyman
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: