I tried to find any documentation about how the chunk movements can be traced with any verbosity, but this seems nowhere documented.
The chunk migrations (empty chunks, zero documents in them) of newly created collections still go horribly slow, nearly granted to a halt (one migration every 15mins or so).
Still, there is zero other activity on my cluster, we cannot use it until those new collections are ready with their chunks on the right shard servers.
MongoDB server version is 4.4.0
The logs of the router servers show:
...
{"t":{"$date":"2020-08-31T06:25:09.557+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn357","msg":"Slow query","attr":{"type":"command","ns":"_KEYHOLE_88800.$cmd","command":{"dbStats":1,"lsid":{"id":{"$uuid":"b8998ee1-a8d9-46be-ba84-d0d1c40b19bd"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1598847907,"i":4}},"signature":{"keyId":6821045628173287455,"hash":{"$binary":"base64":"7ks/HUkgj+LvEKYINCIfalrKvVU=","subType":"0"}}}},"$db":"_KEYHOLE_88800"},"numYields":0,"reslen":11324,"protocol":"op_query","durationMillis":1216}}
{"t":{"$date":"2020-08-31T06:25:09.794+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn357","msg":"Slow query","attr":{"type":"command","ns":"admin.$cmd","command":{"dbStats":1,"lsid":{"id":{"$uuid":"b8998ee1-a8d9-46be-ba84-d0d1c40b19bd"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1598847908,"i":1}},"signature":{"keyId":6821045628173287455,"hash":{"$binary":"base64":"n4DO3e0Xx2Fv0taEA1k7CqkR97U=","subType":"0"}}}},"$db":"admin"},"numYields":0,"reslen":11630,"protocol":"op_query","durationMillis":234}}
{"t":{"$date":"2020-08-31T06:25:12.726+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn357","msg":"Slow query","attr":{"type":"command","ns":"cdrarch.$cmd","command":{"dbStats":1 ,"lsid":{"id":{"$uuid":"b8998ee1-a8d9-46be-ba84-d0d1c40b19bd"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1598847909,"i":3}},"signature":{"keyId":6821045628173287455,"hash":{"$binary":{"base64":"RaCGq/SXVR7wYB7Nb0L/G+R2OfI=","subType":"0"}}}},"$db":"cdrarch"},"numYields":0,"reslen":11718,"protocol":"op_query","durationMillis":2930}}
{"t":{"$date":"2020-08-31T06:25:14.738+02:00"},"s":"I", "c":"SHARDING", "id":20997, "ctx":"Uptime-reporter","msg":"Refreshed RWC defaults","attr":{"newDefaults":{}}}
{"t":{"$date":"2020-08-31T06:25:15.631+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn357","msg":"Slow query","attr":{"type":"command","ns":"config.$cmd","command":{"dbStats":1,"lsid":{"id":{"$uuid":"b8998ee1-a8d9-46be-ba84-d0d1c40b19bd"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1598847912,"i":1}},"signature":{"keyId":6821045628173287455,"hash":{"$binary":{"base64":"XJgwP/q5znnKbcpFEEaobUrBeF4=","subType":"0"}}}},"$db":"config"},"numYields":0,"reslen":11666,"protocol":"op_query","durationMillis":2902}}
{"t":{"$date":"2020-08-31T06:25:16.460+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn357","msg":"Slow query","attr":{"type":"command","ns":"_KEYHOLE_88800.$cmd","command":{"dbStats":1,"lsid":{"id":{"$uuid":"b8998ee1-a8d9-46be-ba84-d0d1c40b19bd"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1598847915,"i":2}},"signature":{"keyId":6821045628173287455,"hash":{" $binary":{"base64":"7M14WAvT4WlyqOnFwnuTbCiPLdQ=","subType":"0"}}}},"$db":"_KEYHOLE_88800"},"numYields":0,"reslen":11324,"protocol":"op_query","durationMillis":120}}
{"t":{"$date":"2020-08-31T06:25:24.746+02:00"},"s":"I", "c":"SHARDING", "id":20997, "ctx":"Uptime-reporter","msg":"Refreshed RWC defaults","attr":{"newDefaults":{}}}
...
{"t":{"$date":"2020-08-31T06:35:19.076+02:00"},"s":"I", "c":"COMMAND", "id":51803, "ctx":"conn142636","msg":"Slow query","attr":{"type":"command","ns":"cdrarch.cdr_af_20200830","appName":"MongoDB Shell","command":{"moveChunk":"cdrarch.cdr_af_20200830","find":{"SHARD_MINSEC":608.0},"to":"db_rs033","_waitForDelete":true,"lsid":{"id":{"$uuid":"f734929b-2bc9-4c58-ab1b-a5027730cb7e"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1598847531,"i":2}},"signature":{"hash":{"$binary":"base64":"AvmYRG2AnH4Ui6mH7I22bm4c64w=","subType":"0"}},"keyId":6821045628173287455}},"$db":"admin"},"numYields":0,"reslen":175,"protocol":"op_msg","durationMillis":987521}}
{"t":{"$date":"2020-08-31T06:35:19.485+02:00"},"s":"I", "c":"SH_REFR", "id":24104, "ctx":"ConfigServerCatalogCacheLoader-1495","msg":"Refreshed cached collection","attr":{"namespace":"cdrarch.cdr_af_20200830","newVersion":{"0":{"$timestamp":{"t":3910,"i":1}},"1":{"$oid":"5f46d8b6da305f92f9b46bdf"}},"oldVersion":" from version 3909|1||5f46d8b6da305f92f9b46bdf","durationMillis":7}}
So you see that the “moveChunk” command took nearly 1000 secs.