Loading...

XML

Word

Printable

JSON

Type: Task
Resolution: Done
Priority: Major - P3
Fix Version/s: None
Affects Version/s: 3.8.2
Component/s: Write Operations
Labels:
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

Reporter:: Satish Anupindi

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Created:: Mar 27 2019 05:27:32 PM UTC

Updated:: Sep 11 2019 07:14:41 PM UTC

Resolved:: Apr 29 2019 02:22:59 PM UTC

Details

Description

Attachments

Activity

People

Dates