[JAVA-1260] Error connecting to secondary when there is no member with _id: 1 Created: 30/May/14  Updated: 10/Jun/14  Resolved: 10/Jun/14

Status: Closed
Project: Java Driver
Component/s: Connection Management
Affects Version/s: 2.12.2
Fix Version/s: None

Type: Bug Priority: Minor - P4
Reporter: bamaro Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

three member replica set with 1 arbiter



 Description   

It looks as if the driver is unable to connect to secondary if the replica set member id's dont follow a continuous order from _id: 0. Sometimes I use a read preference of 'nearest' when calling the java driver.

Through removal and addition of replica members, I found myself with the following replicaset config:

"_id" : "rs0",
"version" : 29,
"members" : [

{ "_id" : 4, "host" : "54.209.160.30:27017" }

,

{ "_id" : 5, "host" : "54.186.49.236:27017", "priority" : 3 }

,

{ "_id" : 6, "host" : "54.187.243.162:27017", "arbiterOnly" : true }

]

I noticed that in the logs of the primary, the continuous repetition of the following:

2014-05-30T00:01:09.050+0000 [initandlisten] connection accepted from 54.209.160.30:59140 #523020 (18 connections now open)
2014-05-30T00:01:09.293+0000 [conn523020] authenticate db: local

{ authenticate: 1, nonce: "xxx", user: "__system", key: "xxx" }

2014-05-30T00:01:09.453+0000 [conn523020] replset couldn't find a slave with id 1, not tracking 53692f8a311b1b09a941a1c3
2014-05-30T00:01:09.533+0000 [conn523020] end connection 54.209.160.30:59140 (17 connections now open)

The logging statement are the only symptom of the issue. I have not noticed any connectivity problem from the java application. I dont knowif the driver is actually finding the 'nearest' replica member or just choosing primary due to this issue.



 Comments   
Comment by bamaro [ 30/May/14 ]

Sorry, I dont. Sure, I just put this up as a courtesy.

Comment by Jeffrey Yemin [ 30/May/14 ]

ReadPreference.nearest() can go to the primary anyway. To test whether there is really a problem, you'd need to have used ReadPreference.secondary(). From the shell output, with ReadPreference.seconary() the driver should have sent query traffic to 54.209.160.30, assuming it was a healthy secondary. You wouldn't happen to have ismaster() from that server, would you?

Either way, I think this can be closed. Do you agree?

Comment by bamaro [ 30/May/14 ]

Hi Jeff, I have already fixed the problem by removing and adding replicasets and manually setting new _id's. However, I still have output from when I was still troubleshooting:

rs0:PRIMARY> db.isMaster()
{
"setName" : "rs0",
"setVersion" : 29,
"ismaster" : true,
"secondary" : false,
"hosts" : [
"54.186.49.236:27017",
"54.209.160.30:27017"
],
"arbiters" : [
"54.187.243.162:27017"
],
"primary" : "54.186.49.236:27017",
"me" : "54.186.49.236:27017",
"maxBsonObjectSize" : 16777216,
"maxMessageSizeBytes" : 48000000,
"maxWriteBatchSize" : 1000,
"localTime" : ISODate("2014-05-30T19:37:58.602Z"),
"maxWireVersion" : 2,
"minWireVersion" : 0,
"ok" : 1
}

rs0:PRIMARY> rs.status()
{
"set" : "rs0",
"date" : ISODate("2014-05-30T19:37:38Z"),
"myState" : 1,
"members" : [

{ "_id" : 5, "name" : "54.186.49.236:27017", "health" : 1, "state" : 1, "stateStr" : "PRIMARY", "uptime" : 2518, "optime" : Timestamp(1401476405, 1), "optimeDate" : ISODate("2014-05-30T19:00:05Z"), "electionTime" : Timestamp(1401476280, 1), "electionDate" : ISODate("2014-05-30T18:58:00Z"), "self" : true }

,

{ "_id" : 4, "name" : "54.209.160.30:27017", "health" : 1, "state" : 2, "stateStr" : "SECONDARY", "uptime" : 2302, "optime" : Timestamp(1401476405, 1), "optimeDate" : ISODate("2014-05-30T19:00:05Z"), "lastHeartbeat" : ISODate("2014-05-30T19:37:38Z"), "lastHeartbeatRecv" : ISODate("2014-05-30T19:37:37Z"), "pingMs" : 80, "syncingTo" : "54.186.49.236:27017" }

,

{ "_id" : 6, "name" : "54.187.243.162:27017", "health" : 1, "state" : 7, "stateStr" : "ARBITER", "uptime" : 2275, "lastHeartbeat" : ISODate("2014-05-30T19:37:37Z"), "lastHeartbeatRecv" : ISODate("2014-05-30T19:37:37Z"), "pingMs" : 1 }

],
"ok" : 1
}

Comment by Jeffrey Yemin [ 30/May/14 ]

Can you run the following commands in a mongo shell connected to the primary:

> db.isMaster()
> rs.status()

and report the results in a comment?

Thanks.

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