生产环境是

一主一从一仲裁

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

日的时间，且一直不变。关于原因，就需要进一步分析了。