[SERVER-6658] slaveOk reads are going to primary Created: 31/Jul/12  Updated: 21/Aug/12  Resolved: 21/Aug/12

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 2.2.0-rc0
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Pierre Dane Assignee: Craig Wilson
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

windows 64 with c# driver v1.5


Operating System: ALL
Participants:

 Description   

linked to : SERVER-6604

I am still seeing this issue Scott.

After upgrading our 2 secondaries to 2.2 rc0 with master still at 2.0.6, driver starts reading from master as well as secondaries. Switching the secondaries back to 2.0.6 resolves the problem. This could be specific to the c# driver, or might be resolved once the master is also upgraded (waiting for production release before upgrading master).

Please see details below. The driver is definitely being set to SlaveOk=true, and I do not see this issue when running 2.0.6.
As you can see both secondaries are synced and operational, and there are queries being routed to the primary. The secondaries have been running 2.2 for over an hour

localhost:3002 *6 6068 1|86 *0 3 19|0 0 30g 70.7g 44.8g 1388 0 0 37|0 870|1 410k 5m 14671 tagstore SEC 11:46:49
mongo86:3002 *6 6069 1|86 *0 3 19|0 0 30g 70.7g 44.8g 1388 0 0 5|1 870|1 410k 5m 14671 tagstore SEC 11:46:49
mongo87:3002 *33 5152 *845 *0 0 47|0 0 30.1g 56.1g 32.1g 3572 0 0 0|0 1528|0 259k 3m 12214 tagstore SEC 11:46:49
mongo88:3002 0 3262 123 0 65 26 0 34g 40.8g 32.8g 160 0 0 0|0 1|1 276k 3m 6639 tagstore M 11:46:49

localhost:3002 *3 6828 1|85 *0 2 41|0 0 30g 70.7g 44.8g 2705 0 0 0|0 415|0 444k 5m 14721 tagstore SEC 11:46:50
mongo86:3002 *3 6842 1|85 *0 2 41|0 0 30g 70.7g 44.8g 2705 0 0 0|0 402|0 445k 5m 14721 tagstore SEC 11:46:50
mongo87:3002 *18 2360 *327 *0 0 38|0 0 30.1g 56.1g 32.1g 1626 0 0 0|0 5|0 354k 4m 12239 tagstore SEC 11:46:50
mongo88:3002 0 3514 113 0 48 26 0 34g 40.8g 32.8g 133 0 0 0|0 2|1 293k 3m 6640 tagstore M 11:46:50

localhost:3002 *41 4981 1|569 *0 3 11|0 0 30g 70.7g 44.8g 1401 0 0 0|0 33|0 527k 6m 14723 tagstore SEC 11:46:51
mongo86:3002 *41 4972 1|569 *0 3 11|0 0 30g 70.7g 44.8g 1401 0 0 0|0 46|0 525k 6m 14723 tagstore SEC 11:46:51
mongo87:3002 *0 2060 *0 *0 0 19|0 0 30.1g 56.1g 32.1g 211 0 0 0|0 2|0 160k 1m 12252 tagstore SEC 11:46:51
mongo88:3002 0 1886 605 0 33 18 0 34g 40.8g 32.8g 122 15.3 0 0|0 0|1 247k 2m 6639 tagstore M 11:46:51

localhost:3002 *7 1987 *116 *0 1 9|0 0 30g 70.2g 44.8g 100 0 0 0|0 0|0 161k 1m 14239 tagstore SEC 11:46:52
mongo86:3002 *7 1986 *116 *0 1 9|0 0 30g 70.2g 44.8g 100 0 0 0|0 0|0 162k 1m 14239 tagstore SEC 11:46:52
mongo87:3002 *19 2458 *350 *0 0 11|0 0 30.1g 55.7g 32.1g 233 0 0 0|0 59|0 180k 2m 11891 tagstore SEC 11:46:52
mongo88:3002 0 7713 79 0 57 13 0 34g 40.8g 32.8g 129 0 0 0|0 2|1 610k 7m 6639 tagstore M 11:46:52

localhost:3002 *5 1898 *79 *0 2 8|0 0 30g 70.2g 44.8g 29 0 0 0|0 0|0 146k 1m 14232 tagstore SEC 11:46:53
mongo86:3002 *5 1897 *79 *0 2 8|0 0 30g 70.2g 44.8g 29 0 0 0|0 0|0 146k 1m 14232 tagstore SEC 11:46:53
mongo87:3002 *0 2563 *0 *0 0 7|0 0 30.1g 55.7g 32.1g 53 0 0 0|0 9|0 202k 2m 11859 tagstore SEC 11:46:53
mongo88:3002 0 7030 80 0 79 7 0 34g 40.8g 32.8g 174 0 0 0|0 2|1 559k 7m 6639 tagstore M 11:46:53

from mongo86
SECONDARY> rs.status()
{
"set" : "tagstore",
"date" : ISODate("2012-07-31T11:48:08Z"),
"myState" : 2,
"syncingTo" : "mongo88:3002",
"members" : [
{
"_id" : 0,
"name" : "mongo86:3002",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 6900,
"optime" :

{ "t" : 1343735324000, "i" : 45 }

,
"optimeDate" : ISODate("2012-07-31T11:48:44Z"),
"self" : true
},
{
"_id" : 1,
"name" : "mongo87:3002",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 6714,
"optime" :

{ "t" : 1343735322000, "i" : 61 }

,
"optimeDate" : ISODate("2012-07-31T11:48:42Z"),
"lastHeartbeat" : ISODate("2012-07-31T11:48:07Z"),
"pingMs" : 0
},

{ "_id" : 2, "name" : "ship71:3002", "health" : 1, "state" : 7, "stateStr" : "ARBITER", "uptime" : 6897, "lastHeartbeat" : ISODate("2012-07-31T11:48:08Z"), "pingMs" : 0 }

,
{
"_id" : 3,
"name" : "mongo88:3002",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 6897,
"optime" :

{ "t" : 1343735324000, "i" : 79 }

,
"optimeDate" : ISODate("2012-07-31T11:48:44Z"),
"lastHeartbeat" : ISODate("2012-07-31T11:48:07Z"),
"pingMs" : 0
}
],
"ok" : 1
}

PRIMARY> db.printSlaveReplicationInfo()
source: mongo86:3002
syncedTo: Tue Jul 31 2012 11:50:03 GMT+0000 (Coordinated Universal Time)
= 1 secs ago (0hrs)
source: mongo87:3002
syncedTo: Tue Jul 31 2012 11:50:01 GMT+0000 (Coordinated Universal Time)
= 3 secs ago (0hrs)
source: ship71:3002
syncedTo: Thu Jan 01 1970 00:00:00 GMT+0000 (Coordinated Universal Time)
= 1343735404 secs ago (373259.83hrs)



 Comments   
Comment by Ian Whalen (Inactive) [ 21/Aug/12 ]

@pierre, please reopen if you continue to see the same problem.

Comment by Ian Whalen (Inactive) [ 17/Aug/12 ]

@pierre, assuming you're still seeing the above problem, are you able to run db.isMaster() and post the output?

Comment by Craig Wilson [ 31/Jul/12 ]

@Pierre could you run db.isMaster() on each of the members and post that here. The C# driver, does not read from the primary when slaveOk is true unless there are no secondaries available. The driver runs db.IsMaster() to determine the state of each of the members every 10 seconds.

Comment by Pierre Dane [ 31/Jul/12 ]

As an aside I am seeing way more queries returning after 100ms that I do with 2.0.6

Generated at Thu Feb 08 03:12:20 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.