2

Problem: MongoDB writes fail with the error -

Timed out after 30000 ms while waiting for a server that matches PrimaryServerSelector. Client view of cluster state is {type=REPLICA_SET, servers=[{address=intdb01:27017, type=REPLICA_SET_SECONDARY, roundTripTime=0.7 ms, state=CONNECTED}]

This happens when the primary has switched from intdb01 to intdb02. Looks like the client driver is still looking for intdb01 to be primary node.

Our Setup

We have 3 mongoDb nodes in a replicaSet called rs0. When we connect to it using Java, we give all 3 servers in the connection string as follows: mongodb://intdb01:27017,intdb02:27017,intdb03:27017/?replicaSet=rs0

db.version --> 3.0.4

Java Driver Version: mongodb-driver-3.0.4.jar, mongodb-driver-core-3.0.4.jar

Client Connection code:

if( mongoClient == null) {
    MongoClientURI mcu = new MongoClientURI(mongoConnect);
    mongoClient = new MongoClient(mcu);
}

mongoConnect contains the connection string shown above.

Mongo Replicaset Status Info

> rs.status()
{
  "set" : "rs0",
  "date" : ISODate("2016-07-19T21:14:03.001Z"),
  "myState" : 1,
  "members" : [{
        "_id" : 0,
        "name" : "intdb01",
        "health" : 1,
        "state" : 2,
        "stateStr" : "SECONDARY",
        "uptime" : 439786,
        "optime" : Timestamp(1468521291, 5),
        "optimeDate" : ISODate("2016-07-14T18:34:51Z"),
        "lastHeartbeat" : ISODate("2016-07-19T21:14:01.877Z"),
        "lastHeartbeatRecv" : ISODate("2016-07-19T21:14:01.611Z"),
        "pingMs" : 0,
        "configVersion" : 4
    },
    {
        "_id" : 1,
        "name" : "intdb02:27017",
        "health" : 1,
        "state" : 1,
        "stateStr" : "PRIMARY",
        "uptime" : 2948844,
        "optime" : Timestamp(1468521291, 5),
        "optimeDate" : ISODate("2016-07-14T18:34:51Z"),
        "electionTime" : Timestamp(1468523057, 1),
        "electionDate" : ISODate("2016-07-14T19:04:17Z"),
        "configVersion" : 4,
        "self" : true
    },
    {
        "_id" : 2,
        "name" : "intdb03:27017",
        "health" : 1,
        "state" : 2,
        "stateStr" : "SECONDARY",
        "uptime" : 439779,
        "optime" : Timestamp(1468521291, 5),
        "optimeDate" : ISODate("2016-07-14T18:34:51Z"),
        "lastHeartbeat" : ISODate("2016-07-19T21:14:01.294Z"),
        "lastHeartbeatRecv" : ISODate("2016-07-19T21:14:01.294Z"),
        "pingMs" : 0,
        "configVersion" : 4
    }
  ],
  "ok" : 1
}

I have checked and rechecked the code/config with the documentation but cannot find what is amiss. We can simulate this by stepping down the primary. The Secondary takes over but the app writes start failing. :-(

Any pointers/tips much appreciated!

Adding Stack trace-

Caused by: com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches PrimaryServerSelector. Client view of cluster state is {type=REPLICA_SET, servers=[{address=intdb01:27017, type=REPLICA_SET_SECONDARY, roundTripTime=0.7 ms, state=CONNECTED}]
at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:370)
at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:101)
at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:75)
at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:71)
at com.mongodb.binding.ClusterBinding.getWriteConnectionSource(ClusterBinding.java:68)
at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:175)
at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:141)
at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:72)
at com.mongodb.Mongo.execute(Mongo.java:747)
at com.mongodb.Mongo$2.execute(Mongo.java:730)
at com.mongodb.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:482)
at com.mongodb.MongoCollectionImpl.update(MongoCollectionImpl.java:474)
at com.mongodb.MongoCollectionImpl.updateOne(MongoCollectionImpl.java:325)
at com.grid.core.persistence.mongodb.dao.GridEventDao.save(GridEventDao.java:69)
... 6 more
2016-07-19 17:05:01,882 [pool-2-thread-2] INFO   org.mongodb.driver.cluster - No server chosen by PrimaryServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=SINGLE, all=[ServerDescription{address=intdb01:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 0, 4]}, minWireVersion=0, maxWireVersion=3, electionId=null, maxDocumentSize=16777216, roundTripTimeNanos=724681, setName='rs0', canonicalAddress=intdb01:27017, hosts=[intdb01:27017, intdb02:27017], passives=[intdb03:27017], arbiters=[], primary='intdb02:27017', tagSet=TagSet{[]}}]}. Waiting for 30000 ms before timing out

I am trying to figure out if it is a coding error or configuration. The last info Message in the stack trace, says connectionMode is SINGLE. Have a suspicion that it is causing this issue but I cannot find any info about it in the developer documentation site.

Master Chief
  • 418
  • 1
  • 6
  • 17
  • If you are going to down-vote a question, be man enough to write your concern to help make it better. Same applies to the person voting to close. – Master Chief Jul 20 '16 at 18:54
  • Can you provide the full stack trace please. – helmy Jul 20 '16 at 20:31
  • added stack trace of write failure. – Master Chief Jul 20 '16 at 20:45
  • So when intdb02:27017 is primary, is it able to connect? e.g. are you only getting these failures during the failover? – helmy Jul 20 '16 at 20:50
  • no, it keeps failing. If I change the connection string in my program and move intdb02 to the front of the string it starts working. So it appears to recognize only the first server. – Master Chief Jul 20 '16 at 21:04

1 Answers1

0

All of the server addresses should appear in the error message. For example, try this with 3 arbitrary hostnames what won't resolve:

com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting for a server that matches PrimaryServerSelector. Client view of cluster state is {type=REPLICA_SET, servers=[{address=xxx:27117, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketException: xxx}, caused by {java.net.UnknownHostException: xxx}}, {address=xxx:27118, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketException: xxx}, caused by {java.net.UnknownHostException: xxx}}, {address=xxx:27119, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketException: xxx}, caused by {java.net.UnknownHostException: xxx}}]
    at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:370)
    at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:101)
    at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.(ClusterBinding.java:75)
    at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.(ClusterBinding.java:71)
    at com.mongodb.binding.ClusterBinding.getWriteConnectionSource(ClusterBinding.java:68)
    at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:175)
    at com.mongodb.operation.BaseWriteOperation.execute(BaseWriteOperation.java:106)
    at com.mongodb.operation.BaseWriteOperation.execute(BaseWriteOperation.java:58)
    at com.mongodb.Mongo.execute(Mongo.java:747)
    at com.mongodb.Mongo$2.execute(Mongo.java:730)
    at com.mongodb.DBCollection.executeWriteOperation(DBCollection.java:327)
    at com.mongodb.DBCollection.insert(DBCollection.java:323)
    at com.mongodb.DBCollection.insert(DBCollection.java:314)
    at com.mongodb.DBCollection.insert(DBCollection.java:284)
    at com.mongodb.DBCollection.insert(DBCollection.java:250)
    at com.mongodb.DBCollection.insert(DBCollection.java:187)
    at InsertTest2.main(InsertTest2.java:26)

Notice how all 3 server addresses appear. I would suggest that you create a simple test program like this and verify, then work backwards from there. Also verify that the hostnames resolve correctly, you might also try IP addresses.

helmy
  • 9,068
  • 3
  • 32
  • 31
  • I will try it. - create a simple test and go from there. It is not a Host/IP resolution as I can connect independently to all , just not when the secondary becomes the primary. I suspect something in the way i have my connection string. I will play around and update if I make any headway. Last option is to download the source if I can find it for org.mongodb.driver.cluster. – Master Chief Jul 20 '16 at 21:58