|
Hi
OK, I think you we can scratch most from above. I found an easy way to reproduce the problem even in a lab environment:
Deploy a shared cluster with 3 shards (shard_01, shard_02, shard_03). Deploy each shards as a PSA (PRIMARY, SECONDARY, ARBITER)
db.adminCommand("getShardMap").map
|
{
|
"shard_01" : "shard_01/localhost:27028,localhost:27128",
|
"shard_02" : "shard_02/localhost:27038,localhost:27138",
|
"shard_03" : "shard_03/localhost:27048,localhost:27148",
|
"config" : "configRepSet/localhost:27029,localhost:27039,localhost:27049"
|
}
|
|
|
|
for (let d of ["tdube04mipmed1", "tdube04mipmed0", "pzur01mipmed0", "pzur01mipmed1", "pgen01mipmed0", "pgen01mipmed1"]) {
|
db.getSiblingDB(d).runCommand({
|
"createIndexes": "sessions",
|
"commitQuorum": 1,
|
"indexes": [
|
{ "name": "n_t_dp", "key": { "n": 1, "t": 1, "dp": 1 } },
|
{ "name": "si_tsi", "key": { "si": 1, "tsi": 1 } },
|
{ "name": "n_t0", "key": { "t0": 1, "n": 1 }, "partialFilterExpression": { "t0": { "$lt": ISODate("2022-04-17T22:00:00Z") } } }
|
]
|
});
|
sh.enableSharding(d);
|
}
|
|
|
db.adminCommand({ movePrimary: "tdube04mipmed0", to: "shard_01" })
|
db.adminCommand({ movePrimary: "tdube04mipmed1", to: "shard_01" })
|
db.adminCommand({ movePrimary: "pzur01mipmed0", to: "shard_02" })
|
db.adminCommand({ movePrimary: "pzur01mipmed1", to: "shard_02" })
|
db.adminCommand({ movePrimary: "pgen01mipmed0", to: "shard_03" })
|
db.adminCommand({ movePrimary: "pgen01mipmed1", to: "shard_03" })
|
|
|
db.getSiblingDB('tdube04mipmed1').sessions.insertMany([
|
{ "_id": ObjectId("62612fd54538aebab5a19bf9"), "sid": NumberLong("2545922668"), "di": "194.230.47.34", "tsp": 54913, "rb": NumberLong(4238), "tsi": "194.230.159.201", "dp": 443, "si": "10.133.216.49", "a": "client-rst", "f": "WALB01MFW01", "sb": NumberLong(1529), "t0": ISODate("2022-04-21T10:17:40Z"), "n": "snat", "p": "https", "t": ISODate("2022-04-21T10:19:03Z"), "sp": 54913 },
|
{ "_id": ObjectId("62612fd54538aebab5a19bfa"), "sid": NumberLong("2543830321"), "di": "35.186.224.25", "tsp": 64335, "rb": NumberLong(153309), "tsi": "194.230.159.177", "dp": 443, "si": "10.128.63.85", "a": "accept", "f": "WALB01MFW01", "sb": NumberLong(116), "t0": ISODate("2022-04-21T10:11:05Z"), "n": "snat", "p": "https", "t": ISODate("2022-04-21T10:19:03Z"), "sp": 64335 },
|
{ "_id": ObjectId("62612fd54538aebab5a19bfb"), "sid": NumberLong("2541614925"), "di": "194.230.47.17", "tsp": 49185, "rb": NumberLong(306330), "tsi": "194.230.159.181", "dp": 443, "si": "10.128.26.161", "a": "accept", "f": "WALB01MFW01", "sb": NumberLong(10003), "t0": ISODate("2022-04-21T10:04:11Z"), "n": "snat", "p": "udp", "t": ISODate("2022-04-21T10:19:03Z"), "sp": 49185 },
|
{ "_id": ObjectId("62612fd54538aebab5a19bfc"), "sid": NumberLong("2546180742"), "di": "216.58.215.246", "tsp": 43324, "rb": NumberLong(454914), "tsi": "194.230.159.193", "dp": 443, "si": "10.128.14.237", "a": "close", "f": "WALB01MFW01", "sb": NumberLong(22994), "t0": ISODate("2022-04-21T10:18:30Z"), "n": "snat", "p": "https", "t": ISODate("2022-04-21T10:19:03Z"), "sp": 43324 },
|
{ "_id": ObjectId("62612fd54538aebab5a19bfd"), "sid": NumberLong("2541615618"), "di": "35.244.237.205", "tsp": 65421, "rb": NumberLong(1991), "tsi": "194.230.159.149", "dp": 443, "si": "10.134.46.165", "a": "accept", "f": "WALB01MFW01", "sb": NumberLong(1532), "t0": ISODate("2022-04-21T10:04:12Z"), "n": "snat", "p": "udp", "t": ISODate("2022-04-21T10:19:04Z"), "sp": 65421 },
|
{ "_id": ObjectId("62612fd54538aebab5a19bfe"), "sid": NumberLong("2541621962"), "di": "216.58.215.234", "tsp": 40214, "rb": NumberLong(3765), "tsi": "194.230.159.221", "dp": 443, "si": "10.133.145.9", "a": "accept", "f": "WALB01MFW01", "sb": NumberLong(10587), "t0": ISODate("2022-04-21T10:04:12Z"), "n": "snat", "p": "udp", "t": ISODate("2022-04-21T10:19:03Z"), "sp": 40214 }
|
])
|
|
|
// Connect to SECONDARY of shard_01, shard_02, shard_03 -> db.shutdownServer()
|
// -> All SECONDARY shards services are down
|
|
db.adminCommand({ "renameCollection": "tdube04mipmed1.sessions", "to": "tdube04mipmed1.sessions.111-1255", "writeConcern": { "wtimeout": 30000 } })
|
// "renameCollection" Command is hanging. While it is waiting, open a new connection to ReplicaSet shard_01
|
|
cfg = db.adminCommand({ replSetGetConfig: 1 }).config;
|
idx = cfg.members.findIndex(x => x.host == "localhost:27128");
|
cfg.members[idx].votes = 0;
|
cfg.members[idx].priority = 0;
|
cfg.version++;
|
db.adminCommand({replSetReconfig: cfg});
|
|
|
// After some time (I guess after 30 seconds) you receive the error:
|
{
|
"ok" : 0,
|
"errmsg" : "Failed command { _shardsvrRenameCollectionParticipant: \"sessions\", to: \"tdube04mipmed1.sessions.111-1255\", dropTarget: false, stayTemp: false, sourceUUID: UUID(\"4a092739-5599-488e-957d-1f4f34ff8e63\"), writeConcern: { w: \"majority\", wtimeout: 60000 }, lsid: { id: UUID(\"50e68494-2c74-4929-a327-8e84b3b2ee6e\"), uid: BinData(0, BB89D3175FB0981C86826C27759082A37160471F60504B4612415186C630AB70) }, txnNumber: 0, $audit: { $impersonatedUsers: [ { user: \"admin\", db: \"admin\" } ], $impersonatedRoles: [ { role: \"root\", db: \"admin\" } ] } } for database 'tdube04mipmed1' on shard 'shard_03' :: caused by :: waiting for replication timed out",
|
"code" : 64,
|
"codeName" : "WriteConcernFailed",
|
"$clusterTime" : {
|
"clusterTime" : Timestamp(1650540422, 7),
|
"signature" : {
|
"hash" : BinData(0, "EQrdPCc8WYOCz7IKyHMdeI7Xwaw="),
|
"keyId" : NumberLong("7089007576913805333")
|
}
|
},
|
"operationTime" : Timestamp(1650540422, 1)
|
}
|
|
|
|
Now you have situation where db.getSiblingDB('tdube04mipmed1').sessions cannot be be used anymore. Any command you try to run on db.getSiblingDB('tdube04mipmed1').sessions just hangs.
Surprisingly db.getSiblingDB('tdube04mipmed1').getCollectionNames() returns sessions.111-1255 which should not be the case, because "renameCollection" actually failed.
Also it says "Failed command ... for database 'tdube04mipmed1' on shard 'shard_03'", however primary shard for database tdube04mipmed1 is "shard_01", not "shard_03". So I would expect the error message "Failed command ... for database 'tdube04mipmed1' on shard 'shard_01'"
- stop / start of all nodes in sharded cluster does not help
- db.getSiblingDB('tdube04mipmed1').dropDatabase() does not help either
I don't find any solution to make "tdube04mipmed1.sessions" usable again, I have to drop the entire sharded cluster and deploy it from scratch!
The workaroud is to set {{{votes: 0, priority: 0} }} before you run "renameCollection". However, typically you don't know the time when a node in your cluster fails, it may happen at arbitrary time. If you have a network or power outage the it does not care whether "renameCollection" is currently executed or not.
Kind Regards
Wernfried
|
|
I run again into this problem. This time it was not by intention, I stopped/started "shard_03" and a rename failed. Note, primary shard for database "pzur01mipmed0" is not "shard_03" which was stopped:
Now, collection pzur01mipmed0.sessions#3 is not created anymore, i.e. I cannot insert any data into such collection:
db.adminCommand({ "renameCollection" : "pzur01mipmed0.sessions#3", "to" : "pzur01mipmed0.sessions#3.110-1155", "writeConcern" : { "wtimeout" : 30000 } })
|
|
Failed command
|
{
|
_shardsvrRenameCollectionParticipant: "sessions#3",
|
to: "pzur01mipmed0.sessions#3.110-1155",
|
dropTarget: false,
|
stayTemp: false,
|
sourceUUID: UUID("ea976782-923e-4e14-9688-2d1317203230"),
|
writeConcern: {
|
w: "majority",
|
wtimeout: 60000
|
},
|
lsid: {
|
id: UUID("2d0ee188-7a78-459a-b1d4-a9fa95012162"),
|
uid: BinData(0, BB89D3175FB0981C86826C27759082A37160471F60504B4612415186C630AB70)
|
},
|
txnNumber: 0,
|
$audit: {
|
$impersonatedUsers: [
|
{
|
user: "mipsys",
|
db: "admin"
|
}
|
],
|
$impersonatedRoles: [
|
{
|
role: "dbOwner",
|
db: "pgen01mipmed0"
|
},
|
{
|
role: "dbOwner",
|
db: "data"
|
},
|
{
|
role: "dbOwner",
|
db: "p-mipmed-as-02"
|
},
|
{
|
role: "dbOwner",
|
db: "plau01mipmed1"
|
},
|
{
|
role: "dbOwner",
|
db: "tdube04mipmed1"
|
},
|
{
|
role: "dbOwner",
|
db: "pgen01mipmed1"
|
},
|
{
|
role: "clusterMonitor",
|
db: "admin"
|
},
|
{
|
role: "dbOwner",
|
db: "p-mipmed-as-01"
|
},
|
{
|
role: "dbOwner",
|
db: "ignored"
|
},
|
{
|
role: "dbOwner",
|
db: "tdube04mipmed0"
|
},
|
{
|
role: "dbOwner",
|
db: "polt01mipmed1"
|
},
|
{
|
role: "mip.admin",
|
db: "admin"
|
},
|
{
|
role: "dbOwner",
|
db: "pzur01mipmed1"
|
},
|
{
|
role: "dbOwner",
|
db: "t-mipmed-as-01"
|
},
|
{
|
role: "dbOwner",
|
db: "mip"
|
},
|
{
|
role: "dbOwner",
|
db: "pmado01mipmed0"
|
},
|
{
|
role: "dbOwner",
|
db: "polt01mipmed0"
|
},
|
{
|
role: "dbOwner",
|
db: "pzur01mipmed0"
|
},
|
{
|
role: "dbOwner",
|
db: "pmado01mipmed1"
|
},
|
{
|
role: "dbOwner",
|
db: "pber08mipmed1"
|
},
|
{
|
role: "clusterManager",
|
db: "admin"
|
},
|
{
|
role: "dbOwner",
|
db: "plau01mipmed0"
|
},
|
{
|
role: "dbOwner",
|
db: "pber08mipmed0"
|
}
|
]
|
}
|
}
|
|
for database 'pzur01mipmed0' on shard 'shard_03' :: caused by :: waiting for replication timed out",
|
|
Here are some logs related to this operation. I can also provide the full log files:
Logging on mongos:
|
|
{"t":{"$date":"2022-04-20T11:56:04.023+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn4059","msg":"Slow query","attr":{"type":"command","ns":"pzur01mipmed0.sessions#3","appName":"MongoDB Shell","command":{"renameCollection":"pzur01mipmed0.sessions#3","to":"pzur01mipmed0.sessions#3.110-1155","writeConcern":{"wtimeout":30000},"lsid":{"id":{"$uuid":"6d981744-2bba-4841-abb7-8b755eefa491"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1650448502,"i":34026}},"signature":{"hash":{"$binary":{"base64":"Va6o9Oz80dDKrfn/tFR3EBPf8jU=","subType":"0"}},"keyId":7081698715102085126}},"$db":"admin"},"numYields":0,"ok":0,"errMsg":"Failed command { _shardsvrRenameCollectionParticipant: \"sessions#3\", to: \"pzur01mipmed0.sessions#3.110-1155\", dropTarget: false, stayTemp: false, sourceUUID: UUID(\"ea976782-923e-4e14-9688-2d1317203230\"), writeConcern: { w: \"majority\", wtimeout: 60000 }, lsid: { id: UUID(\"2d0ee188-7a78-459a-b1d4-a9fa95012162\"), uid: BinData(0, BB89D3175FB0981C86826C27759082A37160471F60504B4612415186C630AB70) }, txnNumber: 0, $audit: { $impersonatedUsers: [ { user: \"mipsys\", db: \"admin\" } ], $impersonatedRoles: [ { role: \"dbOwner\", db: \"pgen01mipmed0\" }, { role: \"dbOwner\", db: \"data\" }, { role: \"dbOwner\", db: \"p-mipmed-as-02\" }, { role: \"dbOwner\", db: \"plau01mipmed1\" }, { role: \"dbOwner\", db: \"tdube04mipmed1\" }, { role: \"dbOwner\", db: \"pgen01mipmed1\" }, { role: \"clusterMonitor\", db: \"admin\" }, { role: \"dbOwner\", db: \"p-mipmed-as-01\" }, { role: \"dbOwner\", db: \"ignored\" }, { role: \"dbOwner\", db: \"tdube04mipmed0\" }, { role: \"dbOwner\", db: \"polt01mipmed1\" }, { role: \"mip.admin\", db: \"admin\" }, { role: \"dbOwner\", db: \"pzur01mipmed1\" }, { role: \"dbOwner\", db: \"t-mipmed-as-01\" }, { role: \"dbOwner\", db: \"mip\" }, { role: \"dbOwner\", db: \"pmado01mipmed0\" }, { role: \"dbOwner\", db: \"polt01mipmed0\" }, { role: \"dbOwner\", db: \"pzur01mipmed0\" }, { role: \"dbOwner\", db: \"pmado01mipmed1\" }, { role: \"dbOwner\", db: \"pber08mipmed1\" }, { role: \"clusterManager\", db: \"admin\" }, { role: \"dbOwner\", db: \"plau01mipmed0\" }, { role: \"dbOwner\", db: \"pber08mipmed0\" } ] } } for database 'pzur01mipmed0' on shard 'shard_03' :: caused by :: waiting for replication timed out","errName":"WriteConcernFailed","errCode":64,"reslen":1762,"readConcern":{"level":"local","provenance":"implicitDefault"},"remote":"10.229.152.20:38584","protocol":"op_msg","durationMillis":61119}}
|
|
|
Logging from SECONDARY Shard_04:
|
|
{"t":{"$date":"2022-04-20T11:55:03.813+02:00"},"s":"I", "c":"COMMAND", "id":20401, "ctx":"ReplWriterWorker-8","msg":"renameCollectionForApplyOps","attr":{"sourceNamespace":"pzur01mipmed0.sessions#3","uuid":"ea976782-923e-4e14-9688-2d1317203230","targetNamespace":"pzur01mipmed0.sessions#3.110-1155","uuidToDrop":"<none>"}}
|
{"t":{"$date":"2022-04-20T11:55:03.813+02:00"},"s":"I", "c":"STORAGE", "id":20319, "ctx":"ReplWriterWorker-8","msg":"renameCollection","attr":{"uuid":{"uuid":{"$uuid":"ea976782-923e-4e14-9688-2d1317203230"}},"fromName":"pzur01mipmed0.sessions#3","toName":"pzur01mipmed0.sessions#3.110-1155"}}
|
|
|
Logging from PRIMARY Shard_04:
|
|
{"t":{"$date":"2022-04-20T11:55:02.926+02:00"},"s":"I", "c":"SHARDING", "id":22655, "ctx":"ShardingDDLCoordinator-938","msg":"Acquired distributed lock","attr":{"lockName":"pzur01mipmed0.sessions#3.110-1155","lockSessionId":{"$oid":"020000000000000000000000"},"reason":"renameCollection"}}
|
{"t":{"$date":"2022-04-20T11:55:03.144+02:00"},"s":"I", "c":"SHARDING", "id":22080, "ctx":"ShardingDDLCoordinator-938","msg":"About to log metadata event","attr":{"namespace":"changelog","event":{"_id":"d-mipmdb-sh1-04.swi.srse.net:27018-2022-04-20T11:55:03.144+02:00-625fd877e594713dc7bacd9a","server":"d-mipmdb-sh1-04.swi.srse.net:27018","shard":"shard_04","clientAddr":"","time":{"$date":"2022-04-20T09:55:03.144Z"},"what":"renameCollection.start","ns":"pzur01mipmed0.sessions#3","details":{"source":"pzur01mipmed0.sessions#3","destination":"pzur01mipmed0.sessions#3.110-1155"}}}}
|
{"t":{"$date":"2022-04-20T11:55:03.797+02:00"},"s":"I", "c":"COMMAND", "id":20400, "ctx":"RenameCollectionParticipantService-467","msg":"renameCollectionForCommand","attr":{"sourceNamespace":"pzur01mipmed0.sessions#3","targetNamespace":"pzur01mipmed0.sessions#3.110-1155","dropTarget":"no"}}
|
{"t":{"$date":"2022-04-20T11:55:03.797+02:00"},"s":"I", "c":"STORAGE", "id":20319, "ctx":"RenameCollectionParticipantService-467","msg":"renameCollection","attr":{"uuid":{"uuid":{"$uuid":"ea976782-923e-4e14-9688-2d1317203230"}},"fromName":"pzur01mipmed0.sessions#3","toName":"pzur01mipmed0.sessions#3.110-1155"}}
|
{"t":{"$date":"2022-04-20T11:55:03.901+02:00"},"s":"I", "c":"SHARDING", "id":5515106, "ctx":"RenameCollectionParticipantService-467","msg":"Collection locally renamed, waiting for CRUD to be unblocked","attr":{"fromNs":"pzur01mipmed0.sessions#3","toNs":"pzur01mipmed0.sessions#3.110-1155"}}
|
{"t":{"$date":"2022-04-20T11:55:03.901+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn8262","msg":"Slow query","attr":{"type":"command","ns":"pzur01mipmed0.$cmd","command":{"_shardsvrRenameCollectionParticipant":"sessions#3","to":"pzur01mipmed0.sessions#3.110-1155","dropTarget":false,"stayTemp":false,"sourceUUID":{"$uuid":"ea976782-923e-4e14-9688-2d1317203230"},"writeConcern":{"w":"majority","wtimeout":60000},"lsid":{"id":{"$uuid":"2d0ee188-7a78-459a-b1d4-a9fa95012162"},"uid":{"$binary":{"base64":"u4nTF1+wmByGgmwndZCCo3FgRx9gUEtGEkFRhsYwq3A=","subType":"0"}}},"txnNumber":0,"$audit":{"$impersonatedUsers":[{"user":"mipsys","db":"admin"}],"$impersonatedRoles":[{"role":"dbOwner","db":"pgen01mipmed0"},{"role":"dbOwner","db":"data"},{"role":"dbOwner","db":"p-mipmed-as-02"},{"role":"dbOwner","db":"plau01mipmed1"},{"role":"dbOwner","db":"tdube04mipmed1"},{"role":"dbOwner","db":"pgen01mipmed1"},{"role":"clusterMonitor","db":"admin"},{"role":"dbOwner","db":"p-mipmed-as-01"},{"role":"dbOwner","db":"ignored"},{"role":"dbOwner","db":"tdube04mipmed0"},{"role":"dbOwner","db":"polt01mipmed1"},{"role":"mip.admin","db":"admin"},{"role":"dbOwner","db":"pzur01mipmed1"},{"role":"dbOwner","db":"t-mipmed-as-01"},{"role":"dbOwner","db":"mip"},{"role":"dbOwner","db":"pmado01mipmed0"},{"role":"dbOwner","db":"polt01mipmed0"},{"role":"dbOwner","db":"pzur01mipmed0"},{"role":"dbOwner","db":"pmado01mipmed1"},{"role":"dbOwner","db":"pber08mipmed1"},{"role":"clusterManager","db":"admin"},{"role":"dbOwner","db":"plau01mipmed0"},{"role":"dbOwner","db":"pber08mipmed0"}]},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1650448503,"i":16004}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$configTime":{"$timestamp":{"t":1650448503,"i":5504}},"$topologyTime":{"$timestamp":{"t":1648836518,"i":2}},"$db":"pzur01mipmed0"},"numYields":0,"reslen":368,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":2}},"Global":{"acquireCount":{"r":2}},"Mutex":{"acquireCount":{"r":1}}},"readConcern":{"provenance":"implicitDefault"},"writeConcern":{"w":"majority","wtimeout":60000,"provenance":"clientSupplied"},"storage":{},"remote":"10.192.241.232:49430","protocol":"op_msg","durationMillis":431}}
|
{"t":{"$date":"2022-04-20T11:56:03.982+02:00"},"s":"E", "c":"SHARDING", "id":5460505, "ctx":"ShardingDDLCoordinator-938","msg":"Error running rename collection","attr":{"namespace":"pzur01mipmed0.sessions#3","error":"WriteConcernFailed: Failed command { _shardsvrRenameCollectionParticipant: \"sessions#3\", to: \"pzur01mipmed0.sessions#3.110-1155\", dropTarget: false, stayTemp: false, sourceUUID: UUID(\"ea976782-923e-4e14-9688-2d1317203230\"), writeConcern: { w: \"majority\", wtimeout: 60000 }, lsid: { id: UUID(\"2d0ee188-7a78-459a-b1d4-a9fa95012162\"), uid: BinData(0, BB89D3175FB0981C86826C27759082A37160471F60504B4612415186C630AB70) }, txnNumber: 0, $audit: { $impersonatedUsers: [ { user: \"mipsys\", db: \"admin\" } ], $impersonatedRoles: [ { role: \"dbOwner\", db: \"pgen01mipmed0\" }, { role: \"dbOwner\", db: \"data\" }, { role: \"dbOwner\", db: \"p-mipmed-as-02\" }, { role: \"dbOwner\", db: \"plau01mipmed1\" }, { role: \"dbOwner\", db: \"tdube04mipmed1\" }, { role: \"dbOwner\", db: \"pgen01mipmed1\" }, { role: \"clusterMonitor\", db: \"admin\" }, { role: \"dbOwner\", db: \"p-mipmed-as-01\" }, { role: \"dbOwner\", db: \"ignored\" }, { role: \"dbOwner\", db: \"tdube04mipmed0\" }, { role: \"dbOwner\", db: \"polt01mipmed1\" }, { role: \"mip.admin\", db: \"admin\" }, { role: \"dbOwner\", db: \"pzur01mipmed1\" }, { role: \"dbOwner\", db: \"t-mipmed-as-01\" }, { role: \"dbOwner\", db: \"mip\" }, { role: \"dbOwner\", db: \"pmado01mipmed0\" }, { role: \"dbOwner\", db: \"polt01mipmed0\" }, { role: \"dbOwner\", db: \"pzur01mipmed0\" }, { role: \"dbOwner\", db: \"pmado01mipmed1\" }, { role: \"dbOwner\", db: \"pber08mipmed1\" }, { role: \"clusterManager\", db: \"admin\" }, { role: \"dbOwner\", db: \"plau01mipmed0\" }, { role: \"dbOwner\", db: \"pber08mipmed0\" } ] } } for database 'pzur01mipmed0' on shard 'shard_03' :: caused by :: waiting for replication timed out"}}
|
{"t":{"$date":"2022-04-20T11:56:04.000+02:00"},"s":"I", "c":"SHARDING", "id":22650, "ctx":"replSetDistLockPinger","msg":"Unlocked distributed lock","attr":{"lockSessionId":{"$oid":"020000000000000000000000"},"lockName":"pzur01mipmed0.sessions#3.110-1155"}}
|
{"t":{"$date":"2022-04-20T11:56:04.022+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn8052","msg":"Slow query","attr":{"type":"command","ns":"pzur01mipmed0.$cmd","appName":"MongoDB Shell","command":{"_shardsvrRenameCollection":"sessions#3","to":"pzur01mipmed0.sessions#3.110-1155","dropTarget":false,"stayTemp":false,"databaseVersion":{"uuid":{"$uuid":"610ffe78-553e-4222-a903-679800bbc898"},"timestamp":{"$timestamp":{"t":1648837899,"i":2}},"lastMod":1},"writeConcern":{"w":"majority","wtimeout":60000},"lsid":{"id":{"$uuid":"6d981744-2bba-4841-abb7-8b755eefa491"},"uid":{"$binary":{"base64":"0+wVVtwDGKHvHj3sWREUt3H6wqvq/NkgyxQgk/ZyCQU=","subType":"0"}}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1650448502,"i":34026}},"signature":{"hash":{"$binary":{"base64":"Va6o9Oz80dDKrfn/tFR3EBPf8jU=","subType":"0"}},"keyId":7081698715102085126}},"$configTime":{"$timestamp":{"t":1650448502,"i":25023}},"$topologyTime":{"$timestamp":{"t":1648836518,"i":2}},"$audit":{"$impersonatedUsers":[{"user":"mipsys","db":"admin"}],"$impersonatedRoles":[{"role":"dbOwner","db":"pgen01mipmed0"},{"role":"dbOwner","db":"data"},{"role":"dbOwner","db":"p-mipmed-as-02"},{"role":"dbOwner","db":"plau01mipmed1"},{"role":"dbOwner","db":"tdube04mipmed1"},{"role":"dbOwner","db":"pgen01mipmed1"},{"role":"clusterMonitor","db":"admin"},{"role":"dbOwner","db":"p-mipmed-as-01"},{"role":"dbOwner","db":"ignored"},{"role":"dbOwner","db":"tdube04mipmed0"},{"role":"dbOwner","db":"polt01mipmed1"},{"role":"mip.admin","db":"admin"},{"role":"dbOwner","db":"pzur01mipmed1"},{"role":"dbOwner","db":"t-mipmed-as-01"},{"role":"dbOwner","db":"mip"},{"role":"dbOwner","db":"pmado01mipmed0"},{"role":"dbOwner","db":"polt01mipmed0"},{"role":"dbOwner","db":"pzur01mipmed0"},{"role":"dbOwner","db":"pmado01mipmed1"},{"role":"dbOwner","db":"pber08mipmed1"},{"role":"clusterManager","db":"admin"},{"role":"dbOwner","db":"plau01mipmed0"},{"role":"dbOwner","db":"pber08mipmed0"}]},"$client":{"application":{"name":"MongoDB Shell"},"driver":{"name":"MongoDB Internal Client","version":"5.0.3"},"os":{"type":"Linux","name":"Red Hat Enterprise Linux Server release 7.9 (Maipo)","architecture":"x86_64","version":"Kernel 3.10.0-1160.2.2.el7.x86_64"},"mongos":{"host":"pzur01mipmed0.swi.srse.net:27017","client":"10.229.152.20:38584","version":"5.0.3"}},"$configServerState":{"opTime":{"ts":{"$timestamp":{"t":1650448502,"i":25023}},"t":-1}},"$db":"pzur01mipmed0"},"numYields":0,"ok":0,"errMsg":"Failed command { _shardsvrRenameCollectionParticipant: \"sessions#3\", to: \"pzur01mipmed0.sessions#3.110-1155\", dropTarget: false, stayTemp: false, sourceUUID: UUID(\"ea976782-923e-4e14-9688-2d1317203230\"), writeConcern: { w: \"majority\", wtimeout: 60000 }, lsid: { id: UUID(\"2d0ee188-7a78-459a-b1d4-a9fa95012162\"), uid: BinData(0, BB89D3175FB0981C86826C27759082A37160471F60504B4612415186C630AB70) }, txnNumber: 0, $audit: { $impersonatedUsers: [ { user: \"mipsys\", db: \"admin\" } ], $impersonatedRoles: [ { role: \"dbOwner\", db: \"pgen01mipmed0\" }, { role: \"dbOwner\", db: \"data\" }, { role: \"dbOwner\", db: \"p-mipmed-as-02\" }, { role: \"dbOwner\", db: \"plau01mipmed1\" }, { role: \"dbOwner\", db: \"tdube04mipmed1\" }, { role: \"dbOwner\", db: \"pgen01mipmed1\" }, { role: \"clusterMonitor\", db: \"admin\" }, { role: \"dbOwner\", db: \"p-mipmed-as-01\" }, { role: \"dbOwner\", db: \"ignored\" }, { role: \"dbOwner\", db: \"tdube04mipmed0\" }, { role: \"dbOwner\", db: \"polt01mipmed1\" }, { role: \"mip.admin\", db: \"admin\" }, { role: \"dbOwner\", db: \"pzur01mipmed1\" }, { role: \"dbOwner\", db: \"t-mipmed-as-01\" }, { role: \"dbOwner\", db: \"mip\" }, { role: \"dbOwner\", db: \"pmado01mipmed0\" }, { role: \"dbOwner\", db: \"polt01mipmed0\" }, { role: \"dbOwner\", db: \"pzur01mipmed0\" }, { role: \"dbOwner\", db: \"pmado01mipmed1\" }, { role: \"dbOwner\", db: \"pber08mipmed1\" }, { role: \"clusterManager\", db: \"admin\" }, { role: \"dbOwner\", db: \"plau01mipmed0\" }, { role: \"dbOwner\", db: \"pber08mipmed0\" } ] } } for database 'pzur01mipmed0' on shard 'shard_03' :: caused by :: waiting for replication timed out","errName":"WriteConcernFailed","errCode":64,"reslen":1956,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":2}}},"writeConcern":{"w":"majority","wtimeout":60000,"provenance":"clientSupplied"},"remote":"10.229.152.20:53874","protocol":"op_msg","durationMillis":61116}}
|
|
|
Logging from PRIMARY Shard_03:
|
|
{"t":{"$date":"2022-04-20T11:56:03.981+02:00"},"s":"E", "c":"SHARDING", "id":5515109, "ctx":"RenameCollectionParticipantService-470","msg":"Error executing rename collection participant","attr":{"fromNs":"pzur01mipmed0.sessions#3","toNs":"pzur01mipmed0.sessions#3.110-1155","error":"WriteConcernFailed: waiting for replication timed out"}}
|
{"t":{"$date":"2022-04-20T11:56:03.981+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn5503","msg":"Slow query","attr":{"type":"command","ns":"pzur01mipmed0.$cmd","command":{"_shardsvrRenameCollectionParticipant":"sessions#3","to":"pzur01mipmed0.sessions#3.110-1155","dropTarget":false,"stayTemp":false,"sourceUUID":{"$uuid":"ea976782-923e-4e14-9688-2d1317203230"},"writeConcern":{"w":"majority","wtimeout":60000},"lsid":{"id":{"$uuid":"2d0ee188-7a78-459a-b1d4-a9fa95012162"},"uid":{"$binary":{"base64":"u4nTF1+wmByGgmwndZCCo3FgRx9gUEtGEkFRhsYwq3A=","subType":"0"}}},"txnNumber":0,"$audit":{"$impersonatedUsers":[{"user":"mipsys","db":"admin"}],"$impersonatedRoles":[{"role":"dbOwner","db":"pgen01mipmed0"},{"role":"dbOwner","db":"data"},{"role":"dbOwner","db":"p-mipmed-as-02"},{"role":"dbOwner","db":"plau01mipmed1"},{"role":"dbOwner","db":"tdube04mipmed1"},{"role":"dbOwner","db":"pgen01mipmed1"},{"role":"clusterMonitor","db":"admin"},{"role":"dbOwner","db":"p-mipmed-as-01"},{"role":"dbOwner","db":"ignored"},{"role":"dbOwner","db":"tdube04mipmed0"},{"role":"dbOwner","db":"polt01mipmed1"},{"role":"mip.admin","db":"admin"},{"role":"dbOwner","db":"pzur01mipmed1"},{"role":"dbOwner","db":"t-mipmed-as-01"},{"role":"dbOwner","db":"mip"},{"role":"dbOwner","db":"pmado01mipmed0"},{"role":"dbOwner","db":"polt01mipmed0"},{"role":"dbOwner","db":"pzur01mipmed0"},{"role":"dbOwner","db":"pmado01mipmed1"},{"role":"dbOwner","db":"pber08mipmed1"},{"role":"clusterManager","db":"admin"},{"role":"dbOwner","db":"plau01mipmed0"},{"role":"dbOwner","db":"pber08mipmed0"}]},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1650448503,"i":16004}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$configTime":{"$timestamp":{"t":1650448503,"i":5504}},"$topologyTime":{"$timestamp":{"t":1648836518,"i":2}},"$db":"pzur01mipmed0"},"numYields":0,"ok":0,"errMsg":"waiting for replication timed out","errName":"WriteConcernFailed","errCode":64,"reslen":466,"locks":{"ParallelBatchWriterMode":{"acquireCount":{"r":1}},"ReplicationStateTransition":{"acquireCount":{"w":2}},"Global":{"acquireCount":{"r":2}},"Mutex":{"acquireCount":{"r":1}}},"writeConcern":{"w":"majority","wtimeout":60000,"provenance":"clientSupplied"},"storage":{},"remote":"10.192.241.232:56702","protocol":"op_msg","durationMillis":60621}}
|
|
|
Kind Regards
Wernfried
|