Major - P3 In this slow query log message, the planningTimeMicros comes positionally last. The durationMillis has always come at the end of each log line for as long as I can tell. This changes a long-held convention in the server logs, and clutters the most visually-important part of the log message.
2022-12-20T04:47:49.330+00:00 I COMMAND 51803 [conn451] "Slow query","attr":{"type":"command","ns":"test30_fsmdb0.auth_privilege_cache_miss_user","appName":"MongoDB Shell","command":{"dropUser":"auth_privilege_cache_miss_user","writeConcern":{"w":"majority","wtimeout":600000},"lsid":{"id":{"$uuid":"10244ba1-1d91-4472-b1cf-e9626c47382c"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1671511668,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$db":"test30_fsmdb0"},"numYields":0,"reslen":163,"readConcern":{"level":"local","provenance":"implicitDefault"},"remote":"127.0.0.1:43380","protocol":"op_msg","durationMillis":564,"planningTimeMicros":0}
We should move this metric so that it is printed earlier and, like many other statistics, we should avoid logging the planning time if it is zero.