我正在尝试在我的Kubernetes集群上设置MongoDB副本集,但辅助成员在几秒钟后仍会重新启动。
这里有几件事情,但可能有用的知道:
4.0.6
enableMajorityReadConcern: false
暂存群集状态(4个节点):
NAME CPU(cores) CPU% MEMORY(bytes) MEMORY%
gke-staging-pool-1-********-**** 551m 28% 3423Mi 60%
gke-staging-pool-1-********-**** 613m 31% 3752Mi 66%
gke-staging-pool-1-********-**** 960m 49% 2781Mi 49%
gke-staging-pool-1-********-**** 602m 31% 3590Mi 63%
由于主要似乎能够保持运行,我设法通过将votes
移除给所有成员而不是主要成员来保持集群的生存。这样Mongo不会放弃主要因为无法看到大部分集合而我的应用仍然可以写入。
如果我把logLevel
转到5
,我唯一得到的错误是:
2019-04-02T15:11:42.233+0000 D EXECUTOR [replication-0] Executing a task on behalf of pool replication
2019-04-02T15:11:42.233+0000 D EXECUTOR [replication-0] Not reaping because the earliest retirement date is 2019-04-02T15:12:11.980+0000
2019-04-02T15:11:42.233+0000 D NETWORK [RS] Timer received error: CallbackCanceled: Callback was canceled
2019-04-02T15:11:42.235+0000 D NETWORK [RS] Decompressing message with snappy
2019-04-02T15:11:42.235+0000 D ASIO [RS] Request 114334 finished with response: { cursor: { nextBatch: [], id: 46974224885, ns: "local.oplog.rs" }, ok: 1.0, operationTime: Timestamp(1554217899, 1), $replData: { term: 11536, lastOpCommitted: { ts: Timestamp(1554217899, 1), t: 11536 }, lastOpVisible: { ts: Timestamp(1554217899, 1), t: 11536 }, configVersion: 666752, replicaSetId: ObjectId('5c8a607380091703c787b3ff'), primaryIndex: 0, syncSourceIndex: -1 }, $oplogQueryData: { lastOpCommitted: { ts: Timestamp(1554217899, 1), t: 11536 }, lastOpApplied: { ts: Timestamp(1554217899, 1), t: 11536 }, rbid: 1, primaryIndex: 0, syncSourceIndex: -1 }, $clusterTime: { clusterTime: Timestamp(1554217899, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } } }
2019-04-02T15:11:42.235+0000 D EXECUTOR [RS] Received remote response: RemoteResponse -- cmd:{ cursor: { nextBatch: [], id: 46974224885, ns: "local.oplog.rs" }, ok: 1.0, operationTime: Timestamp(1554217899, 1), $replData: { term: 11536, lastOpCommitted: { ts: Timestamp(1554217899, 1), t: 11536 }, lastOpVisible: { ts: Timestamp(1554217899, 1), t: 11536 }, configVersion: 666752, replicaSetId: ObjectId('5c8a607380091703c787b3ff'), primaryIndex: 0, syncSourceIndex: -1 }, $oplogQueryData: { lastOpCommitted: { ts: Timestamp(1554217899, 1), t: 11536 }, lastOpApplied: { ts: Timestamp(1554217899, 1), t: 11536 }, rbid: 1, primaryIndex: 0, syncSourceIndex: -1 }, $clusterTime: { clusterTime: Timestamp(1554217899, 1), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } } }
2019-04-02T15:11:42.235+0000 D EXECUTOR [replication-5] Executing a task on behalf of pool replication
2019-04-02T15:11:42.235+0000 D REPL [replication-5] oplog fetcher read 0 operations from remote oplog
2019-04-02T15:11:42.235+0000 D EXECUTOR [replication-5] Scheduling remote command request: RemoteCommand 114336 -- target:foodchain-backend-mongodb-replicaset-0.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017 db:local expDate:2019-04-02T15:11:47.285+0000 cmd:{ getMore: 46974224885, collection: "oplog.rs", batchSize: 13981010, maxTimeMS: 50, term: 11536, lastKnownCommittedOpTime: { ts: Timestamp(1554217899, 1), t: 11536 } }
2019-04-02T15:11:42.235+0000 D ASIO [replication-5] startCommand: RemoteCommand 114336 -- target:foodchain-backend-mongodb-replicaset-0.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017 db:local expDate:2019-04-02T15:11:47.285+0000 cmd:{ getMore: 46974224885, collection: "oplog.rs", batchSize: 13981010, maxTimeMS: 50, term: 11536, lastKnownCommittedOpTime: { ts: Timestamp(1554217899, 1), t: 11536 } }
2019-04-02T15:11:42.235+0000 D EXECUTOR [replication-5] Not reaping because the earliest retirement date is 2019-04-02T15:12:11.980+0000
2019-04-02T15:11:42.235+0000 D NETWORK [RS] Timer received error: CallbackCanceled: Callback was canceled
2019-04-02T15:11:42.235+0000 D NETWORK [RS] Compressing message with snappy
2019-04-02T15:11:42.235+0000 D NETWORK [RS] Timer received error: CallbackCanceled: Callback was canceled
2019-04-02T15:11:42.235+0000 D NETWORK [RS] Timer received error: CallbackCanceled: Callback was canceled
2019-04-02T15:11:42.235+0000 D NETWORK [RS] Timer received error: CallbackCanceled: Callback was canceled
鉴于网络错误,我验证了所有成员是否可以相互连接并且可以(它在所有三个成员的日志中明确显示)。
附加信息:
foodchain_rs:PRIMARY> rs.status()
{
"set" : "foodchain_rs",
"date" : ISODate("2019-04-02T15:35:02.640Z"),
"myState" : 1,
"term" : NumberLong(11536),
"syncingTo" : "",
"syncSourceHost" : "",
"syncSourceId" : -1,
"heartbeatIntervalMillis" : NumberLong(2000),
"optimes" : {
"lastCommittedOpTime" : {
"ts" : Timestamp(1554219299, 1),
"t" : NumberLong(11536)
},
"readConcernMajorityOpTime" : {
"ts" : Timestamp(1554219299, 1),
"t" : NumberLong(11536)
},
"appliedOpTime" : {
"ts" : Timestamp(1554219299, 1),
"t" : NumberLong(11536)
},
"durableOpTime" : {
"ts" : Timestamp(1554219299, 1),
"t" : NumberLong(11536)
}
},
"members" : [
{
"_id" : 0,
"name" : "foodchain-backend-mongodb-replicaset-0.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017",
"health" : 1,
"state" : 1,
"stateStr" : "PRIMARY",
"uptime" : 4376,
"optime" : {
"ts" : Timestamp(1554219299, 1),
"t" : NumberLong(11536)
},
"optimeDate" : ISODate("2019-04-02T15:34:59Z"),
"syncingTo" : "",
"syncSourceHost" : "",
"syncSourceId" : -1,
"infoMessage" : "",
"electionTime" : Timestamp(1554214927, 1),
"electionDate" : ISODate("2019-04-02T14:22:07Z"),
"configVersion" : 666752,
"self" : true,
"lastHeartbeatMessage" : ""
},
{
"_id" : 1,
"name" : "foodchain-backend-mongodb-replicaset-1.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017",
"health" : 1,
"state" : 2,
"stateStr" : "SECONDARY",
"uptime" : 10,
"optime" : {
"ts" : Timestamp(1554219299, 1),
"t" : NumberLong(11536)
},
"optimeDurable" : {
"ts" : Timestamp(1554219299, 1),
"t" : NumberLong(11536)
},
"optimeDate" : ISODate("2019-04-02T15:34:59Z"),
"optimeDurableDate" : ISODate("2019-04-02T15:34:59Z"),
"lastHeartbeat" : ISODate("2019-04-02T15:35:01.747Z"),
"lastHeartbeatRecv" : ISODate("2019-04-02T15:35:01.456Z"),
"pingMs" : NumberLong(0),
"lastHeartbeatMessage" : "",
"syncingTo" : "foodchain-backend-mongodb-replicaset-0.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017",
"syncSourceHost" : "foodchain-backend-mongodb-replicaset-0.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017",
"syncSourceId" : 0,
"infoMessage" : "",
"configVersion" : 666752
}
],
"ok" : 1,
"operationTime" : Timestamp(1554219299, 1),
"$clusterTime" : {
"clusterTime" : Timestamp(1554219299, 1),
"signature" : {
"hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
"keyId" : NumberLong(0)
}
}
}
foodchain_rs:PRIMARY> rs.printReplicationInfo()
configured oplog size: 1228.8701171875MB
log length start to end: 1646798secs (457.44hrs)
oplog first event time: Thu Mar 14 2019 14:08:51 GMT+0000 (UTC)
oplog last event time: Tue Apr 02 2019 15:35:29 GMT+0000 (UTC)
now: Tue Apr 02 2019 15:35:34 GMT+0000 (UTC)
foodchain_rs:PRIMARY> db.getReplicationInfo()
{
"logSizeMB" : 1228.8701171875,
"usedMB" : 4.7,
"timeDiff" : 1646838,
"timeDiffHours" : 457.46,
"tFirst" : "Thu Mar 14 2019 14:08:51 GMT+0000 (UTC)",
"tLast" : "Tue Apr 02 2019 15:36:09 GMT+0000 (UTC)",
"now" : "Tue Apr 02 2019 15:36:11 GMT+0000 (UTC)"
}
foodchain_rs:PRIMARY> rs.conf()
{
"_id" : "foodchain_rs",
"version" : 666752,
"protocolVersion" : NumberLong(1),
"writeConcernMajorityJournalDefault" : true,
"members" : [
{
"_id" : 0,
"host" : "foodchain-backend-mongodb-replicaset-0.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 1,
"tags" : {
},
"slaveDelay" : NumberLong(0),
"votes" : 1
},
{
"_id" : 1,
"host" : "foodchain-backend-mongodb-replicaset-1.foodchain-backend-mongodb-replicaset.foodchain.svc.cluster.local:27017",
"arbiterOnly" : false,
"buildIndexes" : true,
"hidden" : false,
"priority" : 0,
"tags" : {
},
"slaveDelay" : NumberLong(0),
"votes" : 0
}
],
"settings" : {
"chainingAllowed" : true,
"heartbeatIntervalMillis" : 2000,
"heartbeatTimeoutSecs" : 10,
"electionTimeoutMillis" : 100,
"catchUpTimeoutMillis" : -1,
"catchUpTakeoverDelayMillis" : 30000,
"getLastErrorModes" : {
},
"getLastErrorDefaults" : {
"w" : 1,
"wtimeout" : 0
},
"replicaSetId" : ObjectId("5c8a607380091703c787b3ff")
}
}
这个问题是一个太短的electionTimeoutMillis设置。
较低的值会导致更快的故障转移,但会增加对主节点或网络缓慢或污染的敏感度。
在我的情况下,它被设置为100ms
,并且我的辅助节点找不到主要成员的时间不够,因此它无法同步,因此无法使用。
我认为值得注意的是,这个过程没有被杀死。 mongod
PID始终是1
,并且在top
中显示的正常运行时间与rs.status()
mongo shell中显示的正常运行时间不一致。
我正在做的是通过mongo shell监视辅助正常运行时间,如下所示:
watch -n 1.0 "kubectl -n foodchain exec -it foodchain-backend-mongodb-replicaset-0 -- mongo --eval='rs.status().members.map(m => m.uptime)'"
通过该命令,我可以看到辅助正常运行时间从未超过10秒,所以我认为它正在重新启动或被OOM杀死或者其他东西,相反我认为它试图解雇选举,但没有投票这样做,在重新启动时保持沉默。事实上,我认为它真的让我感到困惑的是,尽管将logLevel
设置为5
,但在这方面缺乏信息。