生产环境是
一主一从一仲裁
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
日的时间，且一直不变。关于原因，就需要进一步分析了。
