MONGO 叢集修改linux主機時間後的影響

生產環境是一主一從一仲裁 3 分片的叢集，現在發現其中一個節點比當前時間大了好幾天，後使用 NTP 將時間往回撥整副本集上。

原來時間是 5 月 3 日，當前是 4 月 26 日，對此進行了調整。

[root@cwdtest1 bin]# date

Fri May 3 13:20:31 CST 2019

[root@cwdtest1 bin]# ntpdate -u 10.205.34.171

26 Apr 12:39:23 ntpdate[14568]: step time server 10.205.34.171 offset -607507.747595 sec

[root@cwdtest1 bin]# hwclock --systohc

調整後當前的時間：

[root@cwdtest1 bin]# date

Fri Apr 26 12:39:31 CST 2019

當完成調整時間之後，發現兩個問題：

1. 副本集無法同步新的 oplog ，由此出現了延遲

shard2:PRIMARY> db.printSlaveReplicationInfo();

source: 10.3.252.231:27002

syncedTo: Fri May 03 2019 13:24:23 GMT+0800 (CST)

8 secs (0 hrs) behind the primary

2. 檢視 oplog 的 tLast 時間比當前的大

shard2:PRIMARY> db.getReplicationInfo()

{

"logSizeMB" : 1383.3396482467651,

"usedMB" : 154.49,

"timeDiff" : 17015711,

"timeDiffHours" : 4726.59,

"tFirst" : "Thu Oct 18 2018 14:49:20 GMT+0800 (CST)",

"tLast" : "Fri May 03 2019 13:24:31 GMT+0800 (CST)",

"now" : "Fri Apr 26 2019 13:57:01 GMT+0800 (CST)"

}

shard2:PRIMARY> db.printReplicationInfo()

configured oplog size: 1383.3396482467651MB

log length start to end: 17015711secs (4726.59hrs)

oplog first event time: Thu Oct 18 2018 14:49:20 GMT+0800 (CST)

oplog last event time: Fri May 03 2019 13:24:31 GMT+0800 (CST)

now: Fri Apr 26 2019 15:46:27 GMT+0800 (CST)

檢視 db.getReplicationInfo 中，我們找出 tLast 和 now 兩個時間是從哪裡得到的？

shard2:PRIMARY> db.getReplicationInfo
function () {
        var localdb = this.getSiblingDB("local");
 
        var result = {};
        var oplog;
        var localCollections = localdb.getCollectionNames();
        if (localCollections.indexOf('oplog.rs') >= 0) {
            oplog = 'oplog.rs';
        } else if (localCollections.indexOf('oplog.$main') >= 0) {
            oplog = 'oplog.$main';
        } else {
            result.errmsg = "neither master/slave nor replica set replication detected";
            return result;
        }
 
        var ol = localdb.getCollection(oplog);
        var ol_stats = ol.stats();
        if (ol_stats && ol_stats.maxSize) {
            result.logSizeMB = ol_stats.maxSize / (1024 * 1024);
        } else {
            result.errmsg = "Could not get stats for local." + oplog + " collection. " +
                "collstats returned: " + tojson(ol_stats);
            return result;
        }
 
        result.usedMB = ol_stats.size / (1024 * 1024);
        result.usedMB = Math.ceil(result.usedMB * 100) / 100;
 
        var firstc = ol.find().sort({$natural: 1}).limit(1);
        var lastc = ol.find().sort({$natural: -1}).limit(1);
        if (!firstc.hasNext() || !lastc.hasNext()) {
            result.errmsg =
                "objects not found in local.oplog.$main -- is this a new and empty db instance?";
            result.oplogMainRowCount = ol.count();
            return result;
        }
 
        var first = firstc.next();
        var last = lastc.next();
        var tfirst = first.ts;
        var tlast = last.ts;
 
        if (tfirst && tlast) {
            tfirst = DB.tsToSeconds(tfirst);
            tlast = DB.tsToSeconds(tlast);
            result.timeDiff = tlast - tfirst;
            result.timeDiffHours = Math.round(result.timeDiff / 36) / 100;
            result.tFirst = (new Date(tfirst * 1000)).toString();
            result.tLast = (new Date(tlast * 1000)).toString();
            result.now = Date();
        } else {
            result.errmsg = "ts element not found in oplog objects";
        }
 
        return result;
    }

從以上可以看出 :

var ol = localdb.getCollection(oplog);

var lastc = ol.find().sort({$natural: -1}).limit(1);

var last = lastc.next();

var tlast = last.ts;

result.tLast = (new Date(tlast * 1000)).toString();

result.now = Date();

tLast 的時間是獲取 oplog.rs 集合中最後一條資料的 ts 時間。

Now 的時間是呼叫 Date() 函式獲取當前時間。

於是，此時我懷疑副本集無法同步，是因為 oplog 中存放比當前時間大的日誌，而當調整時間後新生成的 oplog 日誌記錄並不是最新的，因此副本集在對比時發現最新的日誌一直不變，便無法同步。

大概說下 mongodb 同步的機制（借鑑網路）：

1. 執行寫語句時，在 primary 上完成寫操作

2. 在 primary 上記錄一條 oplog 日誌，日誌中包含一個 ts 欄位，值為寫操作執行的時間，比如本例中記為 t

3. secondary 從 primary 拉取 oplog ，獲取到剛才那一次寫操作的日誌

4. secondary 按獲取到的日誌執行相應的寫操作

5. 執行完成後， secondary 再獲取新的日誌，其向 primary 上拉取 oplog 的條件為 {ts:{$gt:t}}

6. primary 此時收到 secondary 的請求，瞭解到 secondary 在請求時間大於 t 的寫操作日誌，所以他知道操作在 t 之前的日誌都已經成功執行了

於是，我在 primary 執行一次插入測試，來驗證懷疑。

shard2:PRIMARY> use shtest

switched to db shtest

shard2:PRIMARY> db.coll.insert( {x:3339876})

WriteResult({ "nInserted" : 1 })

查詢主節點最後一條操作記錄：

rs.debug.getLastOpWritten()