[CSHARP-1227] Connection to replicaset, RequestHeartbeat error Created: 01/Apr/15  Updated: 02/Apr/16  Resolved: 02/Apr/15

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

Type: Bug Priority: Major - P3
Reporter: Rob Koenis Assignee: Craig Wilson
Resolution: Done Votes: 0
Labels: rc
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Server, Windows 2012 R2 running our framework in IIS.
Connection to a cluster of 3 windows 2012 R2 servers running MongoDb 3.0.1
All servers running in windows Azure.


Attachments: Zip Archive serverlogs.zip    

 Description   

The driver crashes with the following error:

An unhandled exception occurred and the process was terminated.
Application ID: Helios-6408e122-16e7-4b49-b613-826625892360
Process ID: 3620
Exception: System.ObjectDisposedException
Message: Cannot access a disposed object.
Object name: 'ClusterableServer'.

StackTrace: at MongoDB.Driver.Core.Servers.ClusterableServer.ThrowIfDisposed()
at MongoDB.Driver.Core.Servers.ClusterableServer.RequestHeartbeat()
at MongoDB.Driver.Core.Clusters.MultiServerCluster.RequestHeartbeat()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.TimerQueueTimer.CallCallback()
at System.Threading.TimerQueueTimer.Fire()
at System.Threading.TimerQueue.FireNextTimers()

We are getting this error in our daily performance tests sometimes.
It happens at random times, not always at the same place.
Never with a direct call on the mongo driver (nothing from our code in the stacktrace).

We also run the same test on a single mongo instance. This never gives any problem.

When our framework starts in gets a client and database class.
It keeps using the same database class the whole time.



 Comments   
Comment by Craig Wilson [ 03/Apr/15 ]

Thanks so much, Rob, for the confirmation. Please re-open if it comes back again.

Comment by Rob Koenis [ 03/Apr/15 ]

I have not found any problems with the latest master.
Today i have upgraded our software to the 2.0.0 final, no problems so far.
Problem solved.

Thanks for the quick response.

Comment by Rob Koenis [ 02/Apr/15 ]

I did have the error last night again in our daily performance test (running the 'old' 2.0 drivers).

I'm now running tests with the latest Master.
It are very long test and the error does not always occur.
It will take some time to make any conclusions if it is fixed.
I will report back if i know more after running lots of tests.

Comment by Craig Wilson [ 01/Apr/15 ]

Rob... I didn't see anything odd in your logs or any particular reason you would be hitting this, but in the course of investigating, we found a race condition that was possible and presented the same stack trace you are seeing. This has been pushed to master. If you're able, it would be tremendous if you could pull master, build it, and see if this fixes your problem. If not, I totally understand.

Thanks,
Craig

Comment by Githook User [ 01/Apr/15 ]

Author:

{u'username': u'craiggwilson', u'name': u'Craig Wilson', u'email': u'craiggwilson@gmail.com'}

Message: CSHARP-1227: fixed race condition between server disposal and heartbeat requests.
Branch: master
https://github.com/mongodb/mongo-csharp-driver/commit/e7b2664b54006dd4b014c5848b225ae3e5b86b59

Comment by Rob Koenis [ 01/Apr/15 ]

set1:PRIMARY> rs.config()
{
"_id" : "set1",
"version" : 199311,
"members" : [
{
"_id" : 1,
"host" : "10.0.0.8:27018",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 1,
"tags" : {

},
"slaveDelay" : 0,
"votes" : 1
},
{
"_id" : 2,
"host" : "10.0.0.9:27018",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 1,
"tags" : {

},
"slaveDelay" : 0,
"votes" : 1
},
{
"_id" : 3,
"host" : "10.0.0.10:27018",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 1,
"tags" : {

},
"slaveDelay" : 0,
"votes" : 1
}
],
"settings" : {
"chainingAllowed" : true,
"heartbeatTimeoutSecs" : 60,
"getLastErrorModes" : {

},
"getLastErrorDefaults" :

{ "w" : "majority", "wtimeout" : 10000 }

}
}

Comment by Rob Koenis [ 01/Apr/15 ]

I have attached the server logs.
The error did occure at 4/1/2015 9:55:29 AM.

The connection string used (username/password are changed):
mongodb://myuser:mypassword@10.0.0.8:27018,10.0.0.9:27018,10.0.0.10:27018/?w=majority;maxIdleTime=1m

2 databases are used in the tests, querystore and streamstore. Every performance test they are recreated.

set1:PRIMARY> rs.status()
{
"set" : "set1",
"date" : ISODate("2015-04-01T13:21:38.533Z"),
"myState" : 1,
"members" : [

{ "_id" : 1, "name" : "10.0.0.8:27018", "health" : 1, "state" : 2, "stateStr" : "SECONDARY", "uptime" : 136165, "optime" : Timestamp(1427882148, 516), "optimeDate" : ISODate("2015-04-01T09:55:48Z"), "lastHeartbeat" : ISODate("2015-04-01T13:21:37.619Z"), "lastHeartbeatRecv" : ISODate("2015-04-01T13:21:37.531Z" ), "pingMs" : 1, "syncingTo" : "10.0.0.10:27018", "configVersion" : 199311 }

,

{ "_id" : 2, "name" : "10.0.0.9:27018", "health" : 1, "state" : 2, "stateStr" : "SECONDARY", "uptime" : 11060, "optime" : Timestamp(1427882148, 516), "optimeDate" : ISODate("2015-04-01T09:55:48Z"), "lastHeartbeat" : ISODate("2015-04-01T13:21:37.593Z"), "lastHeartbeatRecv" : ISODate("2015-04-01T13:21:37.638Z" ), "pingMs" : 0, "syncingTo" : "10.0.0.10:27018", "configVersion" : 199311 }

,

{ "_id" : 3, "name" : "10.0.0.10:27018", "health" : 1, "state" : 1, "stateStr" : "PRIMARY", "uptime" : 177917, "optime" : Timestamp(1427882148, 516), "optimeDate" : ISODate("2015-04-01T09:55:48Z"), "electionTime" : Timestamp(1427716586, 1), "electionDate" : ISODate("2015-03-30T11:56:26Z"), "configVersion" : 199311, "self" : true }

],
"ok" : 1
}

Comment by Rob Koenis [ 01/Apr/15 ]

Logs from the mongo servers added to issue

Comment by Craig Wilson [ 01/Apr/15 ]

Hi Rob,

First of all, thanks for using the new driver. It truly helps us put out a better product when it's tested...

Second, I need some more information.

1. Could you provide your connection string or in-code configuration?
2. Could you provide the output of rs.config() from the shell?
3. Could you provide the log files from your replica set members?

If you are uncomfortable providing any of this publicly, we can move this to a private ticket.

Thanks,
Craig

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