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

darren__chan發表於2019-04-26

生產環境是 一主一從一仲裁 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()

從以上可以看出 :

 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()


查詢副本節點上的最後條操作記錄:

 

發現此時資料可以同步到副本集上,即說明 oplog 日誌不存在不同步的問題,也就是實際上叢集的同步是正常的。

當時發現,每條 oplog 記錄的 ts 一直保持著調整主機時間前的時間, 5 3 日的時間,且一直不變。關於原因,就需要進一步分析了。


來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/29863023/viewspace-2642676/,如需轉載,請註明出處,否則將追究法律責任。

相關文章