1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
|
// SERVER-21305: reported lock times are way too high.
//
// This test uses the fsync command to induce locking.
// @tags: [requires_fsync]
(function() {
'use strict';
function testBlockTime(blockTimeMillis) {
// Lock the database, and in parallel start an operation that needs the lock, so it blocks.
assert.commandWorked(db.fsyncLock());
var startStats = db.serverStatus().locks.Global;
var startTime = new Date();
var minBlockedMillis = blockTimeMillis;
let awaitSleepCmd = startParallelShell(() => {
assert.commandWorked(
db.adminCommand({sleep: 1, millis: 100, lock: "w", $comment: "Lock sleep"}));
}, conn.port);
// Wait until we see somebody waiting to acquire the lock, defend against unset stats.
assert.soon((function() {
var stats = db.serverStatus().locks.Global;
if (!stats.acquireWaitCount || !stats.acquireWaitCount.W)
return false;
if (!stats.timeAcquiringMicros || !stats.timeAcquiringMicros.W)
return false;
if (!startStats.acquireWaitCount || !startStats.acquireWaitCount.W)
return true;
return stats.acquireWaitCount.W > startStats.acquireWaitCount.W;
}));
// Sleep for minBlockedMillis, so the acquirer would have to wait at least that long.
sleep(minBlockedMillis);
db.fsyncUnlock();
awaitSleepCmd();
// The fsync command from the shell cannot have possibly been blocked longer than this.
var maxBlockedMillis = new Date() - startTime;
var endStats = db.serverStatus().locks.Global;
// The server was just started, so initial stats may be missing.
if (!startStats.acquireWaitCount || !startStats.acquireWaitCount.W) {
startStats.acquireWaitCount = {W: 0};
}
if (!startStats.timeAcquiringMicros || !startStats.timeAcquiringMicros.W) {
startStats.timeAcquiringMicros = {W: 0};
}
var acquireWaitCount = endStats.acquireWaitCount.W - startStats.acquireWaitCount.W;
var blockedMillis =
Math.floor((endStats.timeAcquiringMicros.W - startStats.timeAcquiringMicros.W) / 1000);
// Require that no other commands run (and maybe acquire locks) in parallel.
assert.eq(acquireWaitCount, 1, "other commands ran in parallel, can't check timing");
assert.gte(blockedMillis, minBlockedMillis, "reported time acquiring lock is too low");
assert.lte(blockedMillis, maxBlockedMillis, "reported time acquiring lock is too high");
return ({
blockedMillis: blockedMillis,
minBlockedMillis: minBlockedMillis,
maxBlockedMillis: maxBlockedMillis
});
}
var conn = MongoRunner.runMongod();
var db = conn.getDB('test');
printjson([1, 10, 100, 500, 1000, 1500].map(testBlockTime));
MongoRunner.stopMongod(conn);
})();
|
