Today, the slow query log includes a field called durationMillis that measures the amount of time spent executing the command/query. This does not include time spent refreshing the AuthorizationSession at the start of the operation (which is included in userCacheWaitTimeMicros) and time spent parsing the command itself.

Customers and TSEs seem to rely on durationMillis to get a sense of the wall clock time elapsed for an operation to be fully processed by the server. Unfortunately, this is not the case as a command can take a long time to complete if the AuthorizationSession needs to be refreshed and the backing user store is very slow (e.g., LDAP). In these cases, durationMillis is low as long as the command executed quickly but the overall response time was slow.

In an effort to prevent changing the meaning of durationMillis, we can introduce a new field called totalOperationTime intended to capture the total wall clock time of an operation and include it in the slow query logs.