Uploaded image for project: 'Documentation'
  1. Documentation
  2. DOCS-13131

cursor.maxTimeMS should explain how terminated operations are logged

    XMLWordPrintableJSON

Details

    Description

      Description

      The cursor.maxTimeMS Behavior section doesn't explain what is reported in the logs.

      At least in 3.6.12, there will be a log entry with errmsg: "operation exceeded time limit" such as:

      2019-10-15T20:02:11.341+0100 I COMMAND  [conn636131] command myDb.myColl command: aggregate { aggregate: "myColl", pipeline: [... ], allowDiskUse: true, fromMongos: true, cursor: { batchSize: 101 }, maxTimeMS: 5000, shardVersion: [ Timestamp(19622, 240811), ObjectId('5705031ca624b38123a80989') ], $clusterTime: { clusterTime: Timestamp(0, 0), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, ... $db: "myDb" } planSummary: IXSCAN { ... } exception: Error in $cursor stage :: caused by :: errmsg: "operation exceeded time limit" code:ExceededTimeLimit numYields:241 reslen:276 locks:{ Global: { acquireCount: { r: 586 } }, Database: { acquireCount: { r: 293 } }, Collection: { acquireCount: { r: 293 } } } protocol:op_msg 5011ms
      

      It's useful to know that this is logged with this message so we can search for this type of slow query.

      Scope of changes

      Impact to Other Docs

      MVP (Work and Date)

      Resources (Scope or Design Docs, Invision, etc.)

      Attachments

        Activity

          People

            Unassigned Unassigned
            nicholas.cottrell@mongodb.com Nic Cottrell
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

            Dates

              Created:
              Updated:
              1 year, 14 weeks, 2 days ago