当前MongoDB集群的测试环境的架构有两个分片,每个分片是三个节点的副本集,一个mongos,mongoDB v4.4.20
config server也是三个节点的副本集(configReplSet),直接停掉两个节点之后,关闭步骤的返回信息相似,如下
configReplSet:SECONDARY> use admin
switched to db admin
configReplSet:SECONDARY> db.shutdownServer()
server should be down...
> exit
bye
{"t":{"$date":"2023-05-04T07:11:49.394Z"},"s":"I", "c":"QUERY", "id":22791, "ctx":"js","msg":"Failed to end logical session","attr":{"lsid":{"id":{"$uuid":"f7de35d6-892f-4fdd-a78e-80d1d4932386"}},"error":{"code":9001,"codeName":"SocketException","errmsg":"socket exception [CONNECT_ERROR] server [couldn't connect to server 127.0.0.1:27019, connection attempt failed: SocketException: Error connecting to 127.0.0.1:27019 :: caused by :: Connection refused]"}}}
查看主节点121,可以看到变成secondary
configReplSet:PRIMARY>
configReplSet:PRIMARY>
configReplSet:PRIMARY>
configReplSet:PRIMARY>
configReplSet:PRIMARY>
configReplSet:PRIMARY>
configReplSet:PRIMARY>
configReplSet:PRIMARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:SECONDARY>
121节点日志详细信息:
{"t":{"$date":"2023-05-04T15:11:53.400+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.122:27019"}}
{"t":{"$date":"2023-05-04T15:11:53.400+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T15:11:53.531+08:00"},"s":"I", "c":"REPL", "id":21809, "ctx":"ReplCoord-2968","msg":"Can't see a majority of the set, relinquishing primary"}
{"t":{"$date":"2023-05-04T15:11:53.531+08:00"},"s":"I", "c":"REPL", "id":21475, "ctx":"ReplCoord-2968","msg":"Stepping down from primary in response to heartbeat"}
{"t":{"$date":"2023-05-04T15:11:53.532+08:00"},"s":"I", "c":"REPL", "id":21343, "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"I", "c":"REPL", "id":21344, "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"I", "c":"REPL", "id":21340, "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepDown","userOpsKilled":5,"userOpsRunning":7}}}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"I", "c":"COMMAND", "id":6015318, "ctx":"ReplCoord-2968","msg":"Yielding locks for prepared transactions."}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"I", "c":"COMMAND", "id":6015319, "ctx":"ReplCoord-2968","msg":"Invalidating sessions for stepdown."}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"W", "c":"COMMAND", "id":20525, "ctx":"conn109","msg":"Failed to gather storage statistics for slow operation","attr":{"opId":25327164,"error":"lock acquire timeout"}}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-2968","msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"PRIMARY"}}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"W", "c":"COMMAND", "id":20525, "ctx":"conn1732","msg":"Failed to gather storage statistics for slow operation","attr":{"opId":25327173,"error":"lock acquire timeout"}}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn109","msg":"Slow query","attr":{"type":"command","ns":"config.lockpings","command":{"findAndModify":"lockpings","query":{"_id":"db-test03:27020:1682238543:-7230616499206276199"},"update":{"$set":{"ping":{"$date":"2023-05-04T07:11:43.295Z"}}},"upsert":true,"writeConcern":{"w":"majority","wtimeout":15000},"maxTimeMS":30000,"$replData":1,"$clusterTime":{"clusterTime":{"$timestamp":{"t":1683184301,"i":1}},"signature":{"hash":{"$binary":{"base64":"hk1EhaG1QhD+LJYlqa8rN8kD03I=","subType":"0"}},"keyId":7225138377836724247}},"$configServerState":{"opTime":{"ts":{"$timestamp":{"t":1683184276,"i":1}},"t":1}},"$db":"config"},"planSummary":"IDHACK","keysExamined":1,"docsExamined":1,"nMatched":1,"nModified":1,"keysInserted":1,"keysDeleted":1,"numYields":0,"reslen":944,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":3},"writeConcern":{"w":"majority","wtimeout":15000,"provenance":"clientSupplied"},"protocol":"op_msg","durationMillis":10250}}
{"t":{"$date":"2023-05-04T15:11:53.534+08:00"},"s":"W", "c":"COMMAND", "id":20525, "ctx":"conn107","msg":"Failed to gather storage statistics for slow operation","attr":{"opId":25327201,"error":"lock acquire timeout"}}
{"t":{"$date":"2023-05-04T15:11:53.534+08:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn107","msg":"Slow query","attr":{"type":"command","ns":"config.lockpings","command":{"findAndModify":"lockpings","query":{"_id":"db-test02:27020:1682238543:1003676273669917507"},"update":{"$set":{"ping":{"$date":"2023-05-04T07:11:44.867Z"}}},"upsert":true,"writeConcern":{"w":"majority","wtimeout":15000},"maxTimeMS":30000,"$replData":1,"$clusterTime":{"clusterTime":{"$timestamp":{"t":1683184302,"i":1}},"signature":{"hash":{"$binary":{"base64":"pBveU7F8DsrnP+ci1SC8SZjcbog=","subType":"0"}},"keyId":7225138377836724247}},"$configServerState":{"opTime":{"ts":{"$timestamp":{"t":1683184302,"i":1}},"t":1}},"$db":"config"},"planSummary":"IDHACK","keysExamined":1,"docsExamined":1,"nMatched":1,"nModified":1,"keysInserted":1,"keysDeleted":1,"numYields":0,"reslen":943,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":3},"writeConcern":{"w":"majority","wtimeout":15000,"provenance":"clientSupplied"},"protocol":"op_msg","durationMillis":8665}}
{"t":{"$date":"2023-05-04T15:11:53.534+08:00"},"s":"W", "c":"COMMAND", "id":20525, "ctx":"conn1866","msg":"Failed to gather storage statistics for slow operation","attr":{"opId":25327224,"error":"lock acquire timeout"}}
{"t":{"$date":"2023-05-04T15:11:53.533+08:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn1732","msg":"Slow query","attr":{"type":"command","ns":"config.lockpings","command":{"findAndModify":"lockpings","query":{"_id":"db-test02:27018:1682237385:-4185141032096930406"},"update":{"$set":{"ping":{"$date":"2023-05-04T07:11:43.587Z"}}},"upsert":true,"writeConcern":{"w":"majority","wtimeout":15000},"maxTimeMS":30000,"$replData":1,"$clusterTime":{"clusterTime":{"$timestamp":{"t":1683184297,"i":1}},"signature":{"hash":{"$binary":{"base64":"4iK6ahwdeKghfd+N3lscP/Zbil8=","subType":"0"}},"keyId":7225138377836724247}},"$configServerState":{"opTime":{"ts":{"$timestamp":{"t":1683184297,"i":1}},"t":1}},"$db":"config"},"planSummary":"IDHACK","keysExamined":1,"docsExamined":1,"nMatched":1,"nModified":1,"keysInserted":1,"keysDeleted":1,"numYields":0,"reslen":944,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":3},"writeConcern":{"w":"majority","wtimeout":15000,"provenance":"clientSupplied"},"protocol":"op_msg","durationMillis":9945}}
{"t":{"$date":"2023-05-04T15:11:53.534+08:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn1866","msg":"Slow query","attr":{"type":"command","ns":"config.$cmd","command":{"update":"mongos","bypassDocumentValidation":false,"ordered":true,"updates":[{"q":{"_id":"db-test01:27017"},"u":{"$set":{"_id":"db-test01:27017","ping":{"$date":"2023-05-04T07:11:46.249Z"},"up":949382,"waiting":true,"mongoVersion":"4.4.20","advisoryHostFQDNs":[]}},"multi":false,"upsert":true}],"writeConcern":{"w":"majority","wtimeout":60000},"maxTimeMS":30000,"$replData":1,"$clusterTime":{"clusterTime":{"$timestamp":{"t":1683184303,"i":3}},"signature":{"hash":{"$binary":{"base64":"3ceHUCwGYyUkygHSbG/jKqcMMzE=","subType":"0"}},"keyId":7225138377836724247}},"$configServerState":{"opTime":{"ts":{"$timestamp":{"t":1683184302,"i":1}},"t":1}},"$db":"config"},"numYields":0,"reslen":893,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":3},"writeConcern":{"w":"majority","wtimeout":60000,"provenance":"clientSupplied"},"protocol":"op_msg","durationMillis":7283}}
{"t":{"$date":"2023-05-04T15:11:53.534+08:00"},"s":"W", "c":"COMMAND", "id":20525, "ctx":"conn1844","msg":"Failed to gather storage statistics for slow operation","attr":{"opId":25327176,"error":"lock acquire timeout"}}
{"t":{"$date":"2023-05-04T15:11:53.534+08:00"},"s":"I", "c":"SHARDING", "id":21867, "ctx":"Balancer","msg":"CSRS balancer is now stopped"}
{"t":{"$date":"2023-05-04T15:11:53.534+08:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn1844","msg":"Slow query","attr":{"type":"command","ns":"config.lockpings","command":{"findAndModify":"lockpings","query":{"_id":"db-test01:27020:1682238543:-1961663753705588089"},"update":{"$set":{"ping":{"$date":"2023-05-04T07:11:43.713Z"}}},"upsert":true,"writeConcern":{"w":"majority","wtimeout":15000},"maxTimeMS":30000,"$replData":1,"$clusterTime":{"clusterTime":{"$timestamp":{"t":1683184302,"i":1}},"signature":{"hash":{"$binary":{"base64":"pBveU7F8DsrnP+ci1SC8SZjcbog=","subType":"0"}},"keyId":7225138377836724247}},"$configServerState":{"opTime":{"ts":{"$timestamp":{"t":1683184302,"i":1}},"t":1}},"$db":"config"},"planSummary":"IDHACK","keysExamined":1,"docsExamined":1,"nMatched":1,"nModified":1,"keysInserted":1,"keysDeleted":1,"numYields":0,"reslen":944,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"FeatureCompatibilityVersion":{"acquireCount":{"w":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}},"Mutex":{"acquireCount":{"r":1}}},"flowControl":{"acquireCount":1,"timeAcquiringMicros":3},"writeConcern":{"w":"majority","wtimeout":15000,"provenance":"clientSupplied"},"protocol":"op_msg","durationMillis":9821}}
{"t":{"$date":"2023-05-04T15:11:53.544+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2968","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.122:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.122:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T15:11:53.724+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2970","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T15:11:54.047+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2970","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.122:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.122:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T15:11:54.233+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2968","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T15:11:54.346+08:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"WTCheckpointThread","msg":"WiredTiger message","attr":{"message":"[1683184314:346482][16528:0x7fed5a619700], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 2101909, snapshot max: 2101909 snapshot count: 0, oldest timestamp: (1683184297, 1) , meta checkpoint timestamp: (1683184302, 1) base write gen: 1"}}
{"t":{"$date":"2023-05-04T15:11:54.400+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.122:27019"}}
{"t":{"$date":"2023-05-04T15:11:54.400+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
关键信息:
"msg":"Can't see a majority of the set, relinquishing primary"
"msg":"Replica set state transition","attr":{"newState":"SECONDARY","oldState":"PRIMARY"}}
可以看到由于configReplSet不满足majority,主节点也stepdown成secondary(majority,即半数以上成员存活才能保证副本集对外提供读写服务的原则)
登陆mongos查看数据库,发现show databases 失败,因为MongoDB的Read reference默认是primary,此时configReplSet已经没有primary了,mongos无法读configReplSet。但是可写入数据。
mongos> show databases;
uncaught exception: Error: listDatabases failed:{"ok" : 0,"errmsg" : "Could not find host matching read preference { mode: \"primary\" } for set configReplSet","code" : 133,"codeName" : "FailedToSatisfyReadPreference","operationTime" : Timestamp(1683184761, 1),"$clusterTime" : {"clusterTime" : Timestamp(1683184771, 1),"signature" : {"hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),"keyId" : NumberLong(0)}}
} :
_getErrorWithCode@src/mongo/shell/utils.js:25:13
Mongo.prototype.getDBs/<@src/mongo/shell/mongo.js:147:19
Mongo.prototype.getDBs@src/mongo/shell/mongo.js:99:12
shellHelper.show@src/mongo/shell/utils.js:937:13
shellHelper@src/mongo/shell/utils.js:819:15
@(shellhelp2):1:1
mongos> use test
switched to db test
mongos> show tables;
colltest
system.profile
mongos> db.colltest.find()
{ "_id" : ObjectId("64549b2bc5d73938fef3934a"), "name" : "IamTester" }
{ "_id" : ObjectId("6454c38e4ab452e787a2c631"), "name" : "IamADBA" }
mongos> db.colltest.insertOne({"name":"Iamtrying"})
{"acknowledged" : true,"insertedId" : ObjectId("6454c78ea873f26c821c72bc")
}
mongos> db.colltest.find()
{ "_id" : ObjectId("64549b2bc5d73938fef3934a"), "name" : "IamTester" }
{ "_id" : ObjectId("6454c38e4ab452e787a2c631"), "name" : "IamADBA" }
{ "_id" : ObjectId("6454c78ea873f26c821c72bc"), "name" : "Iamtrying" }
启动122从节点
mongod -f /opt/mongodb/conf/configsvr.conf
about to fork child process, waiting until server is ready for connections.
forked process: 5650
child process started successfully, parent exiting
可以看到剩余的121节点从secondary变成原来的primary
configReplSet:SECONDARY>
configReplSet:SECONDARY>
configReplSet:PRIMARY>
configReplSet:PRIMARY>
121节点日志详细信息:
{"t":{"$date":"2023-05-04T16:23:24.690+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.122:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.122:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:24.819+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:25.175+08:00"},"s":"I", "c":"ELECTION", "id":4615655, "ctx":"ReplCoord-2986","msg":"Not starting an election, since we are not electable","attr":{"reason":"Not standing for election because I cannot see a majority (mask 0x1)"}}
{"t":{"$date":"2023-05-04T16:23:25.190+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.122:27019"}}
{"t":{"$date":"2023-05-04T16:23:25.193+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.122:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.122:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:25.325+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:25.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:25.697+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.122:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.122:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:25.830+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:26.197+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.122:27019"}}
{"t":{"$date":"2023-05-04T16:23:26.201+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.122:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.122:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:26.335+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:26.493+08:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"1.1.1.122:46106","connectionId":1873,"connectionCount":23}}
{"t":{"$date":"2023-05-04T16:23:26.497+08:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn1873","msg":"client metadata","attr":{"remote":"1.1.1.122:46106","client":"conn1873","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.20"},"os":{"type":"Linux","name":"CentOS Linux release 7.9.2009 (Core)","architecture":"x86_64","version":"Kernel 3.10.0-1160.el7.x86_64"}}}}
{"t":{"$date":"2023-05-04T16:23:26.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:26.702+08:00"},"s":"I", "c":"REPL", "id":21215, "ctx":"ReplCoord-2994","msg":"Member is in new state","attr":{"hostAndPort":"1.1.1.122:27019","newState":"SECONDARY"}}
{"t":{"$date":"2023-05-04T16:23:26.840+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:27.345+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:27.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:27.851+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2986","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:28.356+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2986","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:28.508+08:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"1.1.1.122:46166","connectionId":1875,"connectionCount":24}}
{"t":{"$date":"2023-05-04T16:23:28.509+08:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn1875","msg":"client metadata","attr":{"remote":"1.1.1.122:46166","client":"conn1875","doc":{"driver":{"name":"NetworkInterfaceTL","version":"4.4.20"},"os":{"type":"Linux","name":"CentOS Linux release 7.9.2009 (Core)","architecture":"x86_64","version":"Kernel 3.10.0-1160.el7.x86_64"}}}}
{"t":{"$date":"2023-05-04T16:23:28.513+08:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"1.1.1.122:46174","connectionId":1876,"connectionCount":25}}
{"t":{"$date":"2023-05-04T16:23:28.514+08:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn1876","msg":"client metadata","attr":{"remote":"1.1.1.122:46174","client":"conn1876","doc":{"application":{"name":"OplogFetcher"},"driver":{"name":"MongoDB Internal Client","version":"4.4.20"},"os":{"type":"Linux","name":"CentOS Linux release 7.9.2009 (Core)","architecture":"x86_64","version":"Kernel 3.10.0-1160.el7.x86_64"}}}}
{"t":{"$date":"2023-05-04T16:23:28.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:28.861+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:29.366+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:35.432+08:00"},"s":"I", "c":"ELECTION", "id":4615652, "ctx":"ReplCoord-2994","msg":"Starting an election, since we've seen no PRIMARY in election timeout period","attr":{"electionTimeoutPeriodMillis":10000}}
{"t":{"$date":"2023-05-04T16:23:35.432+08:00"},"s":"I", "c":"ELECTION", "id":21438, "ctx":"ReplCoord-2994","msg":"Conducting a dry run election to see if we could be elected","attr":{"currentTerm":1}}
{"t":{"$date":"2023-05-04T16:23:35.432+08:00"},"s":"I", "c":"REPL", "id":21752, "ctx":"ReplCoord-2994","msg":"Scheduling remote command request","attr":{"context":"vote request","request":"RemoteCommand 2304501 -- target:1.1.1.52:27019 db:admin cmd:{ replSetRequestVotes: 1, setName: \"configReplSet\", dryRun: true, term: 1, candidateIndex: 1, configVersion: 1, configTerm: 1, lastAppliedOpTime: { ts: Timestamp(1683184312, 1), t: 1 } }"}}
{"t":{"$date":"2023-05-04T16:23:35.432+08:00"},"s":"I", "c":"REPL", "id":21752, "ctx":"ReplCoord-2994","msg":"Scheduling remote command request","attr":{"context":"vote request","request":"RemoteCommand 2304502 -- target:1.1.1.122:27019 db:admin cmd:{ replSetRequestVotes: 1, setName: \"configReplSet\", dryRun: true, term: 1, candidateIndex: 1, configVersion: 1, configTerm: 1, lastAppliedOpTime: { ts: Timestamp(1683184312, 1), t: 1 } }"}}
{"t":{"$date":"2023-05-04T16:23:35.434+08:00"},"s":"I", "c":"ELECTION", "id":51799, "ctx":"ReplCoord-2986","msg":"VoteRequester processResponse","attr":{"term":1,"dryRun":true,"vote":"yes","from":"1.1.1.122:27019","message":{"term":1,"voteGranted":true,"reason":"","ok":1.0,"$gleStats":{"lastOpTime":{"$timestamp":{"t":0,"i":0}},"electionId":{"$oid":"000000000000000000000000"}},"lastCommittedOpTime":{"$timestamp":{"t":1683184302,"i":1}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1683188611,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"operationTime":{"$timestamp":{"t":1683184312,"i":1}}}}}
{"t":{"$date":"2023-05-04T16:23:35.434+08:00"},"s":"I", "c":"ELECTION", "id":21444, "ctx":"ReplCoord-2986","msg":"Dry election run succeeded, running for election","attr":{"newTerm":2}}
{"t":{"$date":"2023-05-04T16:23:35.434+08:00"},"s":"I", "c":"ELECTION", "id":6015300, "ctx":"ReplCoord-2986","msg":"Storing last vote document in local storage for my election","attr":{"lastVote":{"term":2,"candidateIndex":1}}}
{"t":{"$date":"2023-05-04T16:23:35.436+08:00"},"s":"I", "c":"REPL", "id":21752, "ctx":"ReplCoord-2986","msg":"Scheduling remote command request","attr":{"context":"vote request","request":"RemoteCommand 2304503 -- target:1.1.1.52:27019 db:admin cmd:{ replSetRequestVotes: 1, setName: \"configReplSet\", dryRun: false, term: 2, candidateIndex: 1, configVersion: 1, configTerm: 1, lastAppliedOpTime: { ts: Timestamp(1683184312, 1), t: 1 } }"}}
{"t":{"$date":"2023-05-04T16:23:35.437+08:00"},"s":"I", "c":"REPL", "id":21752, "ctx":"ReplCoord-2986","msg":"Scheduling remote command request","attr":{"context":"vote request","request":"RemoteCommand 2304504 -- target:1.1.1.122:27019 db:admin cmd:{ replSetRequestVotes: 1, setName: \"configReplSet\", dryRun: false, term: 2, candidateIndex: 1, configVersion: 1, configTerm: 1, lastAppliedOpTime: { ts: Timestamp(1683184312, 1), t: 1 } }"}}
{"t":{"$date":"2023-05-04T16:23:35.438+08:00"},"s":"I", "c":"ELECTION", "id":51799, "ctx":"ReplCoord-2994","msg":"VoteRequester processResponse","attr":{"term":2,"dryRun":false,"vote":"yes","from":"1.1.1.122:27019","message":{"term":2,"voteGranted":true,"reason":"","ok":1.0,"$gleStats":{"lastOpTime":{"$timestamp":{"t":0,"i":0}},"electionId":{"$oid":"000000000000000000000000"}},"lastCommittedOpTime":{"$timestamp":{"t":1683184302,"i":1}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1683188611,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"operationTime":{"$timestamp":{"t":1683184312,"i":1}}}}}
{"t":{"$date":"2023-05-04T16:23:35.438+08:00"},"s":"I", "c":"ELECTION", "id":21450, "ctx":"ReplCoord-2994","msg":"Election succeeded, assuming primary role","attr":{"term":2}}
{"t":{"$date":"2023-05-04T16:23:35.438+08:00"},"s":"I", "c":"REPL", "id":21358, "ctx":"ReplCoord-2994","msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}}
{"t":{"$date":"2023-05-04T16:23:35.439+08:00"},"s":"I", "c":"REPL", "id":21106, "ctx":"ReplCoord-2994","msg":"Resetting sync source to empty","attr":{"previousSyncSource":":27017"}}
{"t":{"$date":"2023-05-04T16:23:35.439+08:00"},"s":"I", "c":"REPL", "id":21359, "ctx":"ReplCoord-2994","msg":"Entering primary catch-up mode"}
{"t":{"$date":"2023-05-04T16:23:35.446+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2986","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:35.446+08:00"},"s":"I", "c":"REPL", "id":21364, "ctx":"ReplCoord-2986","msg":"Caught up to the latest optime known via heartbeats after becoming primary","attr":{"targetOpTime":{"ts":{"$timestamp":{"t":1683184312,"i":1}},"t":1},"myLastApplied":{"ts":{"$timestamp":{"t":1683184312,"i":1}},"t":1}}}
{"t":{"$date":"2023-05-04T16:23:35.446+08:00"},"s":"I", "c":"REPL", "id":21363, "ctx":"ReplCoord-2986","msg":"Exited primary catch-up mode"}
{"t":{"$date":"2023-05-04T16:23:35.446+08:00"},"s":"I", "c":"REPL", "id":21107, "ctx":"ReplCoord-2986","msg":"Stopping replication producer"}
{"t":{"$date":"2023-05-04T16:23:35.446+08:00"},"s":"I", "c":"REPL", "id":21239, "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":2}}
{"t":{"$date":"2023-05-04T16:23:35.446+08:00"},"s":"I", "c":"REPL", "id":21239, "ctx":"ReplBatcher","msg":"Oplog buffer has been drained","attr":{"term":2}}
{"t":{"$date":"2023-05-04T16:23:35.447+08:00"},"s":"I", "c":"REPL", "id":21343, "ctx":"RstlKillOpThread","msg":"Starting to kill user operations"}
{"t":{"$date":"2023-05-04T16:23:35.447+08:00"},"s":"I", "c":"REPL", "id":21344, "ctx":"RstlKillOpThread","msg":"Stopped killing user operations"}
{"t":{"$date":"2023-05-04T16:23:35.447+08:00"},"s":"I", "c":"REPL", "id":21340, "ctx":"RstlKillOpThread","msg":"State transition ops metrics","attr":{"metrics":{"lastStateTransition":"stepUp","userOpsKilled":0,"userOpsRunning":8}}}
{"t":{"$date":"2023-05-04T16:23:35.448+08:00"},"s":"I", "c":"REPL", "id":4508103, "ctx":"OplogApplier-0","msg":"Increment the config term via reconfig"}
{"t":{"$date":"2023-05-04T16:23:35.448+08:00"},"s":"I", "c":"REPL", "id":6015313, "ctx":"OplogApplier-0","msg":"Replication config state is Steady, starting reconfig"}
{"t":{"$date":"2023-05-04T16:23:35.448+08:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"OplogApplier-0","msg":"Setting new configuration state","attr":{"newState":"ConfigReconfiguring","oldState":"ConfigSteady"}}
{"t":{"$date":"2023-05-04T16:23:35.448+08:00"},"s":"I", "c":"REPL", "id":21353, "ctx":"OplogApplier-0","msg":"replSetReconfig config object parses ok","attr":{"numMembers":3}}
{"t":{"$date":"2023-05-04T16:23:35.448+08:00"},"s":"I", "c":"REPL", "id":51814, "ctx":"OplogApplier-0","msg":"Persisting new config to disk"}
{"t":{"$date":"2023-05-04T16:23:35.450+08:00"},"s":"I", "c":"REPL", "id":6015315, "ctx":"OplogApplier-0","msg":"Persisted new config to disk"}
{"t":{"$date":"2023-05-04T16:23:35.450+08:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"OplogApplier-0","msg":"Setting new configuration state","attr":{"newState":"ConfigSteady","oldState":"ConfigReconfiguring"}}
{"t":{"$date":"2023-05-04T16:23:35.450+08:00"},"s":"I", "c":"REPL", "id":21392, "ctx":"OplogApplier-0","msg":"New replica set config in use","attr":{"config":{"_id":"configReplSet","version":1,"term":2,"configsvr":true,"protocolVersion":1,"writeConcernMajorityJournalDefault":true,"members":[{"_id":0,"host":"1.1.1.52:27019","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1.0,"tags":{},"slaveDelay":0,"votes":1},{"_id":1,"host":"1.1.1.121:27019","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1.0,"tags":{},"slaveDelay":0,"votes":1},{"_id":2,"host":"1.1.1.122:27019","arbiterOnly":false,"buildIndexes":true,"hidden":false,"priority":1.0,"tags":{},"slaveDelay":0,"votes":1}],"settings":{"chainingAllowed":true,"heartbeatIntervalMillis":2000,"heartbeatTimeoutSecs":10,"electionTimeoutMillis":10000,"catchUpTimeoutMillis":-1,"catchUpTakeoverDelayMillis":30000,"getLastErrorModes":{},"getLastErrorDefaults":{"w":1,"wtimeout":0},"replicaSetId":{"$oid":"6444d90732c549e2549786d1"}}}}}
{"t":{"$date":"2023-05-04T16:23:35.450+08:00"},"s":"I", "c":"REPL", "id":21393, "ctx":"OplogApplier-0","msg":"Found self in config","attr":{"hostAndPort":"1.1.1.121:27019"}}
{"t":{"$date":"2023-05-04T16:23:35.451+08:00"},"s":"I", "c":"REPL", "id":6015310, "ctx":"OplogApplier-0","msg":"Starting to transition to primary."}
{"t":{"$date":"2023-05-04T16:23:35.453+08:00"},"s":"I", "c":"REPL", "id":6015309, "ctx":"OplogApplier-0","msg":"Logging transition to primary to oplog on stepup"}
{"t":{"$date":"2023-05-04T16:23:35.455+08:00"},"s":"I", "c":"TXN", "id":22454, "ctx":"OplogApplier-0","msg":"Waiting for coordinator tasks from previous term to complete"}
{"t":{"$date":"2023-05-04T16:23:35.455+08:00"},"s":"I", "c":"SHARDING", "id":21856, "ctx":"Balancer","msg":"CSRS balancer is starting"}
{"t":{"$date":"2023-05-04T16:23:35.455+08:00"},"s":"I", "c":"SHARDING", "id":22049, "ctx":"PeriodicShardedIndexConsistencyChecker","msg":"Checking consistency of sharded collection indexes across the cluster"}
{"t":{"$date":"2023-05-04T16:23:35.456+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2996","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:35.456+08:00"},"s":"I", "c":"STORAGE", "id":20657, "ctx":"OplogApplier-0","msg":"IndexBuildsCoordinator::onStepUp - this node is stepping up to primary"}
{"t":{"$date":"2023-05-04T16:23:35.456+08:00"},"s":"I", "c":"REPL", "id":21331, "ctx":"OplogApplier-0","msg":"Transition to primary complete; database writes are now permitted"}
{"t":{"$date":"2023-05-04T16:23:35.456+08:00"},"s":"I", "c":"REPL", "id":6015306, "ctx":"OplogApplier-0","msg":"Applier already left draining state, exiting."}
{"t":{"$date":"2023-05-04T16:23:35.520+08:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"1.1.1.122:46312","connectionId":1877,"connectionCount":26}}
{"t":{"$date":"2023-05-04T16:23:35.521+08:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn1877","msg":"client metadata","attr":{"remote":"1.1.1.122:46312","client":"conn1877","doc":{"application":{"name":"OplogFetcher"},"driver":{"name":"MongoDB Internal Client","version":"4.4.20"},"os":{"type":"Linux","name":"CentOS Linux release 7.9.2009 (Core)","architecture":"x86_64","version":"Kernel 3.10.0-1160.el7.x86_64"}}}}
{"t":{"$date":"2023-05-04T16:23:35.527+08:00"},"s":"I", "c":"TXN", "id":22452, "ctx":"TransactionCoordinator","msg":"Need to resume coordinating commit for transactions with an in-progress two-phase commit/abort","attr":{"numPendingTransactions":0}}
{"t":{"$date":"2023-05-04T16:23:35.527+08:00"},"s":"I", "c":"NETWORK", "id":22989, "ctx":"conn1876","msg":"Error sending response to client. Ending connection from remote","attr":{"error":{"code":9001,"codeName":"SocketException","errmsg":"Broken pipe"},"remote":"1.1.1.122:46174","connectionId":1876}}
{"t":{"$date":"2023-05-04T16:23:35.527+08:00"},"s":"I", "c":"TXN", "id":22438, "ctx":"TransactionCoordinator","msg":"Incoming coordinateCommit requests are now enabled"}
{"t":{"$date":"2023-05-04T16:23:35.528+08:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn1876","msg":"Connection ended","attr":{"remote":"1.1.1.122:46174","connectionId":1876,"connectionCount":25}}
{"t":{"$date":"2023-05-04T16:23:35.529+08:00"},"s":"I", "c":"SHARDING", "id":21857, "ctx":"Balancer","msg":"CSRS balancer thread is recovering"}
{"t":{"$date":"2023-05-04T16:23:35.529+08:00"},"s":"I", "c":"SHARDING", "id":21858, "ctx":"Balancer","msg":"CSRS balancer thread is recovered"}
{"t":{"$date":"2023-05-04T16:23:35.529+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"MirrorMaestro","msg":"Connecting","attr":{"hostAndPort":"1.1.1.122:27019"}}
{"t":{"$date":"2023-05-04T16:23:35.530+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ShardRegistry","msg":"Connecting","attr":{"hostAndPort":"1.1.1.121:27018"}}
{"t":{"$date":"2023-05-04T16:23:35.535+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"TaskExecutorPool-0","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27020"}}
{"t":{"$date":"2023-05-04T16:23:35.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:36.533+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"TaskExecutorPool-0","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27018"}}
{"t":{"$date":"2023-05-04T16:23:36.533+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"TaskExecutorPool-0","msg":"Connecting","attr":{"hostAndPort":"1.1.1.122:27018"}}
{"t":{"$date":"2023-05-04T16:23:36.535+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"TaskExecutorPool-0","msg":"Connecting","attr":{"hostAndPort":"1.1.1.121:27020"}}
{"t":{"$date":"2023-05-04T16:23:36.535+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"TaskExecutorPool-0","msg":"Connecting","attr":{"hostAndPort":"1.1.1.122:27020"}}
{"t":{"$date":"2023-05-04T16:23:36.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:37.461+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2997","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:37.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:38.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:39.466+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:39.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:40.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:41.471+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2996","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:41.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:42.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:43.476+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2997","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:43.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:44.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:45.480+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2996","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
{"t":{"$date":"2023-05-04T16:23:45.551+08:00"},"s":"I", "c":"SHARDING", "id":20997, "ctx":"conn1871","msg":"Refreshed RWC defaults","attr":{"newDefaults":{}}}
{"t":{"$date":"2023-05-04T16:23:45.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:46.599+08:00"},"s":"I", "c":"CONNPOOL", "id":22576, "ctx":"ReplNetwork","msg":"Connecting","attr":{"hostAndPort":"1.1.1.52:27019"}}
{"t":{"$date":"2023-05-04T16:23:47.485+08:00"},"s":"I", "c":"REPL_HB", "id":23974, "ctx":"ReplCoord-2994","msg":"Heartbeat failed after max retries","attr":{"target":"1.1.1.52:27019","maxHeartbeatRetries":2,"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Error connecting to 1.1.1.52:27019 :: caused by :: Connection refused"}}}
关键信息:
"msg":"Connection accepted","attr":{"remote":"1.1.1.122:46166","connectionId":1875,"connectionCount":24}}
"msg":"Election succeeded, assuming primary role"
"msg":"Replica set state transition","attr":{"newState":"PRIMARY","oldState":"SECONDARY"}}
可以看到从节点122启动之后,configReplSet满足majority,原先的primary又从secondary变回了primary
登陆mongos查看数据库,发现集群正常
mongos> show databases;
admin 0.000GB
config 0.003GB
查看configReplSet状态
configReplSet:PRIMARY> rs.printSecondaryReplicationInfo()
source: 1.1.1.52:27019syncedTo: Thu Jan 01 1970 08:00:00 GMT+0800 (CST)1683189238 secs (467552.57 hrs) behind the primary
source: 1.1.1.122:27019syncedTo: Thu May 04 2023 16:33:56 GMT+0800 (CST)2 secs (0 hrs) behind the primary
启动剩余52节点,恢复整个mongoDB集群
mongod -f /opt/mongodb/conf/configsvr.conf &
[1] 71130
about to fork child process, waiting until server is ready for connections.
forked process: 71132
child process started successfully, parent exiting
[1]+ 完成 mongod -f /opt/mongodb/conf/configsvr.conf
其他发现:
configReplSet数据量较小,从节点出现问题后,2秒内primary变成secondary,启动122从节点之后,22秒左右configReplSet恢复正常,整个集群变成可读写