-
Type:
Task
-
Resolution: Done
-
Priority:
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
-
None
-
None
-
None
-
None
-
None
-
None
-
None
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?