Replication test

[Adnan Khurram]

HI Guys,

I am exploring the replication functionality in MongoDB, just wanted to clarify a scenario.

I have a java program which is inserting values in the db constantly in a three instance replica set, now if i do rs.stepDown() on the primary the java program waits for a couple of seconds for the elections and then continues inserting but if i know do the rs.stepDown() on the new primary, my program just throws and exception and exits.

For the first primary it works after the election by itself whereas in case of the second primary stepping down it throws and exception. Could someone please explain why is it doing that whereas i thought it would continue even in case of the second step down.

Kind Regards,

[Jeff Yemin]

Hi Adnan,

Please provide the stack trace of the exception so it's clear which exception the driver is throwing.

Regards,

Jeff

--
You received this message because you are subscribed to the Google Groups "mongodb-user"
group.
 
For other MongoDB technical support options, see: https://docs.mongodb.org/manual/support/
---
You received this message because you are subscribed to the Google Groups "mongodb-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email to mongodb-user...@googlegroups.com.
To post to this group, send email to mongod...@googlegroups.com.
Visit this group at https://groups.google.com/group/mongodb-user.
To view this discussion on the web visit https://groups.google.com/d/msgid/mongodb-user/c2aa38bb-eee2-4946-89e6-d34b7508fb43%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Adnan Khurram]

Hi Jeff,

Here is the log from the beginning of the program in java.

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Cluster created with settings {hosts=[akhurraml2:27017, akhurraml2:27018, akhurraml2:27019], mode=MULTIPLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Adding discovered server akhurraml2:27017 to client view of cluster

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Adding discovered server akhurraml2:27018 to client view of cluster

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Adding discovered server akhurraml2:27019 to client view of cluster

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: No server chosen by WritableServerSelector from cluster description ClusterDescription{type=UNKNOWN, connectionMode=MULTIPLE, all=[ServerDescription{address=akhurraml2:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=akhurraml2:27018, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=akhurraml2:27019, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Opened connection [connectionId{localValue:3, serverValue:7}] to akhurraml2:27019

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27019, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1192559, setName='m101', canonicalAddress=AKhurramL2:27019, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27017', tagSet=TagSet{[]}, electionId=null, setVersion=3}

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Discovered cluster type of REPLICA_SET

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Opened connection [connectionId{localValue:2, serverValue:9}] to akhurraml2:27017

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1141655, setName='m101', canonicalAddress=AKhurramL2:27017, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27017', tagSet=TagSet{[]}, electionId=572b58430000000000000001, setVersion=3}

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Setting max election id to 572b58430000000000000001 from replica set primary akhurraml2:27017

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Setting max set version to 3 from replica set primary akhurraml2:27017

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Discovered replica set primary akhurraml2:27017

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Opened connection [connectionId{localValue:4, serverValue:10}] to akhurraml2:27017

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Opened connection [connectionId{localValue:1, serverValue:9}] to akhurraml2:27018

May 05, 2016 5:03:58 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=825965, setName='m101', canonicalAddress=AKhurramL2:27018, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27017', tagSet=TagSet{[]}, electionId=null, setVersion=3}

and this is the log from when the first primary does rs.stepDown()

May 05, 2016 5:07:59 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Opened connection [connectionId{localValue:5, serverValue:17}] to akhurraml2:27017

May 05, 2016 5:07:59 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1832142, setName='m101', canonicalAddress=AKhurramL2:27017, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=3}

May 05, 2016 5:07:59 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, all=[ServerDescription{address=akhurraml2:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1832142, setName='m101', canonicalAddress=AKhurramL2:27017, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=3}, ServerDescription{address=akhurraml2:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1369341, setName='m101', canonicalAddress=AKhurramL2:27018, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27017', tagSet=TagSet{[]}, electionId=null, setVersion=3}, ServerDescription{address=akhurraml2:27019, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1086987, setName='m101', canonicalAddress=AKhurramL2:27019, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27017', tagSet=TagSet{[]}, electionId=null, setVersion=3}]}. Waiting for 30000 ms before timing out

May 05, 2016 5:08:02 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27019, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1547645, setName='m101', canonicalAddress=AKhurramL2:27019, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=3}

May 05, 2016 5:08:03 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1224290, setName='m101', canonicalAddress=AKhurramL2:27018, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=3}

May 05, 2016 5:08:09 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27018, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1126162, setName='m101', canonicalAddress=AKhurramL2:27018, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27018', tagSet=TagSet{[]}, electionId=572b6fe80000000000000002, setVersion=3}

May 05, 2016 5:08:09 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1218621, setName='m101', canonicalAddress=AKhurramL2:27017, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27018', tagSet=TagSet{[]}, electionId=null, setVersion=3}

May 05, 2016 5:08:10 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Monitor thread successfully connected to server with description ServerDescription{address=akhurraml2:27018, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 2, 0]}, minWireVersion=0, maxWireVersion=4, maxDocumentSize=16777216, roundTripTimeNanos=1055612, setName='m101', canonicalAddress=AKhurramL2:27018, hosts=[AKhurramL2:27017, AKhurramL2:27018, AKhurramL2:27019], passives=[], arbiters=[], primary='AKhurramL2:27018', tagSet=TagSet{[]}, electionId=572b6fe80000000000000002, setVersion=3}

May 05, 2016 5:08:10 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Setting max election id to 572b6fe80000000000000002 from replica set primary akhurraml2:27018

May 05, 2016 5:08:10 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Discovered replica set primary akhurraml2:27018

May 05, 2016 5:08:10 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Opened connection [connectionId{localValue:6, serverValue:10}] to akhurraml2:27018

and here is what i get if i do rs.stepDown() on the new primary now.

May 05, 2016 5:09:35 PM com.mongodb.diagnostics.logging.JULLogger log

WARNING: Got socket exception on connection [connectionId{localValue:6, serverValue:10}] to akhurraml2:27018. All connections to akhurraml2:27018 will be closed.

May 05, 2016 5:09:35 PM com.mongodb.diagnostics.logging.JULLogger log

INFO: Closed connection [connectionId{localValue:6, serverValue:10}] to akhurraml2:27018 because there was a socket exception raised by this connection.

Exception in thread "main" com.mongodb.MongoSocketReadException: Exception receiving message

at com.mongodb.connection.InternalStreamConnection.translateReadException(InternalStreamConnection.java:480)

at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:225)

at com.mongodb.connection.UsageTrackingInternalConnection.receiveMessage(UsageTrackingInternalConnection.java:102)

at com.mongodb.connection.DefaultConnectionPool$PooledConnection.receiveMessage(DefaultConnectionPool.java:435)

at com.mongodb.connection.WriteCommandProtocol.receiveMessage(WriteCommandProtocol.java:234)

at com.mongodb.connection.WriteCommandProtocol.execute(WriteCommandProtocol.java:104)

at com.mongodb.connection.InsertCommandProtocol.execute(InsertCommandProtocol.java:67)

at com.mongodb.connection.InsertCommandProtocol.execute(InsertCommandProtocol.java:37)

at com.mongodb.connection.DefaultServer$DefaultServerProtocolExecutor.execute(DefaultServer.java:159)

at com.mongodb.connection.DefaultServerConnection.executeProtocol(DefaultServerConnection.java:286)

at com.mongodb.connection.DefaultServerConnection.insertCommand(DefaultServerConnection.java:115)

at com.mongodb.operation.MixedBulkWriteOperation$Run$2.executeWriteCommandProtocol(MixedBulkWriteOperation.java:455)

at com.mongodb.operation.MixedBulkWriteOperation$Run$RunExecutor.execute(MixedBulkWriteOperation.java:646)

at com.mongodb.operation.MixedBulkWriteOperation$Run.execute(MixedBulkWriteOperation.java:401)

at com.mongodb.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:179)

at com.mongodb.operation.MixedBulkWriteOperation$1.call(MixedBulkWriteOperation.java:168)

at com.mongodb.operation.OperationHelper.withConnectionSource(OperationHelper.java:230)

at com.mongodb.operation.OperationHelper.withConnection(OperationHelper.java:221)

at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:168)

at com.mongodb.operation.MixedBulkWriteOperation.execute(MixedBulkWriteOperation.java:74)

at com.mongodb.Mongo.execute(Mongo.java:781)

at com.mongodb.Mongo$2.execute(Mongo.java:764)

at com.mongodb.MongoCollectionImpl.executeSingleWriteRequest(MongoCollectionImpl.java:515)

at com.mongodb.MongoCollectionImpl.insertOne(MongoCollectionImpl.java:306)

at com.mongodb.MongoCollectionImpl.insertOne(MongoCollectionImpl.java:297)

at com.nextcontrols.App.main(App.java:33)

Caused by: java.net.SocketException: Software caused connection abort: recv failed

at java.net.SocketInputStream.socketRead0(Native Method)

at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)

at java.net.SocketInputStream.read(SocketInputStream.java:170)

at java.net.SocketInputStream.read(SocketInputStream.java:141)

at com.mongodb.connection.SocketStream.read(SocketStream.java:85)

at com.mongodb.connection.InternalStreamConnection.receiveResponseBuffers(InternalStreamConnection.java:491)

at com.mongodb.connection.InternalStreamConnection.receiveMessage(InternalStreamConnection.java:221)

... 24 more