[SERVER-72270] Move planningTimeMicros so that it does not come last in slow query logs Created: 20/Dec/22  Updated: 29/Oct/23  Resolved: 06/Jan/23

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 6.3.0-rc0

Type: Improvement Priority: Major - P3
Reporter: Louis Williams Assignee: James Wahlin
Resolution: Fixed Votes: 2
Labels: neweng
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Assigned Teams:
Query Optimization
Backwards Compatibility: Fully Compatible
Sprint: QO 2023-01-09
Participants:

 Description   

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.



 Comments   
Comment by Githook User [ 05/Jan/23 ]

Author:

{'name': 'James Wahlin', 'email': 'james@mongodb.com', 'username': 'jameswahlin'}

Message: SERVER-72270 Move planningTimeMicros so that it does not come last in slow query logs
Branch: master
https://github.com/mongodb/mongo/commit/c2b1796123a27c0e7e2f8c01a4411568d7d5dad2

Generated at Thu Feb 08 06:21:18 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.