MongoDB副本集 - 次要重复下降

问题描述 投票:1回答:1

我正在尝试在我的Kubernetes集群上设置MongoDB副本集,但辅助成员在几秒钟后仍会重新启动。

这里有几件事情,但可能有用的知道:

  • Mongo服务器(和客户端)版本是4.0.6
  • 我正在使用官方头盔mongodb-replicaset图表来设置副本集,我正在使用的唯一自定义设置是enableMajorityReadConcern: false
  • Oplog大小配置为~1228MB(仅使用4.7)
  • 它发生在Primary-Secondary arch和PSA架构中,其中Arbiter像Secondary辅助成员一样重复死亡,而Primary始终启动并运行
  • 这在我的minikube和GCP上的暂存群集上都会发生,并且有大量的免费资源(我在没有资源限制的情况下部署它,请参阅下面的群集状态)

暂存群集状态(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")
    }
}
mongodb kubernetes kubernetes-helm replicaset
1个回答
2
投票

这个问题是一个太短的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,但在这方面缺乏信息。

© www.soinside.com 2019 - 2024. All rights reserved.