[CSHARP-1855] Upgrading from Mongo Legacy 1.11.0 to 2.4.0 (or 2.3.0) connection Timeout Issues Created: 01/Dec/16  Updated: 12/Jan/18  Resolved: 12/Jan/18

Status: Closed
Project: C# Driver
Component/s: Connectivity
Affects Version/s: 2.3
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Ryan Kuhn Assignee: Robert Stam
Resolution: Cannot Reproduce Votes: 1
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Mongo Server Version 3.2.9
Mongo C# Driver Version 2.3.0 and 2.4.0


Issue Links:
Related
related to CSHARP-2147 Add logging of heartbeat information ... Closed

 Description   

After upgrading from 1.11.0 to 2.4.0 or 2.3.0 C# legacy driver, we have connection issues being reported at random. The main modified code was dealing with how to connect to mongo. We changed it from:

db = new MongoClient(url).GetServer().GetDatabase(url.DatabaseName, settings);

to this:

db = new MongoServer(serverSettings).GetDatabase(url.DatabaseName, settings);

Any advice would be appreciated.

{"Type":"System.TimeoutException","Message":"A timeout occured after 30000ms selecting a server using CompositeServerSelector{ Selectors = WritableServerSelector, LatencyLimitingServerSelector

{ AllowedLatencyRange = 00:00:00.0150000 }

}. Client view of cluster state is { ClusterId : \"2\", ConnectionMode : \"ReplicaSet\", Type : \"ReplicaSet\", State : \"Disconnected\", Servers : [{ ServerId: \"

{ ClusterId : 2, EndPoint : \"Unspecified/aga-rogue-mongo01.aga-dev.sandbox.farm:27017\" }

\", EndPoint: \"Unspecified/aga-rogue-mongo01.aga-dev.sandbox.farm:27017\", State: \"Disconnected\", Type: \"Unknown\" }, { ServerId: \"

{ ClusterId : 2, EndPoint : \"Unspecified/aga-rogue-mongo02.aga-dev.sandbox.farm:27017\" }

\", EndPoint: \"Unspecified/aga-rogue-mongo02.aga-dev.sandbox.farm:27017\", State: \"Disconnected\", Type: \"Unknown\" }] }.","Source":"MongoDB.Driver.Core","Data":{},"StackTrace":" at MongoDB.Driver.Core.Clusters.Cluster.WaitForDescriptionChangedHelper.HandleCompletedTask(Task completedTask)\r\n at MongoDB.Driver.Core.Clusters.Cluster.WaitForDescriptionChanged(IServerSelector selector, ClusterDescription description, Task descriptionChangedTask, TimeSpan timeout, CancellationToken cancellationToken)\r\n at MongoDB.Driver.Core.Clusters.Cluster.SelectServer(IServerSelector selector, CancellationToken cancellationToken)\r\n at MongoDB.Driver.Core.Bindings.WritableServerBinding.GetReadChannelSource(CancellationToken cancellationToken)\r\n at MongoDB.Driver.Core.Operations.FindOperation`1.Execute(IReadBinding binding, CancellationToken cancellationToken)



 Comments   
Comment by Robert Stam [ 12/Jan/18 ]

Linking to CSHARP-2147 as additional logging would have helped troubleshoot the potential issue.

Comment by Ryan Kuhn [ 21/Apr/17 ]

I solved my problem. There seems to be an issue with multiple database specific connection strings to the same servers. Example:

mongodb://db1User:******@server_names/db1
mongodb://db2User:******@server_names/db2
mongodb://db3User:******@server_names/db3

etc, as we have 25 different connection strings and users.

By switching to one connection string:

mongodb://masterUser:******@server_names

And getting the database by name after we have the server connection via server.GetDatabase("db1").

The problem is now solved. Please fix this behavior as I wouldn't expect it to start failing connections for having > 1 connection string.

Comment by Ryan Kuhn [ 19/Apr/17 ]

Time of Log Message:
Date=2017-04-19 20:10:51,377, Exception={"Type":"System.TimeoutException","Message":"A timeout occured after 30000ms.......

Looked at both servers in the replica set:

aga-rogue-mongo01.aga-dev.sandbox.farm:

2017-04-19T20:10:46.054+0000 I NETWORK [conn209085] end connection 10.108.97.81:65527 (87 connections now open)
2017-04-19T20:10:46.177+0000 I NETWORK [initandlisten] connection accepted from 10.108.97.81:49161 #209086 (88 connections now open)
2017-04-19T20:10:46.177+0000 I NETWORK [initandlisten] connection accepted from 10.108.97.81:49162 #209087 (89 connections now open)
2017-04-19T20:10:46.252+0000 I ACCESS [conn209087] Successfully authenticated as principal asdbUser on AssetStatusDB

aga-rogue-mongo02.aga-dev.sandbox.farm:

2017-04-19T20:10:46.057+0000 I NETWORK [conn108470] end connection 10.108.97.81:65528 (69 connections now open)
2017-04-19T20:10:46.105+0000 I NETWORK [initandlisten] connection accepted from 10.108.97.81:49158 #108471 (70 connections now open)
2017-04-19T20:10:46.105+0000 I NETWORK [initandlisten] connection accepted from 10.108.97.81:65534 #108472 (71 connections now open)
2017-04-19T20:10:46.163+0000 I ACCESS [conn108471] Successfully authenticated as principal asdbUser on AssetStatusDB

Connection String:
mongodb://asdbUser:********************@aga-rogue-mongo01.aga-dev.sandbox.farm:27017,aga-rogue-mongo02.aga-dev.sandbox.farm:27017/AssetStatusDB?replicaSet=rogue

Comment by Ryan Kuhn [ 19/Apr/17 ]

@rstam, same issue, made no difference:

Exception={"Type":"System.TimeoutException","Message":"A timeout occured after 30000ms selecting a server using CompositeServerSelector{ Selectors = WritableServerSelector, LatencyLimitingServerSelector

{ AllowedLatencyRange = 00:00:00.0150000 }

}. Client view of cluster state is { ClusterId : \"3\", ConnectionMode : \"ReplicaSet\", Type : \"ReplicaSet\", State : \"Disconnected\", Servers : [{ ServerId: \"

{ ClusterId : 3, EndPoint : \"Unspecified/aga-rogue-mongo01.aga-dev.sandbox.farm:27017\" }

\", EndPoint: \"Unspecified/aga-rogue-mongo01.aga-dev.sandbox.farm:27017\", State: \"Disconnected\", Type: \"Unknown\" }, { ServerId: \"

{ ClusterId : 3, EndPoint : \"Unspecified/aga-rogue-mongo02.aga-dev.sandbox.farm:27017\" }

\", EndPoint: \"Unspecified/aga-rogue-mongo02.aga-dev.sandbox.farm:27017\", State: \"Disconnected\", Type: \"Unknown\" }] }.","Source":"MongoDB.Driver.Core","Data":{},"StackTrace":" at MongoDB.Driver.Core.Clusters.Cluster.WaitForDescriptionChangedHelper.HandleCompletedTask(Task completedTask)\r\n at MongoDB.Driver.Core.Clusters.Cluster.WaitForDescriptionChanged(IServerSelector selector, ClusterDescription description, Task descriptionChangedTask, TimeSpan timeout, CancellationToken cancellationToken)\r\n at MongoDB.Driver.Core.Clusters.Cluster.SelectServer(IServerSelector selector, CancellationToken cancellationToken)\r\n at MongoDB.Driver.Core.Bindings.WritableServerBinding.GetReadChannelSource(CancellationToken cancellationToken)\r\n at MongoDB.Driver.Core.Operations.FindOperation`1.Execute(IReadBinding binding, CancellationToken cancellationToken)\r\n at MongoDB.Driver.MongoCollection.ExecuteReadOperation[TResult](IReadOperation`1 operation, ReadPreference readPreference)\r\n at MongoDB.Driver.MongoCollection.FindOneAs[TDocument](FindOneArgs args)\r\n

Comment by Robert Stam [ 21/Mar/17 ]

Not sure why you would be having connection timeout issues, but we recommend that you NOT use code like this:

new MongoServer(...)

When created this way the MongoServer instance can never be garbage collected, and you will eventually run out of memory (or ports). Running out of ports might explain your connection issues.

The correct way to get a MongoServer instance is:

var client = new MongoClient(...);
var server = client.GetServer();

Comment by Johan Widén [ 12/Dec/16 ]

We have the same problem as described but have not upgraded from legacy.
Mongo C# Driver Version: 2.3.0
Mongo Server Version: 3.2.10.
We create a connection with: var client = new MongoClient(connectionString);

Generated at Wed Feb 07 21:40:51 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.