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

Port usage through the roof / IOError / 5.0.0.beta

    XMLWordPrintable

Details

    • Task
    • Status: Closed
    • Resolution: Done
    • None
    • 5.0.0
    • None

    Description

      I'm not sure if this is a MongoDB, Mongoid or Moped problem, but I'm getting massive port usage while inserting into the database.

      It looks like that for each insert the driver is opening a new connection to the database, spawning a never dying thread which keeps it's own port open.

      The log near the error:

      # ... this goes for a while ...
      D, [2015-07-14T15:35:13.714276 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.insert | SUCCEEDED | 0.004395s
      D, [2015-07-14T15:35:13.716073 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.find | STARTED | {:filter=>{"_id"=><BSON::ObjectId:0x70241950927080 data=55a556595175610ba6000420>}, :project=>nil, :skip=>nil, :limit=>nil, :flags=>[:slave_ok]}
      D, [2015-07-14T15:35:13.716664 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.find | SUCCEEDED | 0.00062s
      D, [2015-07-14T15:35:13.717464 MONGOID-2982] DEBUG -- : MONGODB | Adding 127.0.0.1:27017 to the cluster. | runtime: 0.0079ms
      D, [2015-07-14T15:35:13.725873 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.insert | STARTED | {:insert=>"invoice_lines_calls", :documents=>[{"_id"=><BSON::ObjectId:0x70241894454620 data=55a556615175610ba600057b>, "caller"=>"REDACTED", "timestamp"=>2014-12-05 14:20:18 UTC, "duration"=>66, "destination_prefix"=>"48", "destination_number"=>"9...
      D, [2015-07-14T15:35:13.731809 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.insert | SUCCEEDED | 0.006016s
      D, [2015-07-14T15:35:13.733481 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.find | STARTED | {:filter=>{"_id"=><BSON::ObjectId:0x70241950927080 data=55a556595175610ba6000420>}, :project=>nil, :skip=>nil, :limit=>nil, :flags=>[:slave_ok]}
      D, [2015-07-14T15:35:13.733899 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.find | SUCCEEDED | 0.000453s
      D, [2015-07-14T15:35:13.734600 MONGOID-2982] DEBUG -- : MONGODB | Adding 127.0.0.1:27017 to the cluster. | runtime: 0.0069ms
      D, [2015-07-14T15:35:13.749801 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.insert | STARTED | {:insert=>"invoice_lines_calls", :documents=>[{"_id"=><BSON::ObjectId:0x70241898694400 data=55a556615175610ba600057c>, "caller"=>"REDACTED", "timestamp"=>2014-12-05 17:36:11 UTC, "duration"=>30, "destination_prefix"=>"48", "destination_number"=>"9...
      D, [2015-07-14T15:35:13.754060 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.insert | SUCCEEDED | 0.004342s
      D, [2015-07-14T15:35:13.756130 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.find | STARTED | {:filter=>{"_id"=><BSON::ObjectId:0x70241950927080 data=55a556595175610ba6000420>}, :project=>nil, :skip=>nil, :limit=>nil, :flags=>[:slave_ok]}
      D, [2015-07-14T15:35:13.756601 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.find | SUCCEEDED | 0.000509s
      D, [2015-07-14T15:35:13.757380 MONGOID-2982] DEBUG -- : MONGODB | Adding 127.0.0.1:27017 to the cluster. | runtime: 0.0079ms
      D, [2015-07-14T15:35:13.764873 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.insert | STARTED | {:insert=>"invoice_lines_calls", :documents=>[{"_id"=><BSON::ObjectId:0x70241898792900 data=55a556615175610ba600057d>, "caller"=>"REDACTED", "timestamp"=>2014-12-06 15:15:23 UTC, "duration"=>30, "destination_prefix"=>"48", "destination_number"=>"9...
      D, [2015-07-14T15:35:13.769091 MONGOID-2982] DEBUG -- : MONGODB | 127.0.0.1:27017 | mx_test.insert | FAILED | IOError | 0.004289s
      

      As reported by the activity monitor just before the app crashed:

      • mongod Threads: 1716;
      • mongod Ports: 1701;

      I find it weird that for each insert there's a Adding 127.0.0.1:27017 to the cluster entry.

      There are 1022 inserts on the invoice_lines_calls collection before the crash.

      This app is running normally at dev/test/staging/production on MongoDB 2.6 + Mongoid 4.

      This test is part of the rspec suite, and it was run locally on OSX using (single instance) MongoDB 3.0.4 + Mongoid 5.0.0.beta . All these inserts are running from the same Sidekiq process/job.

      Any ideas on how to narrow down the problem? I'm willing dig this up to the bone.

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              lucasmartins lucasmartins
              Votes:
              0 Vote for this issue
              Watchers:
              0 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: