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
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
|
// Test read after opTime functionality with maxTimeMS.
(function() {
"use strict";
var replTest = new ReplSetTest({ nodes: 2 });
replTest.startSet();
replTest.initiate();
var config = replTest.getReplSetConfigFromNode();
var runTest = function(testDB, primaryConn) {
primaryConn.getDB('test').user.insert({ x: 1 }, { writeConcern: { w: 2 }});
var localDB = primaryConn.getDB('local');
var oplogTS = localDB.oplog.rs.find().sort({ $natural: -1 }).limit(1).next();
var twoSecTS = new Timestamp(oplogTS.ts.getTime() + 2, 0);
var term = -1;
if (config.protocolVersion === 1) {
term = oplogTS.t;
}
// Test timeout with maxTimeMS
var runTimeoutTest = function() {
var timeoutResult = assert.commandFailedWithCode(
testDB.runCommand({
find: 'user',
filter: { x: 1 },
readConcern: {
afterOpTime: { ts: twoSecTS, t: term }
},
maxTimeMS: 5000,
}),
ErrorCodes.ExceededTimeLimit
);
assert.gt(timeoutResult.waitedMS, 500);
};
var countLogMessages = function(msg) {
var total = 0;
var logMessages = assert.commandWorked(testDB.adminCommand({getLog: 'global'})).log;
for (var i = 0; i < logMessages.length; i++) {
if (logMessages[i].indexOf(msg) != -1) {
total++;
}
}
return total;
};
var checkLog = function(msg, expectedCount) {
var count;
assert.soon(function() {
count = countLogMessages(msg);
return expectedCount == count;
},
'Expected ' + expectedCount + ', but instead saw ' + count +
' log entries containing the following message: ' + msg,
60000,
300);
};
// Run the time out test 3 times with replication debug log level increased to 2
// for first and last run. The time out message should be logged twice.
testDB.setLogLevel(2, 'command');
runTimeoutTest();
testDB.setLogLevel(0, 'command');
var msg = 'Command on database ' + testDB.getName() +
' timed out waiting for read concern to be satisfied. Command:';
checkLog(msg, 1);
// Read concern timed out message should not be logged.
runTimeoutTest();
testDB.setLogLevel(2, 'command');
runTimeoutTest();
testDB.setLogLevel(0, 'command');
checkLog(msg, 2);
// Test read on future afterOpTime that will eventually occur.
var insertFunc = startParallelShell(
"sleep(2100); db.user.insert({ y: 1 }, { writeConcern: { w: 2 }});",
primaryConn.port);
var res = assert.commandWorked(testDB.runCommand({
find: 'user',
filter: { x: 1 },
readConcern: {
afterOpTime: { ts: twoSecTS, t: term },
},
maxTimeMS: 10 * 1000,
}));
assert.eq(null, res.code);
assert.gt(res.waitedMS, 0);
insertFunc();
};
var primary = replTest.getPrimary();
runTest(primary.getDB('test'), primary);
runTest(replTest.getSecondary().getDB('test'), primary);
replTest.stopSet();
})();
|
