-
Type:
Task
-
Resolution: Fixed
-
Priority:
Minor - P4
-
Affects Version/s: None
-
Component/s: Sharding
-
Labels:
-
Fully Compatible
-
Sharding 2022-06-27, Sharding 2022-07-11
-
5
SessionInfo::finalize() may be called by the garbage collector when the last reference to the SessionInfo C++ object within the DriverSession and ServerSession JavaScript objects has been released. This causes the transaction to be aborted despite the JavaScript test wanting to later run commitTransaction for the transaction.
A similar issue also exists for the abortTransaction test case but it doesn't lead a test failure due to the transaction having aborted anyway.
[js_test:api_params_nontransaction_sharded] s21525| 2022-04-12T09:19:17.302+00:00 I COMMAND 51803 [conn13] "Slow query","attr":{"type":"command","ns":"admin.$cmd","appName":"MongoDB Shell","command":{"flushRouterConfig":1,"lsid":{"id":{"$uuid":"7ec31f43-172a-4ca1-87aa-c59c66fa5b3b"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1649755157,"i":27}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$db":"admin"},"numYields":0,"reslen":173,"readConcern":{"level":"local","provenance":"implicitDefault"},"remote":"127.0.0.1:60048","protocol":"op_msg","durationMillis":0}
[js_test:api_params_nontransaction_sharded] s21525| 2022-04-12T09:19:17.337+00:00 D3 TXN 22895 [conn13] "Aborting transaction on all participant shards","attr":{"sessionId":{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}},"txnNumber":0,"txnRetryCounter":0,"numParticipantShards":2}
[js_test:api_params_nontransaction_sharded] d21520| 2022-04-12T09:19:17.338+00:00 D3 TXN 20508 [conn38] "Received abortTransaction","attr":{"txnNumberAndRetryCounter":{"txnNumber":0,"txnRetryCounter":0},"sessionId":{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}}}
[js_test:api_params_nontransaction_sharded] d21520| 2022-04-12T09:19:17.339+00:00 I TXN 51802 [conn38] "transaction","attr":{"parameters":{"lsid":{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}},"txnNumber":0,"txnRetryCounter":0,"autocommit":false,"readConcern":{"provenance":"implicitDefault"}},"readTimestamp":"Timestamp(0, 0)","ninserted":1,"keysInserted":1,"terminationCause":"aborted","timeActiveMicros":504,"timeInactiveMicros":45665,"numYields":0,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":6}},"Global":{"acquireCount":{"r":1,"w":3}},"Database":{"acquireCount":{"w":3}},"Collection":{"acquireCount":{"w":3}},"Mutex":{"acquireCount":{"r":6}}},"storage":{},"wasPrepared":false,"durationMillis":46}
...
[js_test:api_params_nontransaction_sharded] s21525| 2022-04-12T09:19:17.340+00:00 I TXN 51805 [conn13] "transaction","attr":{"parameters":{"lsid":{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}},"txnNumber":0,"txnRetryCounter":0,"autocommit":false},"numParticipants":2,"terminationCause":"aborted","abortCause":"abort","timeActiveMicros":26358,"timeInactiveMicros":39014,"durationMillis":65}
[js_test:api_params_nontransaction_sharded] s21525| 2022-04-12T09:19:17.340+00:00 I COMMAND 51803 [conn13] "Slow query","attr":{"type":"command","ns":"admin.$cmd","appName":"MongoDB Shell","command":{"abortTransaction":1,"lsid":{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"}},"txnNumber":0,"autocommit":false,"$db":"admin"},"numYields":0,"reslen":242,"remote":"127.0.0.1:60048","protocol":"op_msg","durationMillis":3}
[js_test:api_params_nontransaction_sharded] s21525| 2022-04-12T09:19:17.343+00:00 I COMMAND 51803 [conn13] "Slow query","attr":{"type":"command","ns":"admin.$cmd","appName":"MongoDB Shell","command":{"endSessions":[{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"}}],"$db":"admin"},"numYields":0,"reslen":163,"readConcern":{"level":"local","provenance":"implicitDefault"},"remote":"127.0.0.1:60048","protocol":"op_msg","durationMillis":0}
...
[js_test:api_params_nontransaction_sharded] d21520| 2022-04-12T09:19:17.391+00:00 D1 COMMAND 21962 [conn41] "Assertion while executing command","attr":{"command":"coordinateCommitTransaction","db":"admin","commandArgs":{"coordinateCommitTransaction":1,"participants":[{"shardId":"api_params_nontransaction_sharded-rs0"},{"shardId":"api_params_nontransaction_sharded-rs1"}],"writeConcern":{"w":"majority","wtimeout":0,"provenance":"implicitDefault"},"coordinator":true,"autocommit":false,"txnNumber":0,"lsid":{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1649755157,"i":28}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$configTime":{"$timestamp":{"t":1649755157,"i":28}},"$topologyTime":{"$timestamp":{"t":1649755145,"i":10}},"$client":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"6.0.0-alpha0-1-g327a616-patch-62553a3b7742ae52c85c6677"},"os":{"type":"Linux","name":"Red Hat Enterprise Linux release 8.0 (Ootpa)","architecture":"x86_64","version":"Kernel 4.18.0-80.1.2.el8_0.x86_64"},"mongos":{"host":"ip-10-122-84-33.ec2.internal:21525","client":"127.0.0.1:60048","version":"6.0.0-alpha0-1-g327a616-patch-62553a3b7742ae52c85c6677"}},"mayBypassWriteBlocking":false,"$db":"admin"},"error":"NoSuchTransaction: Recovering the transaction's outcome found the transaction aborted"}
[js_test:api_params_nontransaction_sharded] d21520| 2022-04-12T09:19:17.391+00:00 I COMMAND 51803 [conn41] "Slow query","attr":{"type":"command","ns":"admin.$cmd","appName":"MongoDB Shell","command":{"coordinateCommitTransaction":1,"participants":[{"shardId":"api_params_nontransaction_sharded-rs0"},{"shardId":"api_params_nontransaction_sharded-rs1"}],"writeConcern":{"w":"majority","wtimeout":0,"provenance":"implicitDefault"},"coordinator":true,"autocommit":false,"txnNumber":0,"lsid":{"id":{"$uuid":"28571f7a-ee42-4a14-946e-546a7466d793"},"uid":{"$binary":{"base64":"47DEQpj8HBSa+/TImW+5JCeuQeRkm5NMpJWZG3hSuFU=","subType":"0"}}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1649755157,"i":28}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$configTime":{"$timestamp":{"t":1649755157,"i":28}},"$topologyTime":{"$timestamp":{"t":1649755145,"i":10}},"$client":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"6.0.0-alpha0-1-g327a616-patch-62553a3b7742ae52c85c6677"},"os":{"type":"Linux","name":"Red Hat Enterprise Linux release 8.0 (Ootpa)","architecture":"x86_64","version":"Kernel 4.18.0-80.1.2.el8_0.x86_64"},"mongos":{"host":"ip-10-122-84-33.ec2.internal:21525","client":"127.0.0.1:60048","version":"6.0.0-alpha0-1-g327a616-patch-62553a3b7742ae52c85c6677"}},"mayBypassWriteBlocking":false,"$db":"admin"},"numYields":0,"ok":0,"errMsg":"Recovering the transaction's outcome found the transaction aborted","errName":"NoSuchTransaction","errCode":251,"reslen":408,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":6}},"Global":{"acquireCount":{"r":2,"w":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":5},"writeConcern":{"w":"majority","wtimeout":0,"provenance":"implicitDefault"},"storage":{},"remote":"10.122.84.33:51308","protocol":"op_msg","durationMillis":11}
...
[js_test:api_params_nontransaction_sharded] Error: command failed: {
[js_test:api_params_nontransaction_sharded] "errorLabels" : [
[js_test:api_params_nontransaction_sharded] "TransientTransactionError"
[js_test:api_params_nontransaction_sharded] ],
[js_test:api_params_nontransaction_sharded] "ok" : 0,
[js_test:api_params_nontransaction_sharded] "errmsg" : "Recovering the transaction's outcome found the transaction aborted",
[js_test:api_params_nontransaction_sharded] "code" : 251,
[js_test:api_params_nontransaction_sharded] "codeName" : "NoSuchTransaction",
I puzzled over how despite the session local variable not having anything referencing it that the SessionInfo C++ object within it is being kept alive. Neither session = null nor session._serverSession = null followed by gc() were sufficient for triggering SessionInfo::finalize() to be called. I don't have a good answer here because SpiderMonkey's JS_GC() API is meant to do mark and sweep of all objects reachable from rooted objects in the JSContext.
Steps to reproduce
python buildscripts/resmoke.py run --suite=sharding jstests/sharding/api_params_nontransaction_sharded.js
Unable to find source-code formatter for language: diff. Available languages are: actionscript, ada, applescript, bash, c, c#, c++, cpp, css, erlang, go, groovy, haskell, html, java, javascript, js, json, lua, none, nyan, objc, perl, php, python, r, rainbow, ruby, scala, sh, sql, swift, visualbasic, xml, yaml
diff --git a/jstests/sharding/libs/mongos_api_params_util.js b/jstests/sharding/libs/mongos_api_params_util.js
index ee04ffbc6da..ccd9413ccd5 100644
--- a/jstests/sharding/libs/mongos_api_params_util.js
+++ b/jstests/sharding/libs/mongos_api_params_util.js
@@ -257,6 +257,9 @@ let MongosAPIParametersUtil = (function() {
context.lsid = session.getSessionId();
context.txnNum = session.getTxnNumber_forTesting();
+
+ session._serverSession.handle = null;
+ gc();
},
command: (context) => ({
commitTransaction: 1,
@@ -1546,6 +1549,10 @@ let MongosAPIParametersUtil = (function() {
for (let i = 0; i < testInstances.length; ++i) {
const {apiParameters, commandName, runOrExplain} = testInstances[i];
+ if (commandName !== "commitTransaction") {
+ continue;
+ }
+
// Creating a new db implicitly should succeed with 'apiStrict: true'.
assert.commandWorked(st.s.getDB("db").runCommand(
{create: 'collection', apiVersion: '1', apiStrict: true}));