Uploaded image for project: 'Mongoid'
  1. Mongoid
  2. MONGOID-4398

Client initialization race leads to connection and thread leak on MRI Ruby

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 6.1.0, 12_01_17
    • Affects Version/s: 6.0.3
    • Component/s: None
    • None
    • Environment:
      MRI Ruby 2.3.3, Mongo driver 2.4.0, Mongo server 3.2

      Mongoid employs no synchronization when initializing mongo client instances. This means that data races can happen as the ||= is not atomic.

      from https://github.com/mongodb/mongoid/blob/v6.0.3/lib/mongoid/clients.rb:

            def default
              clients[:default] ||= Clients::Factory.default
            end
      
            def with_name(name)
              clients[name.to_sym] ||= Clients::Factory.create(name)
            end
      

      To try and simulate this, I added a sleep to the Mongo::Client initialization to trigger the issue more often

      ENV['RACK_ENV'] ||= 'development'
      
      require 'mongoid'
      
      module SlowClient
        def new(*args)
          sleep 1
          puts "Attempting to create a client..."
      
          super
        end
      end
      
      Mongo::Client.singleton_class.prepend SlowClient
      
      class DummyDocument
        include ::Mongoid::Document
      
        store_in collection: 'dummydocs'
      end
      
      Mongoid.load!('mongoid.yml')
      
      puts "Locked and loaded"
      
      sleep 1
      
      puts "Requesting..."
      
      10.times.map do
        Thread.new do
          DummyDocument.find('584de8800000000000000000')
        end
      end.each(&:join)
      
      puts "Requests done"
      
      sleep 1
      
      puts "Thread list:"
      
      Thread.list.each do |t|
        puts t.backtrace.first
      end
      
      puts "Count: #{Thread.list.count}"
      

      And this is the output of running this example:

      $ bundle exec ruby testcase.rb
      Locked and loaded
      Requesting...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Attempting to create a client...
      Requests done
      Thread list:
      boom_mongoid.rb:43:in `backtrace'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/server/monitor.rb:123:in `sleep'
      ~/.rvm/gems/ruby-2.3.3/gems/mongo-2.4.0/lib/mongo/cluster/cursor_reaper.rb:167:in `sleep'
      Count: 21
      

      Each thread creates its own Mongo::Client, and each client leaves the monitor and cursor reaper thread running in the background.

      We were hit by this issue when doing deploys/restarts in a high-traffic system using the puma threaded web server.

            Assignee:
            emily.stolfo Emily Stolfo
            Reporter:
            ivoanjo Ivo Anjo
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: