Investigate changes in SERVER-112619: Enable slow in progress query logs by default

    • Type: Investigation
    • Resolution: Unresolved
    • Priority: Major - P3
    • None
    • Affects Version/s: None
    • Component/s: None
    • None
    • None
    • Developer Tools

      Original Downstream Change Summary

      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.

            Assignee:
            Unassigned
            Reporter:
            Backlog - Core Eng Program Management Team
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated: