scoped connection not being returned to the pool

[Pavel Dimow]

Hi,

I have simple mongodb (version 3.6.2) setup (replica set with three members, primary, secondary and arbiter) and every 5 minutes I see these messages in log on a secondary server.

The number of open connections is always increasing. To me it looks like some kind of monitoring but I am not sure.

Any thoughts on this?

2018-03-17T11:05:11.534+0000 I NETWORK  [thread7] scoped connection to mongodb2:27017 not being returned to the pool

2018-03-17T11:05:11.535+0000 I NETWORK  [thread7] Starting new replica set monitor for my-replica-set/172.16.3.52:27017,mongodb2:27017

2018-03-17T11:05:11.537+0000 I NETWORK  [thread7] Successfully connected to mongodb2:27017 (1872 connections now open to mongodb2:27017 with a 0 second timeout)

[Kevin Adistambha]

Hi Pavel

Replica set members will monitor each other (see Replication) so that every node is aware of the status of every other node in the set.

Also, if your application is connected to the replica set (e.g. using the replicaSet option in the URI string), then the driver will automatically monitor the whole replica set. Please see What’s the point of periodic monitoring in the Server Discovery and Monitoring spec.

Are you seeing any issue that was caused by the connections?

Best regards
Kevin

​

[Pavel Dimow]

Hi Kevin,

sorry for my late reply, I have lost a faith that somebody will answer my question. The this is that I don't see any issues right now, but I am worried about this:

(1872 connections now open to mongodb2:27017 with a 0 second timeout)

this number is now much higher around 37000, and I don't understand why there are 37000 open connections? 

[Kevin Adistambha]

Hi Pavel

this number is now much higher around 37000, and I don’t understand why there are 37000 open connections?

One possible cause is an application opened a connection and don’t close them when it is done with it.

The message “scoped connection not being returned to the pool” originated from this line in the MongoDB 3.6.4 source code: https://github.com/mongodb/mongo/blob/r3.6.4/src/mongo/client/connpool.cpp#L662-L663, and from the comments, that part of the code is responsible for deleting failed connections.

Are you using a monitoring service of some kind? Also, could you check that the application is calling close() properly on the connections?

Official drivers also operate connection pooling. It is also possible that the maximum number of connection in the pool is set too high. Please see How does connection pooling work in PyMongo for an example.

Best regards
Kevin

​

[Pavel Dimow]

Hi Kevin,

tnx for your help. I am running simple replica set with 3 members (of which one is arbiter). The message

2018-03-17T11:05:11.534+0000 I NETWORK  [thread7] scoped connection to mongodb2:27017 not being returned to the pool

2018-03-17T11:05:11.535+0000 I NETWORK  [thread7] Starting new replica set monitor for my-replica-set/172.16.3.52:27017,mongodb2:27017

2018-03-17T11:05:11.537+0000 I NETWORK  [thread7] Successfully connected to mongodb2:27017 (1872 connections now open to mongodb2:27017 with a 0 second timeout)

is from secondary server (in my case mongodb1) and mongodb2 is a primary, while mongodb3 is a arbiter. I don't have many traffic at all I have periods of long silence for couple of hours but I still have this message appears at regular intervals on secondary server. I also don't have any monitoring, so I suspect that this could be a bug in mongodb itself?

[Kevin Adistambha]

Hi Pavel

2018-03-17T11:05:11.537+0000 I NETWORK [thread7] Successfully connected to mongodb2:27017 (1872 connections now open to mongodb2:27017 with a 0 second timeout)

Yes the messages are from an internal replica set monitoring thread. I assume you are alarmed by the message 1872 connections now open. However, this is not a reflection of the number of client connections to the server.

The output of db.serverStatus().connections shows the actual number of currently open client connections to the server. Please see the connections section in serverStatus page for more information. The output of db.serverStatus() is the canonical source of information regarding the state of the server.

Having said that, a similar concern regarding this message was reported in SERVER-34120. Please watch/upvote the ticket if you’re interested in this.

Best regards
Kevin

​

[Pavel Dimow]

Thank you very much for your help Kevin!

[Madhu N]

I think we have not found the any fix for this yet.

I having the same issue.

[Kevin Adistambha]

Hi Madhu

I think we have not found the any fix for this yet.
I having the same issue.

Please note that as mentioned in SERVER-34120, this is just a bookkeeping issue. There is no resource leak, so you can safely ignore the scoped connection not being returned to the pool messages.

The ticket is currently in code review, meaning that this bookkeeping mistake will be fixed shortly.

Best regards,
Kevin

​