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

Refreshing replica set from a forked process sometimes causes BSON error

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 12_01_17
    • Affects Version/s: 1.12
    • Component/s: Replica Set
    • Labels:
      None
    • Environment:
      Phusion Passenger with smart spawning enabled

      We recently started using Passenger's smart spawning mode in production, which forks a preloaded process to create workers. This means several processes end up with references to the same connections and sockets. The driver is supposed to detect this case and handle it automatically (see RUBY-250), but we're getting this exception a few dozen times a day:

      TypeError (no c decoder for this type yet (0)):
      /vendor/bundle/ruby/2.1.0/gems/bson-1.12.0/lib/bson/bson_c.rb:24:in `deserialize'
      /vendor/bundle/ruby/2.1.0/gems/bson-1.12.0/lib/bson/bson_c.rb:24:in `deserialize'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/networking.rb:238:in `read_documents'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/networking.rb:184:in `receive'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/networking.rb:146:in `receive_message'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:551:in `block in send_initial_query'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:547:in `send_initial_query'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:532:in `refresh'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:139:in `next'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/db.rb:605:in `command'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/node.rb:110:in `block (2 levels) in set_config'
      /vendor/ruby-2.1.5/lib/ruby/2.1.0/timeout.rb:91:in `block in timeout'
      /vendor/ruby-2.1.5/lib/ruby/2.1.0/timeout.rb:101:in `call'
      /vendor/ruby-2.1.5/lib/ruby/2.1.0/timeout.rb:101:in `timeout'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/node.rb:109:in `block in set_config'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/node.rb:102:in `synchronize'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/node.rb:102:in `set_config'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/pool_manager.rb:183:in `block in connect_to_members'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/pool_manager.rb:179:in `each'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/pool_manager.rb:179:in `connect_to_members'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/pool_manager.rb:70:in `block in connect'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/pool_manager.rb:65:in `synchronize'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/pool_manager.rb:65:in `connect'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/connection/pool_manager.rb:83:in `refresh!'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:206:in `block in connect'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:199:in `synchronize'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:199:in `connect'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:259:in `hard_refresh!'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:245:in `refresh'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:521:in `sync_refresh'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:341:in `checkout'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/mongo_replica_set_client.rb:359:in `checkout_reader'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:625:in `checkout_socket_from_connection'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:550:in `block in send_initial_query'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:547:in `send_initial_query'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:532:in `refresh'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/cursor.rb:139:in `next'
      /vendor/bundle/ruby/2.1.0/gems/mongo-1.12.0/lib/mongo/collection.rb:329:in `find_one'
      

      The stack trace here looks very similar to the one in RUBY-464.

      The error only happens when the replica set is being refreshed. That operation uses a different socket than the ones used for queries, which isn't automatically reopened after the process is forked.

      I opened a pull request with a patch to detect when the socket used to refresh the replica set was created in a different process and open a new one: https://github.com/mongodb/mongo-ruby-driver/pull/585

            Assignee:
            emily.stolfo Emily Stolfo
            Reporter:
            eugeneius Eugene Kenny
            Votes:
            1 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: