[JAVA-2891] The JAVA driver does not reconnect after a rebuild and init of a replica set Created: 21/Jun/18  Updated: 27/Oct/23  Resolved: 21/Aug/18

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

Type: Task Priority: Major - P3
Reporter: Cory Chamberlain Assignee: Unassigned
Resolution: Gone away Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

RHEL 7.2



 Description   

We are using a 3 member replica set (1 member is an arbiter). If we restart the primary mongod instance our java applications reconnect correctly when a new primary is available, however if we rebuild (delete all mongodb data) and initialize the replica set none of our java applications are able to reconnect unless we restart them (not desirable).  We're creating the MongoClient with a list of ServerAddress (3 servers) and we set the serverSelectionTimeout and connectTimeout options (both set to 3 seconds).  We have the same problem with the C++ driver (3.1.1 version).



 Comments   
Comment by Jeffrey Yemin [ 21/Aug/18 ]

chambec4

As we haven't heard back from you in a while, we're closing this issue, but happy to re-open if you come back with more information.

Regards,
Jeff

Comment by Cory Chamberlain [ 27/Jun/18 ]

Hey Jeff.

So it turns out I cannot recreate it in one of our systems because we started using Percona Server for MongoDB.  The original system I was testing with is still using the FOSS version of MongoDB.  I checked again this morning and I still see the issue in the older system that is not using Percona.

Comment by Cory Chamberlain [ 27/Jun/18 ]

Hey Jeff, Interestingly I can no longer recreate the issue.  I do not know what has changed.  I'm going to continue to try and recreate, and investigate what we might have done that affected this.

 

Thanks,

Cory

Comment by Jeffrey Yemin [ 21/Jun/18 ]

Please bump up the logging level to DEBUG for the org.mongodb.driver.cluster component and attach the resulting application logs from right before you shut down the replica set until a minute or so after the new one comes up.

Also, once the new replica set is up, connect via the mongo shell to the primary, and run both rs.status()} and {{db.isMaster() and attach the results (replacing actual addresses as above).

Comment by Cory Chamberlain [ 21/Jun/18 ]

Hey Jeff,

Thanks for your response.  Here is the exception that we keep getting after the replica set has been initialized:

Error in runnable com.mongodb.MongoTimeoutException: Timed out after 3000 ms while waiting for a server that matches ReadPreferenceServerSelector{readPreference=primary}. Client view of cluster state is {type=REPLICA_SET, servers=[

{address=host-arb, type=REPLICA_SET_ARBITER, roundTripTime=0.5 ms, state=CONNECTED}

, {address=host1, type=UNKNOWN, state=CONNECTING}, {address=host2, type=REPLICA_SET_SECONDARY, roundTripTime=0.4 ms, state=CONNECTED}]
at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:377) ~[?:?]
at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:104) ~[?:?]
at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:75) ~[?:?]
at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:74) ~[?:?]
at com.mongodb.binding.ClusterBinding.getReadConnectionSource(ClusterBinding.java:63) ~[?:?]
at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:402) ~[?:?]
at com.mongodb.operation.FindOperation.execute(FindOperation.java:510) ~[?:?]
at com.mongodb.operation.FindOperation.execute(FindOperation.java:1) ~[?:?]
at com.mongodb.Mongo.execute(Mongo.java:836) ~[?:?]
at com.mongodb.Mongo$2.execute(Mongo.java:823) ~[?:?]

The concern I see with this exception is {address=host1, type=UNKNOWN, state=CONNECTING}, because host1 is currently the Primary.  For security reasons I replaced the actual addresses with host1, host2, and, host-arb.  I did wait a long time (over 10 minutes), and I'm still not connected and seeing the above exception.  As another data point, I restarted the primary mongod application (host1) which caused host2 to take Primary, and the java application in question reconnected (Exceptions stopped).

 

Thanks,

Cory Chamberlain

 

 

Comment by Jeffrey Yemin [ 21/Jun/18 ]

Hi chambec4,

Sorry to hear you're having trouble. I tried reproducing this but was unable to, with the following program:

        MongoClient client = new MongoClient(Arrays.asList(
                new ServerAddress("localhost", 27017),
                new ServerAddress("localhost", 27018),
                new ServerAddress("localhost", 27019)),
                MongoClientOptions.builder().serverSelectionTimeout(3000).connectTimeout(3000).build());
 
        while (true) {
            try {
                System.out.println(client.getDatabase("test").getCollection("test").count());
            } catch (MongoException e) {
                e.printStackTrace();
            }
            Thread.sleep(1000);
        }

While running this, I destroyed and re-built the replica set. Eventually, the driver was able to re-connect, though as expected it throws various MongoException instances while the replica set is unavailable. For example, here's one execution (not all intermediate log messages are included, to keep this short):

0
0
0
0
com.mongodb.MongoCommandException: Command failed with error 11600: 'interrupted at shutdown' on server localhost:27017. The full response is { "operationTime" : { "$timestamp" : { "t" : 1529607397, "i" : 1 } }, "ok" : 0.0, "errmsg" : "interrupted at shutdown", "code" : 11600, "codeName" : "InterruptedAtShutdown", "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1529607397, "i" : 1 } }, "signature" : { "hash" : { "$binary" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "$type" : "00" }, "keyId" : { "$numberLong" : "0" } } } }
	at com.mongodb.connection.ProtocolHelper.getCommandFailureException(ProtocolHelper.java:164)
	at com.mongodb.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:286)
	at com.mongodb.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:247)
	at com.mongodb.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:98)
	at com.mongodb.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:441)
	at com.mongodb.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:70)
	at com.mongodb.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:192)
	at com.mongodb.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:264)
	at com.mongodb.connection.DefaultServerConnection.command(DefaultServerConnection.java:126)
	at com.mongodb.connection.DefaultServerConnection.command(DefaultServerConnection.java:118)
	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:226)
	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:217)
	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:120)
	at com.mongodb.operation.CountOperation$1.call(CountOperation.java:240)
	at com.mongodb.operation.CountOperation$1.call(CountOperation.java:236)
	at com.mongodb.operation.OperationHelper.withConnectionSource(OperationHelper.java:462)
	at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:406)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:236)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:59)
	at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:144)
	at com.mongodb.client.internal.MongoCollectionImpl.executeCount(MongoCollectionImpl.java:197)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:177)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:167)
	at JAVA2891.main(JAVA2891.java:37)
com.mongodb.MongoSocketReadException: Prematurely reached end of stream
14:56:46.482 [main] WARN  org.mongodb.driver.connection - Got socket exception on connection [connectionId{localValue:38, serverValue:16}] to localhost:27017. All connections to localhost:27017 will be closed.
	at com.mongodb.connection.SocketStream.read(SocketStream.java:87)
	at com.mongodb.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:538)
14:56:46.483 [main] INFO  org.mongodb.driver.connection - Closed connection [connectionId{localValue:38, serverValue:16}] to localhost:27017 because there was a socket exception raised by this connection.
	at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:409)
	at com.mongodb.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:281)
	at com.mongodb.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:247)
	at com.mongodb.connection.UsageTrackingInternalConnection.sendAndReceive(UsageTrackingInternalConnection.java:98)
	at com.mongodb.connection.DefaultConnectionPool$PooledConnection.sendAndReceive(DefaultConnectionPool.java:441)
	at com.mongodb.connection.CommandProtocolImpl.execute(CommandProtocolImpl.java:70)
	at com.mongodb.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:192)
	at com.mongodb.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:264)
	at com.mongodb.connection.DefaultServerConnection.command(DefaultServerConnection.java:126)
	at com.mongodb.connection.DefaultServerConnection.command(DefaultServerConnection.java:118)
	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:226)
	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:217)
	at com.mongodb.operation.CommandOperationHelper.executeWrappedCommandProtocol(CommandOperationHelper.java:120)
	at com.mongodb.operation.CountOperation$1.call(CountOperation.java:240)
	at com.mongodb.operation.CountOperation$1.call(CountOperation.java:236)
	at com.mongodb.operation.OperationHelper.withConnectionSource(OperationHelper.java:462)
	at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:406)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:236)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:59)
	at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:144)
	at com.mongodb.client.internal.MongoCollectionImpl.executeCount(MongoCollectionImpl.java:197)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:177)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:167)
	at JAVA2891.main(JAVA2891.java:37)
14:56:46.486 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Exception in monitor thread while connecting to server localhost:27017
com.mongodb.MongoSocketOpenException: Exception opening socket
	at com.mongodb.connection.SocketStream.open(SocketStream.java:62) ~[mongodb-driver-core-3.7.1.jar:na]
	at com.mongodb.connection.InternalStreamConnection.open(InternalStreamConnection.java:118) ~[mongodb-driver-core-3.7.1.jar:na]
	at com.mongodb.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:128) ~[mongodb-driver-core-3.7.1.jar:na]
	at java.base/java.lang.Thread.run(Thread.java:844) [na:na]
Caused by: java.net.ConnectException: Connection refused (Connection refused)
	at java.base/java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:na]
	at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:400) ~[na:na]
	at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:243) ~[na:na]
	at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:225) ~[na:na]
	at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:402) ~[na:na]
	at java.base/java.net.Socket.connect(Socket.java:591) ~[na:na]
	at com.mongodb.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:59) ~[mongodb-driver-core-3.7.1.jar:na]
	at com.mongodb.connection.SocketStream.open(SocketStream.java:57) ~[mongodb-driver-core-3.7.1.jar:na]
	... 3 common frames omitted
14:56:47.487 [main] INFO  org.mongodb.driver.cluster - No server chosen by ReadPreferenceServerSelector{readPreference=primary} from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}, ServerDescription{address=localhost:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=829857, setName='repl0', canonicalAddress=localhost:27018, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27017', tagSet=TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:56:37 EDT 2018, lastUpdateTimeNanos=997488699793762}, ServerDescription{address=localhost:27019, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=798600, setName='repl0', canonicalAddress=localhost:27019, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27017', tagSet=TagSet{[]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:56:37 EDT 2018, lastUpdateTimeNanos=997488699756349}]}. Waiting for 3000 ms before timing out
14:56:59.506 [main] INFO  org.mongodb.driver.cluster - No server chosen by com.mongodb.client.internal.MongoClientDelegate$1@70f59913 from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}, ServerDescription{address=localhost:27018, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}, ServerDescription{address=localhost:27019, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}]}. Waiting for 3000 ms before timing out
14:57:01.128 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:108, serverValue:4}] to localhost:27017
14:57:01.129 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=REPLICA_SET_GHOST, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=285482, setName='null', canonicalAddress=null, hosts=[], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=null, lastWriteDate=null, lastUpdateTimeNanos=997511996393684}
14:57:01.129 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Server localhost:27017 does not appear to be a member of an initiated replica set.
14:57:01.633 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Server localhost:27017 does not appear to be a member of an initiated replica set.
14:57:02.139 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Server localhost:27017 does not appear to be a member of an initiated replica set.
com.mongodb.MongoTimeoutException: Timed out after 3000 ms while waiting for a server that matches com.mongodb.client.internal.MongoClientDelegate$1@70f59913. Client view of cluster state is {type=REPLICA_SET, servers=[{address=localhost:27017, type=REPLICA_SET_GHOST, roundTripTime=0.9 ms, state=CONNECTED}, {address=localhost:27018, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}, {address=localhost:27019, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused (Connection refused)}}]
	at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:389)
	at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:108)
	at com.mongodb.client.internal.MongoClientDelegate.getConnectedClusterDescription(MongoClientDelegate.java:108)
	at com.mongodb.client.internal.MongoClientDelegate.createClientSession(MongoClientDelegate.java:77)
	at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.getClientSession(MongoClientDelegate.java:185)
	at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:141)
	at com.mongodb.client.internal.MongoCollectionImpl.executeCount(MongoCollectionImpl.java:197)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:177)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:167)
	at JAVA2891.main(JAVA2891.java:37)
not appear to be a member of an initiated replica set.
14:57:05.026 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Server localhost:27017 does not appear to be a member of an initiated replica set.
14:57:05.128 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27019] INFO  org.mongodb.driver.cluster - Server localhost:27019 does not appear to be a member of an initiated replica set.
14:57:05.531 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Server localhost:27018 does not appear to be a member of an initiated replica set.
14:57:05.531 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Server localhost:27017 does 14:57:06.036 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=682686, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997516903487320}
14:57:06.036 [main] INFO  org.mongodb.driver.cluster - No server chosen by ReadPreferenceServerSelector{readPreference=primary} from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=682686, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997516903487320}, ServerDescription{address=localhost:27018, type=REPLICA_SET_GHOST, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=521601, setName='null', canonicalAddress=null, hosts=[], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=null, lastWriteDate=null, lastUpdateTimeNanos=997516903426425}, ServerDescription{address=localhost:27019, type=REPLICA_SET_GHOST, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=438500, setName='null', canonicalAddress=null, hosts=[], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=null, lastWriteDate=null, lastUpdateTimeNanos=997516499384921}]}. Waiting for 3000 ms before timing out
14:57:06.134 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27019] INFO  org.mongodb.driver.cluster - Server localhost:27019 does not appear to be a member of an initiated replica set.
14:57:06.539 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Server localhost:27018 does not appear to be a member of an initiated replica set.
14:57:06.638 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27019] INFO  org.mongodb.driver.cluster - Server localhost:27019 does not appear to be a member of an initiated replica set.
14:57:07.042 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Server localhost:27018 does not appear to be a member of an initiated replica set.
14:57:07.142 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27019] INFO  org.mongodb.driver.cluster - Server localhost:27019 does not appear to be a member of an initiated replica set.
14:57:07.546 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27018, type=REPLICA_SET_OTHER, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=525872, setName='repl0', canonicalAddress=localhost:27018, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, electionId=null, setVersion=1, lastWriteDate=Wed Dec 31 19:00:00 EST 1969, lastUpdateTimeNanos=997518414289658}
com.mongodb.MongoTimeoutException: Timed out after 3000 ms while waiting for a server that matches ReadPreferenceServerSelector{readPreference=primary}. Client view of cluster state is {type=REPLICA_SET, servers=[{address=localhost:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, roundTripTime=0.6 ms, state=CONNECTED}, {address=localhost:27018, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, roundTripTime=0.5 ms, state=CONNECTED}, {address=localhost:27019, type=REPLICA_SET_ARBITER, roundTripTime=0.5 ms, state=CONNECTED}]
	at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:389)
	at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:108)
	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:82)
	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:78)
	at com.mongodb.binding.ClusterBinding.getReadConnectionSource(ClusterBinding.java:65)
	at com.mongodb.client.internal.ClientSessionBinding.getReadConnectionSource(ClientSessionBinding.java:76)
	at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:404)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:236)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:59)
	at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:144)
	at com.mongodb.client.internal.MongoCollectionImpl.executeCount(MongoCollectionImpl.java:197)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:177)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:167)
	at JAVA2891.main(JAVA2891.java:37)
14:57:14.053 [main] INFO  org.mongodb.driver.cluster - No server chosen by ReadPreferenceServerSelector{readPreference=primary} from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=749312, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997523932937059}, ServerDescription{address=localhost:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=734900, setName='repl0', canonicalAddress=localhost:27018, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997523932934888}, ServerDescription{address=localhost:27019, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=725138, setName='repl0', canonicalAddress=localhost:27019, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=1, lastWriteDate=Wed Dec 31 19:00:00 EST 1969, lastUpdateTimeNanos=997523932929033}]}. Waiting for 3000 ms before timing out
com.mongodb.MongoTimeoutException: Timed out after 3000 ms while waiting for a server that matches ReadPreferenceServerSelector{readPreference=primary}. Client view of cluster state is {type=REPLICA_SET, servers=[{address=localhost:27017, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, roundTripTime=0.7 ms, state=CONNECTED}, {address=localhost:27018, type=REPLICA_SET_SECONDARY, TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, roundTripTime=0.6 ms, state=CONNECTED}, {address=localhost:27019, type=REPLICA_SET_ARBITER, roundTripTime=0.6 ms, state=CONNECTED}]
	at com.mongodb.connection.BaseCluster.createTimeoutException(BaseCluster.java:389)
	at com.mongodb.connection.BaseCluster.selectServer(BaseCluster.java:108)
	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:82)
	at com.mongodb.binding.ClusterBinding$ClusterBindingConnectionSource.<init>(ClusterBinding.java:78)
	at com.mongodb.binding.ClusterBinding.getReadConnectionSource(ClusterBinding.java:65)
	at com.mongodb.client.internal.ClientSessionBinding.getReadConnectionSource(ClientSessionBinding.java:76)
	at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:404)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:236)
	at com.mongodb.operation.CountOperation.execute(CountOperation.java:59)
	at com.mongodb.client.internal.MongoClientDelegate$DelegateOperationExecutor.execute(MongoClientDelegate.java:144)
	at com.mongodb.client.internal.MongoCollectionImpl.executeCount(MongoCollectionImpl.java:197)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:177)
	at com.mongodb.client.internal.MongoCollectionImpl.count(MongoCollectionImpl.java:167)
	at JAVA2891.main(JAVA2891.java:37)
14:57:18.062 [main] INFO  org.mongodb.driver.cluster - No server chosen by ReadPreferenceServerSelector{readPreference=primary} from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=localhost:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=710910, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997527943241025}, ServerDescription{address=localhost:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=691952, setName='repl0', canonicalAddress=localhost:27018, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997527943226555}, ServerDescription{address=localhost:27019, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=670588, setName='repl0', canonicalAddress=localhost:27019, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=1, lastWriteDate=Wed Dec 31 19:00:00 EST 1969, lastUpdateTimeNanos=997527943226737}]}. Waiting for 3000 ms before timing out
14:57:18.567 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27018] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=629307, setName='repl0', canonicalAddress=localhost:27018, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27017', tagSet=TagSet{[Tag{name='dc', value='pa'}, Tag{name='ordinal', value='two'}]}, electionId=null, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997529435334256}
14:57:18.567 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=644665, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27017', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=7fffffff0000000000000001, setVersion=1, lastWriteDate=Thu Jun 21 14:57:05 EDT 2018, lastUpdateTimeNanos=997529435347487}
14:57:19.071 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=617644, setName='repl0', canonicalAddress=localhost:27017, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27017', tagSet=TagSet{[Tag{name='dc', value='ny'}, Tag{name='ordinal', value='one'}]}, electionId=7fffffff0000000000000001, setVersion=1, lastWriteDate=Thu Jun 21 14:57:18 EDT 2018, lastUpdateTimeNanos=997529939617736}
14:57:19.072 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27017] INFO  org.mongodb.driver.cluster - Discovered replica set primary localhost:27017
14:57:19.102 [main] INFO  org.mongodb.driver.connection - Opened connection [connectionId{localValue:117, serverValue:16}] to localhost:27017
14:57:19.575 [cluster-ClusterId{value='5b2bf4bb90b78e9599ae4bd1', description='null'}-localhost:27019] INFO  org.mongodb.driver.cluster - Monitor thread successfully connected to server with description ServerDescription{address=localhost:27019, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 6, 4]}, minWireVersion=0, maxWireVersion=6, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=null, roundTripTimeNanos=686766, setName='repl0', canonicalAddress=localhost:27019, hosts=[localhost:27018, localhost:27017], passives=[], arbiters=[localhost:27019], primary='localhost:27017', tagSet=TagSet{[]}, electionId=null, setVersion=1, lastWriteDate=Wed Dec 31 19:00:00 EST 1969, lastUpdateTimeNanos=997530443220358}
0
0
0
0
0
0

Let me know how your use case differs.

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