-
Type:
Investigation
-
Resolution: Unresolved
-
Priority:
Major - P3
-
None
-
Affects Version/s: None
-
Component/s: None
-
None
-
None
-
Developer Tools
There are several changes that are now enabled with this commit:
1. New log component and query log line: Slow in-progress query.
Example line:
{"t":{"$date":"2025-10-27T15:50:57.115+00:00"},"s":"I", "c":"SLOWPROG", "id":1794200, "ctx":"conn1","msg":"Slow in-progress query","attr":{"type":"remove","isFromUserConnection":true,"ns":"log_slow_in_progress_queries.test","collectionType":"normal","appName":"MongoDB Shell","command":{"q":{"a":{"$gte":0}},"limit":0,"comment":"Delete Index Scan"},"planSummary":"IXSCAN { a: 1 }","planningTimeMicros":977,"keysDeleted":20,"numYields":1,"planCacheShapeHash":"FA029766","queryHash":"FA029766","planCacheKey":"E8D26CBF","locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"w":1}},"Database":{"acquireCount":{"w":1}},"Collection":{"acquireCount":{"w":1}}},"flowControl":{"acquireCount":1},"storage":{"timeWaitingMicros":{"storageEngineMicros":81}},"cpuNanos":2913587,"remote":"127.0.0.1:51332","queues":{"ingress":{"admissions":1},"execution":{"admissions":2}},"workingMillis":2,"durationMillis":3}}
Because the query that is being logged is still running, there are less information than in a regular "Slow query" logs. For example there are no docs/keysExamined field. We plan to iterate on this in the future.
The query is logged at most once if it's duration cross slowOpInProgressThreshold.
The query is checked for this during yielding, so if a query doesn't yield or check for interrupt, than it won't be logged (this is considered a bug and should be fixed).
2. New profiler setting: slowOpInProgressThreshold
This setting is a part of database-specific profiling settings and can be set using profile command:
db.setProfilingLevel(0, {slowinprogms: 0})
This setting controls the threshold at which queries are logged even during execution.
3. New command line / configuration option:
--defaultSlowInProgMS / operationProfiling.slowOpInProgressThresholdMs
The default amount of milliseconds after which a query should be logged while it is still in-progress.
If there are no profiling settings for a database, this value will be used to determine when to log a long-running query.
Default value: 5000 ms.
With this value we statistically log ~10 time less queries than a regular slow query log.
Description of Linked Ticket
In SERVER-17942 we have introduced a new log line: "Slow in-progress query".
New line was put into a separate log component and it was printed at debug(1) severity, so it can be disabled by setting verbosity of the component to 0.
However, now this line is disabled by default.
In this ticket we need to enable it by default.
And the best way for that seems to support a default log component verbosity mechanism.
- depends on
-
SERVER-112619 Enable slow in progress query logs by default
-
- Closed
-
-
SERVER-113243 Optionally return log lines caused by a command on the command response
-
- Needs Verification
-