[SERVER-54571] queryHash and planCacheKey Fields Absent in getMore Requests Created: 15/Feb/21  Updated: 29/Oct/23  Resolved: 19/Aug/21

Status: Closed
Project: Core Server
Component/s: Aggregation Framework, Diagnostics, Logging, Querying
Affects Version/s: 4.2.12, 4.4.4
Fix Version/s: 5.1.0-rc0

Type: Improvement Priority: Major - P3
Reporter: Diego Rodriguez (Inactive) Assignee: Mickey Winters
Resolution: Fixed Votes: 3
Labels: neweng
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Documented
is documented by DOCS-14927 Investigate changes in SERVER-54571: ... Closed
Backwards Compatibility: Fully Compatible
Backport Requested:
v5.0, v4.4, v4.2
Sprint: Query Execution 2021-05-31, Query Execution 2021-06-14, Query Execution 2021-06-28, Query Execution 2021-07-12, Query Execution 2021-07-26, QE 2021-08-09, QE 2021-08-23
Participants:

 Description   

Hi Team,

Starting in v4.2, MongoDB introduced the queryHash and planCacheKey that respectively help identify slow queries with the same query shape and the plan cache entry associated with the query.

Said fields are present in the log from the initial batch for a "slow" query:

{
  "type": "command",
  "ns": "test.foo",
  "appName": "MongoDB Shell",
  "command": {
    "find": "foo",
    "filter": {
      "a": 1
    },
    "lsid": {
      "id": {
        "$uuid": "564cec84-a387-4fa5-9f50-97eafe97efde"
      }
    },
    "$db": "test"
  },
  "planSummary": "IXSCAN { a: 1 }",
  "cursorid": 8918754329959567000,
  "keysExamined": 101,
  "docsExamined": 101,
  "numYields": 0,
  "nreturned": 101,
  "queryHash": "4B53BE76",
  "planCacheKey": "100FCEBA",
  "reslen": 3825,
  "locks": {
    "ReplicationStateTransition": {
      "acquireCount": {
        "w": 1
      }
    },
    "Global": {
      "acquireCount": {
        "r": 1
      }
    },
    "Database": {
      "acquireCount": {
        "r": 1
      }
    },
    "Collection": {
      "acquireCount": {
        "r": 1
      }
    },
    "Mutex": {
      "acquireCount": {
        "r": 1
      }
    }
  },
  "storage": {
    "data": {
      "bytesRead": 2013,
      "timeReadingMicros": 3
    }
  },
  "protocol": "op_msg",
  "durationMillis": 1
}

But are absent from any subsequent getMore requests:

{
  "type": "command",
  "ns": "test.foo",
  "appName": "MongoDB Shell",
  "command": {
    "getMore": 8918754329959567000,
    "collection": "foo",
    "lsid": {
      "id": {
        "$uuid": "564cec84-a387-4fa5-9f50-97eafe97efde"
      }
    },
    "$db": "test"
  },
  "originatingCommand": {
    "find": "foo",
    "filter": {
      "a": 1
    },
    "lsid": {
      "id": {
        "$uuid": "564cec84-a387-4fa5-9f50-97eafe97efde"
      }
    },
    "$db": "test"
  },
  "planSummary": "IXSCAN { a: 1 }",
  "cursorid": 8918754329959567000,
  "keysExamined": 276,
  "docsExamined": 276,
  "cursorExhausted": true,
  "numYields": 0,
  "nreturned": 276,
  "reslen": 10474,
  "locks": {
    "ReplicationStateTransition": {
      "acquireCount": {
        "w": 1
      }
    },
    "Global": {
      "acquireCount": {
        "r": 1
      }
    },
    "Database": {
      "acquireCount": {
        "r": 1
      }
    },
    "Collection": {
      "acquireCount": {
        "r": 1
      }
    },
    "Mutex": {
      "acquireCount": {
        "r": 1
      }
    }
  },
  "storage": {},
  "protocol": "op_msg",
  "durationMillis": 0
}

This happens for both find and aggregate operations in both v4.2.12 and v4.4.4.

It would be nice to have these fields present in the getMore requests as not having them makes troubleshooting more difficult and/or inaccurate when using those fields as an analysis criteria, for example:

  1. We might miss the getMore requests.
  2. We might miss a query shape in its entirety if the first batch is slow and the slowness is only observed in subsequent getMore requests.

Regards
Diego



 Comments   
Comment by Vivian Ge (Inactive) [ 06/Oct/21 ]

Updating the fixversion since branching activities occurred yesterday. This ticket will be in rc0 when it’s been triggered. For more active release information, please keep an eye on #server-release. Thank you!

Comment by Githook User [ 19/Aug/21 ]

Author:

{'name': 'Mickey. J Winters', 'email': 'mickey.winters@mongodb.com', 'username': 'mjrb'}

Message: SERVER-54571 Add queryHash and planCacheKey fields to getMore request slow query logs
Branch: master
https://github.com/mongodb/mongo/commit/093eeacde2f5a2c84dbf9ac22ea851ac4471e3e4

Generated at Thu Feb 08 05:33:54 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.