Uploaded image for project: 'Java Driver'
  1. Java Driver
  2. JAVA-3248

Why does Mongo driver not retry writes during ReplicaSet elections when retryWrites=true ?

    • Type: Icon: Task Task
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 3.8.2
    • Component/s: Write Operations
    • None
    • Environment:
      MongoDB 3 member replica set running 4.0.5 enterprise

      We have a 3 member replica set in our lab environment. We have set retryWrites=true in the connection string in our Java client. 
      The issue is when I stop the primary member (to force an election) I expect the write retries to start (once per failed write) and then the serverStatus command should give a number of the retry occurrences. We observe that some writes fail when the primary is taken down and db.serverStatus() shows retriedStatementsCount as 0

      "transactions" : {
      	"retriedCommandsCount" : NumberLong(0),
      	"retriedStatementsCount" : NumberLong(0),
      	"transactionsCollectionWriteCount" : NumberLong(0),
      	"currentActive" : NumberLong(0),
      	"currentInactive" : NumberLong(0),
      	"currentOpen" : NumberLong(0),
      	"totalAborted" : NumberLong(0),
      	"totalCommitted" : NumberLong(0),
      	"totalStarted" : NumberLong(0)
      },

      our connection string:

      mongoClient = MongoClients.create("mongodb://"+config.getServers()+"/?readPreference=primary&retryWrites=true");
      

      We see connection exceptions (as expected) when we shutdown the primary, but no evidence of retries.

      2019-03-11 14:29:31.118  INFO 19804 --- [       thread-4] org.mongodb.driver.connection            : Closed connection [connectionId{localValue:12, serverValue:7593}] to mrerh7mongodb1.phx.lab.aexp.com:27017 because there was a socket exception raised on another connection from this pool.
      14:29:31 WARN  TestResource:415 - Exception! Thread: 4 Counter: 33073 Try: 2 uuid: 37ac2f43-0953-4a20-b420-9cde5c83f5e0 Message: com.mongodb.MongoQueryException Query failed with error code 11600 and error message 'Executor error during find command :: caused by :: interrupted at shutdown' on server mrerh7mongodb1.phx.lab.aexp.com:27017
      [Ljava.lang.StackTraceElement;@44cccc6f
      2019-03-11 14:29:31.120  INFO 19804 --- [       thread-2] org.mongodb.driver.connection            : Closed connection [connectionId{localValue:11, serverValue:7592}] to mrerh7mongodb1.phx.lab.aexp.com:27017 because there was a socket exception raised on another connection from this pool.
      14:29:31 WARN  TestResource:415 - Exception! Thread: 2 Counter: 33072 Try: 2 uuid: f8f41ba1-b450-4971-960b-845d5f97c11f Message: com.mongodb.MongoQueryException Query failed with error code 11600 and error message 'Executor error during find command :: caused by :: interrupted at shutdown' on server mrerh7mongodb1.phx.lab.aexp.com:27017
      [Ljava.lang.StackTraceElement;@232f1aec
      2019-03-11 14:29:31.121  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server mrerh7mongodb1.phx.lab.aexp.com:27017
      
      com.mongodb.MongoNodeIsRecoveringException: Command failed with error 11600 (InterruptedAtShutdown): 'interrupted at shutdown' on server mrerh7mongodb1.phx.lab.aexp.com:27017. The full response is { "operationTime" : { "$timestamp" : { "t" : 1552339771, "i" : 8 } }, "ok" : 0.0, "errmsg" : "interrupted at shutdown", "code" : 11600, "codeName" : "InterruptedAtShutdown", "$clusterTime" : { "clusterTime" : { "$timestamp" : { "t" : 1552339771, "i" : 8 } }, "signature" : { "hash" : { "$binary" : "AAAAAAAAAAAAAAAAAAAAAAAAAAA=", "$type" : "00" }, "keyId" : { "$numberLong" : "0" } } } }
      	at com.mongodb.internal.connection.ProtocolHelper.createSpecialException(ProtocolHelper.java:246) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.ProtocolHelper.getCommandFailureException(ProtocolHelper.java:175) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.InternalStreamConnection.receiveCommandMessageResponse(InternalStreamConnection.java:293) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.InternalStreamConnection.sendAndReceive(InternalStreamConnection.java:255) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.CommandHelper.sendAndReceive(CommandHelper.java:83) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.CommandHelper.executeCommand(CommandHelper.java:38) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.lookupServerDescription(DefaultServerMonitor.java:180) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:124) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
      
      2019-03-11 14:29:31.123  INFO 19804 --- [       thread-3] org.mongodb.driver.connection            : Closed connection [connectionId{localValue:10, serverValue:7591}] to mrerh7mongodb1.phx.lab.aexp.com:27017 because there was a socket exception raised on another connection from this pool.
      14:29:31 WARN  TestResource:415 - Exception! Thread: 3 Counter: 33071 Try: 2 uuid: 3fbc28a7-2a19-46b4-b01c-971844813fca Message: com.mongodb.MongoQueryException Query failed with error code 11600 and error message 'Executor error during find command :: caused by :: interrupted at shutdown' on server mrerh7mongodb1.phx.lab.aexp.com:27017
      [Ljava.lang.StackTraceElement;@7e9c73ad
      2019-03-11 14:29:31.125  INFO 19804 --- [       thread-1] org.mongodb.driver.connection            : Closed connection [connectionId{localValue:8, serverValue:7590}] to mrerh7mongodb1.phx.lab.aexp.com:27017 because there was a socket exception raised on another connection from this pool.
      14:29:31 WARN  TestResource:415 - Exception! Thread: 1 Counter: 33074 Try: 1 uuid: 7328dfcd-64f2-4a49-9e35-4cc044d2412d Message: com.mongodb.MongoQueryException Query failed with error code 11600 and error message 'Executor error during find command :: caused by :: interrupted at shutdown' on server mrerh7mongodb1.phx.lab.aexp.com:27017
      [Ljava.lang.StackTraceElement;@2d1e42c1
      2019-03-11 14:29:31.170  INFO 19804 --- [       thread-4] org.mongodb.driver.cluster               : No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=mrerh7mongodb1.phx.lab.aexp.com:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=mrerh7mongodb2.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=482547, setName='rs_test', canonicalAddress=mrerh7mongodb2.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb1.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:22 MST 2019, lastUpdateTimeNanos=14102993339268631}, ServerDescription{address=mrerh7mongodb3.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=644952, setName='rs_test', canonicalAddress=mrerh7mongodb3.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb1.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:22 MST 2019, lastUpdateTimeNanos=14102993340532632}]}. Waiting for 30000 ms before timing out
      2019-03-11 14:29:31.171  INFO 19804 --- [       thread-2] org.mongodb.driver.cluster               : No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=mrerh7mongodb1.phx.lab.aexp.com:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=mrerh7mongodb2.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=482547, setName='rs_test', canonicalAddress=mrerh7mongodb2.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb1.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:22 MST 2019, lastUpdateTimeNanos=14102993339268631}, ServerDescription{address=mrerh7mongodb3.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=644952, setName='rs_test', canonicalAddress=mrerh7mongodb3.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb1.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:22 MST 2019, lastUpdateTimeNanos=14102993340532632}]}. Waiting for 30000 ms before timing out
      2019-03-11 14:29:31.172  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mrerh7mongodb2.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=758063, setName='rs_test', canonicalAddress=mrerh7mongodb2.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103002380566392}
      2019-03-11 14:29:31.174  INFO 19804 --- [       thread-3] org.mongodb.driver.cluster               : No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=mrerh7mongodb1.phx.lab.aexp.com:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=mrerh7mongodb2.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=758063, setName='rs_test', canonicalAddress=mrerh7mongodb2.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103002380566392}, ServerDescription{address=mrerh7mongodb3.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=748888, setName='rs_test', canonicalAddress=mrerh7mongodb3.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb1.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103002379978826}]}. Waiting for 30000 ms before timing out
      2019-03-11 14:29:31.178  INFO 19804 --- [       thread-1] org.mongodb.driver.cluster               : No server chosen by WritableServerSelector from cluster description ClusterDescription{type=REPLICA_SET, connectionMode=MULTIPLE, serverDescriptions=[ServerDescription{address=mrerh7mongodb1.phx.lab.aexp.com:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=mrerh7mongodb2.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=758063, setName='rs_test', canonicalAddress=mrerh7mongodb2.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103002380566392}, ServerDescription{address=mrerh7mongodb3.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=748888, setName='rs_test', canonicalAddress=mrerh7mongodb3.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb1.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103002379978826}]}. Waiting for 30000 ms before timing out
      2019-03-11 14:29:31.624  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Exception in monitor thread while connecting to server mrerh7mongodb1.phx.lab.aexp.com:27017
      
      com.mongodb.MongoSocketOpenException: Exception opening socket
      	at com.mongodb.internal.connection.SocketChannelStream.open(SocketChannelStream.java:60) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.InternalStreamConnection.open(InternalStreamConnection.java:126) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.DefaultServerMonitor$ServerMonitorRunnable.run(DefaultServerMonitor.java:131) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]
      Caused by: java.net.ConnectException: Connection refused
      	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[na:1.8.0_181]
      	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:717) ~[na:1.8.0_181]
      	at sun.nio.ch.SocketAdaptor.connect(SocketAdaptor.java:111) ~[na:1.8.0_181]
      	at com.mongodb.internal.connection.SocketStreamHelper.initialize(SocketStreamHelper.java:64) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	at com.mongodb.internal.connection.SocketChannelStream.open(SocketChannelStream.java:57) ~[mongodb-driver-core-3.8.2.jar!/:na]
      	... 3 common frames omitted
      
      2019-03-11 14:29:32.174  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mrerh7mongodb3.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=858686, setName='rs_test', canonicalAddress=mrerh7mongodb3.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103003381993627}
      2019-03-11 14:29:41.632  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:66, serverValue:11}] to mrerh7mongodb1.phx.lab.aexp.com:27017
      2019-03-11 14:29:41.635  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mrerh7mongodb1.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=2805823, setName='rs_test', canonicalAddress=mrerh7mongodb1.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='null', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103012843688730}
      2019-03-11 14:29:41.686  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mrerh7mongodb3.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=797898, setName='rs_test', canonicalAddress=mrerh7mongodb3.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb3.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000006, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103012893818457}
      2019-03-11 14:29:42.137  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mrerh7mongodb1.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=2427490, setName='rs_test', canonicalAddress=mrerh7mongodb1.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb3.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103013345289458}
      2019-03-11 14:29:42.186  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mrerh7mongodb2.phx.lab.aexp.com:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=969137, setName='rs_test', canonicalAddress=mrerh7mongodb2.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb3.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=null, setVersion=2, lastWriteDate=Mon Mar 11 14:29:31 MST 2019, lastUpdateTimeNanos=14103013393877362}
      2019-03-11 14:29:43.187  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Monitor thread successfully connected to server with description ServerDescription{address=mrerh7mongodb3.phx.lab.aexp.com:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[4, 0, 5]}, minWireVersion=0, maxWireVersion=7, maxDocumentSize=16777216, logicalSessionTimeoutMinutes=30, roundTripTimeNanos=749316, setName='rs_test', canonicalAddress=mrerh7mongodb3.phx.lab.aexp.com:27017, hosts=[mrerh7mongodb3.phx.lab.aexp.com:27017, mrerh7mongodb1.phx.lab.aexp.com:27017, mrerh7mongodb2.phx.lab.aexp.com:27017], passives=[], arbiters=[], primary='mrerh7mongodb3.phx.lab.aexp.com:27017', tagSet=TagSet{[]}, electionId=7fffffff0000000000000006, setVersion=2, lastWriteDate=Mon Mar 11 14:29:43 MST 2019, lastUpdateTimeNanos=14103014395168298}
      2019-03-11 14:29:43.187  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Setting max election id to 7fffffff0000000000000006 from replica set primary mrerh7mongodb3.phx.lab.aexp.com:27017
      2019-03-11 14:29:43.187  INFO 19804 --- [.aexp.com:27017] org.mongodb.driver.cluster               : Discovered replica set primary mrerh7mongodb3.phx.lab.aexp.com:27017
      2019-03-11 14:29:43.191  INFO 19804 --- [       thread-2] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:70, serverValue:60}] to mrerh7mongodb3.phx.lab.aexp.com:27017
      2019-03-11 14:29:43.192  INFO 19804 --- [       thread-1] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:69, serverValue:59}] to mrerh7mongodb3.phx.lab.aexp.com:27017
      2019-03-11 14:29:43.192  INFO 19804 --- [       thread-3] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:68, serverValue:58}] to mrerh7mongodb3.phx.lab.aexp.com:27017
      14:29:43 INFO  TestResource:268 -  mongo spookreq SET Request took ### 12022 ### ms , UUID: 8d1dd443-91d1-46d5-9245-07230d553578
      2019-03-11 14:29:43.193  INFO 19804 --- [       thread-4] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:71, serverValue:61}] to mrerh7mongodb3.phx.lab.aexp.com:27017
      14:29:43 INFO  TestResource:275 - Cursor has 0 elements.

      Why don't we see a >0 number of retry statements in the transactions subdocument in the db.severStatus() command? 

            Assignee:
            Unassigned Unassigned
            Reporter:
            satish.anupindi@aexp.com Satish Anupindi
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: