diff options
author | Xiangyu Yao <xiangyu.yao@mongodb.com> | 2019-03-01 15:36:56 -0500 |
---|---|---|
committer | Xiangyu Yao <xiangyu.yao@mongodb.com> | 2019-03-12 14:48:59 -0400 |
commit | a6123ee9c73bb00c9a3ef11878ccbd8b361014f3 (patch) | |
tree | dcddbb2f4eab9d9f86636a4b4373d1033264ddf4 | |
parent | c9dd94ca1a571f9d145eaa9029d8ce905a86f933 (diff) | |
download | mongo-a6123ee9c73bb00c9a3ef11878ccbd8b361014f3.tar.gz |
SERVER-39922 Fix lock stats suboperation tests for mobile
(cherry picked from commit aa45190a746db0a6cfb413d4766e57cf3f25ee30)
-rw-r--r-- | jstests/noPassthrough/lock_stats_suboperation_curop.js | 8 | ||||
-rw-r--r-- | jstests/noPassthrough/lock_stats_suboperation_logs.js | 21 |
2 files changed, 19 insertions, 10 deletions
diff --git a/jstests/noPassthrough/lock_stats_suboperation_curop.js b/jstests/noPassthrough/lock_stats_suboperation_curop.js index a44eac13e6c..5fae6ddeab1 100644 --- a/jstests/noPassthrough/lock_stats_suboperation_curop.js +++ b/jstests/noPassthrough/lock_stats_suboperation_curop.js @@ -1,4 +1,5 @@ -/* This test checks that currentOp correctly reports the lockStats for sub-operations. Before +/** + * This test checks that currentOp correctly reports the lockStats for sub-operations. Before * SERVER-26854, the currentOp entry for each sub-operation reports the aggregate lock wait time of * all preceding sub-operations. * @@ -15,7 +16,7 @@ * 6. Run 'currentOp' to check the entry for createIndex. The lock wait time should be 0 rather * than ~2. * - * @tags: [requires_fsync] + * @tags: [requires_fsync, requires_document_locking] */ (function() { 'use strict'; @@ -70,7 +71,8 @@ }); jsTestLog(tojson(res.inprog[0])); // Assert that sub-operation 'createIndex' has 0 lock wait time. Before SERVER-26854, it - // erroneously reported ~2s as it counted the lock wait time for the previous sub-operation. + // erroneously reported `blockedMillis` as it counted the lock wait time for the previous + // sub-operation. assert(!('timeAcquiringMicros' in res.inprog[0].lockStats.Global)); assert.commandWorked( diff --git a/jstests/noPassthrough/lock_stats_suboperation_logs.js b/jstests/noPassthrough/lock_stats_suboperation_logs.js index 9e69f9a6537..3d533f1363d 100644 --- a/jstests/noPassthrough/lock_stats_suboperation_logs.js +++ b/jstests/noPassthrough/lock_stats_suboperation_logs.js @@ -1,4 +1,5 @@ -/* This test checks that mongod correctly logs report the lockStats for sub-operations. Before +/** + * This test checks that mongod correctly logs report the lockStats for sub-operations. Before * SERVER-26854, the log for each sub-operation reported the aggregate lock wait time of all * preceding sub-operations. * @@ -69,11 +70,10 @@ let lines = mongodLogs.split('\n'); const lockWaitTimeRegex = /timeAcquiringMicros: { [wW]: ([0-9]+)/; let match; - let supposedLockWaitTime; + let firstOpWaitTime; + let parentOpWaitTime; let numWaitedForLocks = 0; - // Only the logs of 'parent command' (aggregation with $out) and the first - // sub-operation(createCollection) have the information about the long wait for the lock. for (let line of lines) { if ((match = lockWaitTimeRegex.exec(line)) !== null) { let lockWaitTime = match[1]; @@ -81,14 +81,21 @@ // validation stage. if (lockWaitTime < blockedMillis * 1000) continue; - if (supposedLockWaitTime === undefined) - supposedLockWaitTime = lockWaitTime; + if (firstOpWaitTime === undefined) + firstOpWaitTime = lockWaitTime; else - assert.eq(lockWaitTime, supposedLockWaitTime); // Should be the same. + parentOpWaitTime = lockWaitTime; numWaitedForLocks++; jsTestLog('Operation/Sub-operation log: '); jsTestLog(line); } } + + // Only the logs of 'parent command' (aggregation with $out) and the first + // sub-operation(createCollection) have the information about the long wait for the lock. assert.eq(numWaitedForLocks, 2); + + // Total waiting time should be greater than or equal to the waiting time of the + // first sub-operation. + assert(parentOpWaitTime >= firstOpWaitTime); })(); |