[JAVA-708] ReadPreference.nearest() does not count primary in expected way Created: 05/Dec/12  Updated: 19/Mar/13  Resolved: 25/Feb/13

Status: Closed
Project: Java Driver
Component/s: Cluster Management
Affects Version/s: 2.10.0
Fix Version/s: 2.11.0

Type: Bug Priority: Major - P3
Reporter: piotrs Assignee: Jeffrey Yemin
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Java 1.7, Mongodb 2.2


Issue Links:
Related
is related to JAVA-753 Java Driver sending reads with NEARES... Closed

 Description   

My configuration is very simple, I've two servers A[primary] and B[secondary] geographically distributed with ~120 ms ping distance. Both A and B runs application with ReadPreference.nearest().
I would expect, that reads from A server hits only A mongodb and reads from B hits only B. However it is not working this way. What I observe is that reads from application on B hits B[secondary] only. But reads from application on A hits both A[primary] and B[secondary].
It looks like nearest() does not mean: "read from nearest node, where nearest is where ping time < 15ms" but: "read from nearest SECONDARY node where ping time < 15 ms OR any if no such secondary node".

Is it expected behaviour?



 Comments   
Comment by auto [ 08/Feb/13 ]

Author:

{u'date': u'2013-01-07T16:34:34Z', u'email': u'jeff.yemin@10gen.com', u'name': u'Jeff Yemin'}

Message: JAVA-708, JAVA-753: Fixed several read preference bugs which caused queries to be sent to secondaries with unacceptable latency and members that are not available for reads (in recovering state)
Branch: master
https://github.com/mongodb/mongo-java-driver/commit/f97eb442eec7332ac34fa74b0b46983743b3a095

Comment by Jeffrey Yemin [ 17/Dec/12 ]

I found the bug. It's in com.mongodb.ReplicaSetStatus.ReplicaSet#calculateBestPingTime. Primaries are being ignored when calculating the best ping time.

Comment by piotrs [ 07/Dec/12 ]

Thank you for your anser, it's good to know it is not an expected behaviour.

Below some debug information. I change hosts name into A and B

 
rs:PRIMARY> rs.status()
{
        "set" : "rs",
        "date" : ISODate("2012-12-07T11:21:00Z"),
        "myState" : 1,
        "members" : [
                {
                        "_id" : 0,
                        "name" : "A:27017",
                        "health" : 1,
                        "state" : 1,
                        "stateStr" : "PRIMARY",
                        "uptime" : 435074,
                        "optime" : Timestamp(1354879188000, 2),
                        "optimeDate" : ISODate("2012-12-07T11:19:48Z"),
                        "self" : true
                },
                {
                        "_id" : 1,
                        "name" : "B:27017",
                        "health" : 1,
                        "state" : 2,
                        "stateStr" : "SECONDARY",
                        "uptime" : 82962,
                        "optime" : Timestamp(1354879188000, 2),
                        "optimeDate" : ISODate("2012-12-07T11:19:48Z"),
                        "lastHeartbeat" : ISODate("2012-12-07T11:21:00Z"),
                        "pingMs" : 127
                }
        ],
        "ok" : 1
}

A mongo status from A:

{replSetName: rs, members: [ { address:'A:27017', ok:true, ping:0.515565, isMaster:true, isSecondary:false, setName:rs, maxBsonObjectSize:16777216, }

,

{ address:'/B:27017', ok:true, ping:267.9882, isMaster:false, isSecondary:true, setName:rs, maxBsonObjectSize:16777216, }

],
updaterIntervalMS: 5000, updaterIntervalNoMasterMS: 10,
slaveAcceptableLatencyMS: 15, inetAddrCacheMS: 300000, latencySmoothFactor: 4.0}

and this status doesn't change over time.

A mongo status from B:

{replSetName: rs, members: [ 
{ address:'A:27017', ok:true, ping:122.56836, isMaster:true, isSecondary:false, setName:rs, maxBsonObjectSize:16777216, },
{ address:'B:27017', ok:true, ping:0.43346196, isMaster:false, isSecondary:true, setName:rs, maxBsonObjectSize:16777216, } ], 
updaterIntervalMS: 5000, updaterIntervalNoMasterMS: 10, slaveAcceptableLatencyMS: 15, inetAddrCacheMS: 300000, latencySmoothFactor: 4.0}

To remind: both applications on A and B has ReadPreference.nearest(). But I see queries from application A on mongo server on B, it's some fraction of all queries. I don't see queries from application B on A server however, which is expected.

I'd be happy to provide additional information if it might help.

If it is needed I can provide information about ReadPreference per collection and data from A and B:28017 pages.

Comment by Jeffrey Yemin [ 05/Dec/12 ]

That's definitely not the intention. Can you periodically print the ReplicaSetStatus on all your app servers, like:

System.out.println(mongo.getReplicaSetStatus());

It will tell us what the driver sees as the current state of the world.

Generated at Thu Feb 08 08:52:53 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.