|
Copying a comment from siyuan.zhou from the initial investigation on the build failure ticket:
"Agree with Yves, the root cause of this issue is _initialSyncState->beginTimestamp > _initialSyncState->stopTimestamp.
[js_test:sharding_rs1] 2017-08-16T10:25:17.011+0000 d20762| 2017-08-16T10:25:17.010+0000 E REPL [replication-1] Possible rollback on sync source ip-10-186-5-61:20760. Currently at { : Timestamp 1502879111000|2 }. Started at { : Timestamp 1502879111000|3 }
|
Before the start of initial sync at , the sync source has optime at 1502879111000|3, t: 1.
[js_test:sharding_rs1] 2017-08-16T10:25:11.923+0000 d20760| 2017-08-16T10:25:11.921+0000 D REPL_HB [conn5] Processed heartbeat from and generated response, ... durableOpTime: { ts: Timestamp 1502879111000|2, t: 1 }, opTime: { ts: Timestamp 1502879111000|3, t: 1 }
|
Later on the latest optime ts: Timestamp 1502879111000|3, t: 1 became durable and committed.
[js_test:sharding_rs1] 2017-08-16T10:25:16.984+0000 d20762| 2017-08-16T10:25:16.983+0000 D REPL_HB [replexec-3] Received response to heartbeat (requestId: 24) from ip-10-186-5-61:20760, { ok: 1.0, electionTime: new Date(6454816622996619266), state: 1, v: 2, hbmsg: "", set: "sharding_rs1-rs0", term: 1, primaryId: 0, durableOpTime: { ts: Timestamp 1502879111000|3, t: 1 }, opTime: { ts: Timestamp 1502879111000|3, t: 1 }, $replData: { term: 1, lastOpCommitted: { ts: Timestamp 1502879111000|3, t: 1 }, lastOpVisible: { ts: Timestamp 0|0, t: -1 }, configVersion: 2, replicaSetId: ObjectId('59941d85a5f5304f61ec7a0f'), primaryIndex: 0, syncSourceIndex: -1 } }
|
However the last timestamp fetcher got a stale optime ts: Timestamp 1502879111000|2, t: 1.
I suspect this is an issue about the oplog visibility rules in RocksDB since we changed the code of oplog visibility recently."
|