-
Type:
Task
-
Resolution: Done
-
Affects Version/s: None
-
Component/s: None
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.
- related to
-
MONGOID-4157 New client created every time when using Model.with(collection: "...")
-
- Closed
-