summaryrefslogtreecommitdiff
path: root/jstests/replsets/optime.js
blob: 7311c5e9b9d111f03e6236f1572aa7c21bc85f09 (plain)
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
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
// Tests tracking of latestOptime and earliestOptime in serverStatus.oplog
// Also tests tracking of wall clock times in replSetGetStatus

function timestampCompare(o1, o2) {
    if (o1.t < o2.t) {
        return -1;
    } else if (o1.t > o2.t) {
        return 1;
    } else {
        if (o1.i < o2.i) {
            return -1;
        } else if (o1.i > o2.i) {
            return 1;
        } else {
            return 0;
        }
    }
}

function wallTimeCompare(d1, d2) {
    if (d1 < d2) {
        return -1;
    } else if (d1 > d2) {
        return 1;
    } else {
        return 0;
    }
}

function optimesAndWallTimesAreEqual(replTest, isPersistent) {
    let prevReplStatus = replTest.nodes[0].getDB('admin').runCommand({replSetGetStatus: 1});
    let prevOptime = prevReplStatus.optimes.appliedOpTime.ts;
    let prevAppliedWallTime = prevReplStatus.optimes.lastAppliedWallTime;
    let prevDurableWallTime = prevReplStatus.optimes.lastDurableWallTime;
    for (var i = 1; i < replTest.nodes.length; i++) {
        let currentReplStatus = replTest.nodes[i].getDB('admin').runCommand({replSetGetStatus: 1});
        let currOptime = currentReplStatus.optimes.appliedOpTime.ts;
        let currAppliedWallTime = currentReplStatus.optimes.lastAppliedWallTime;
        let currDurableWallTime = currentReplStatus.optimes.lastDurableWallTime;
        if (timestampCompare(prevOptime, currOptime) != 0 ||
            wallTimeCompare(prevAppliedWallTime, currAppliedWallTime) != 0 ||
            (isPersistent && wallTimeCompare(prevDurableWallTime, currDurableWallTime) != 0)) {
            jsTest.log("optimesAndWallTimesAreEqual returning false match, prevOptime: " +
                       tojson(prevOptime) + " latestOptime: " + tojson(currOptime) +
                       " prevAppliedWallTime: " + tojson(prevAppliedWallTime) +
                       " latestWallTime: " + tojson(currAppliedWallTime) +
                       " prevDurableWallTime: " + tojson(prevDurableWallTime) +
                       " latestDurableWallTime: " + tojson(currDurableWallTime));
            replTest.dumpOplog(replTest.nodes[i], {}, 20);
            replTest.dumpOplog(replTest.nodes[i - 1], {}, 20);
            return false;
        }
        prevReplStatus = currentReplStatus;
    }
    return true;
}

// This test has a part that rolls over the oplog. Doing so requires a fresh stable
// checkpoint. Set the syncdelay to a small value to increase checkpoint frequency.
var replTest = new ReplSetTest(
    {name: "replStatus", nodes: 3, oplogSize: 1, waitForKeys: true, nodeOptions: {syncdelay: 1}});

const nodes = replTest.startSet();

// Tests that serverStatus oplog returns an error if the oplog collection doesn't exist.
assert.commandFailedWithCode(nodes[0].getDB('admin').serverStatus({oplog: true}), 17347);

replTest.initiate();
var primary = replTest.getPrimary();
replTest.awaitReplication();
replTest.awaitSecondaryNodes();

const isPersistent = primary.getDB('admin').serverStatus().storageEngine.persistent;

// Check initial optimes
assert.soon(function() {
    return optimesAndWallTimesAreEqual(replTest, isPersistent);
});
var initialInfo = primary.getDB('admin').serverStatus({oplog: true}).oplog;
let initialReplStatusInfo = primary.getDB('admin').runCommand({replSetGetStatus: 1});

// Do an insert to increment optime, but without rolling the oplog
// latestOptime should be updated, but earliestOptime should be unchanged
var options = {writeConcern: {w: replTest.nodes.length}};
if (isPersistent) {
    // Ensure the durable optime is advanced.
    options.writeConcern.j = true;
}
assert.commandWorked(primary.getDB('test').foo.insert({a: 1}, options));
assert.soon(function() {
    return optimesAndWallTimesAreEqual(replTest, isPersistent);
});

var info = primary.getDB('admin').serverStatus({oplog: true}).oplog;
var entry = primary.getDB('local').oplog.rs.findOne().ts;
jsTest.log("First entry's timestamp is " + tojson(entry));
let replStatusInfo = primary.getDB('admin').runCommand({replSetGetStatus: 1});

const dumpInfoFn = function() {
    jsTestLog("Initial server status: " + tojsononeline(initialInfo));
    jsTestLog("Initial replSetGetStatus: " + tojsononeline(initialReplStatusInfo));
    jsTestLog("Final server status: " + tojsononeline(info));
    jsTestLog("Final replSetGetStatus: " + tojsononeline(replStatusInfo));
};

assert.gt(timestampCompare(info.latestOptime, initialInfo.latestOptime), 0, dumpInfoFn);
assert.gt(wallTimeCompare(replStatusInfo.optimes.lastAppliedWallTime,
                          initialReplStatusInfo.optimes.lastAppliedWallTime),
          0,
          dumpInfoFn);
if (isPersistent) {
    assert.gt(wallTimeCompare(replStatusInfo.optimes.lastDurableWallTime,
                              initialReplStatusInfo.optimes.lastDurableWallTime),
              0,
              dumpInfoFn);
}
assert.eq(timestampCompare(info.earliestOptime, initialInfo.earliestOptime), 0, dumpInfoFn);

// Insert some large documents to force the oplog to roll over
var largeString = new Array(1024 * 10).toString();
for (var i = 0; i < 2000; i++) {
    primary.getDB('test').foo.insert({largeString: largeString}, options);
}
assert.soon(function() {
    return optimesAndWallTimesAreEqual(replTest, isPersistent);
});
entry = primary.getDB('local').oplog.rs.findOne().ts;
jsTest.log("First entry's timestamp is now " + tojson(entry) + " after oplog rollover");

// This block requires a fresh stable checkpoint.
assert.soon(function() {
    // Test that earliestOptime was updated
    info = primary.getDB('admin').serverStatus({oplog: true}).oplog;
    jsTest.log("Earliest optime is now " + tojson(info.earliestOptime) +
               "; looking for it to be different from " + tojson(initialInfo.earliestOptime));
    replStatusInfo = primary.getDB('admin').runCommand({replSetGetStatus: 1});
    return timestampCompare(info.latestOptime, initialInfo.latestOptime) > 0 &&
        wallTimeCompare(replStatusInfo.optimes.lastAppliedWallTime,
                        initialReplStatusInfo.optimes.lastAppliedWallTime) > 0 &&
        (!isPersistent ||
         wallTimeCompare(replStatusInfo.optimes.lastDurableWallTime,
                         initialReplStatusInfo.optimes.lastDurableWallTime) > 0) &&
        timestampCompare(info.earliestOptime, initialInfo.earliestOptime) > 0;
});

replTest.stopSet();