[SERVER-57474] profile_operation_metrics.js not resilient to query yielding Created: 04/Jun/21  Updated: 29/Oct/23  Resolved: 15/Jul/21

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 5.0.0, 5.1.0
Fix Version/s: 5.0.2, 5.1.0-rc0

Type: Bug Priority: Major - P3
Reporter: Gregory Wlodarek Assignee: Gregory Wlodarek
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Depends
Related
is related to SERVER-57501 Disable profile_operation_metrics.js ... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Backport Requested:
v5.0
Sprint: Execution Team 2021-06-28, Execution Team 2021-07-12, Execution Team 2021-07-26
Participants:
Linked BF Score: 152

 Description   

When running profile_operation_metrics.js, it's possible for queries to yield. Each yield results in the cursorSeeks metric being incremented. There's a build failure on the debug variants experiencing this behaviour, specifically the findIxScanAndFetch test in profile_operation_metrics.js.

On a successful run, where there's no yielding, there are 2 cursorSeeks. This is what the test expects.

[conn1] "Slow query","attr":{"type":"command","ns":"profile_operation_metrics.coll","appName":"MongoDB Shell","command":{"find":"coll","filter":{"_id":1},"lsid":{"id":{"$uuid":"a910abbe-144f-45a6-86b3-efa816fc27ab"}},"$db":"profile_operation_metrics"},"planSummary":"IXSCAN { _id: 1 }","keysExamined":1,"docsExamined":1,"fromMultiPlanner":true,"cursorExhausted":true,"numYields":0,"nreturned":1,"reslen":151,"locks":{"Global":{"acquireCount":{"r":3}},"Mutex":{"acquireCount":{"r":3}}},"storage":{},"operationMetrics":{"docBytesRead":29,"docUnitsRead":1,"idxEntryBytesRead":3,"idxEntryUnitsRead":1,"docUnitsReturned":1,"cursorSeeks":2,"cpuNanos":4718330},"remote":"127.0.0.1:44910","protocol":"op_msg","durationMillis":4}

But when there's a yield, there are 3 cursorSeeks, causing the test to fail.

[conn1] "Slow query","attr":{"type":"command","ns":"profile_operation_metrics.coll","appName":"MongoDB Shell","command":{"find":"coll","filter":{"_id":1},"lsid":{"id":{"$uuid":"ebdfd9b7-35b7-429a-aba5-315b45fef51f"}},"$db":"profile_operation_metrics"},"planSummary":"IXSCAN { _id: 1 }","keysExamined":1,"docsExamined":1,"fromMultiPlanner":true,"cursorExhausted":true,"numYields":1,"nreturned":1,"reslen":151,"locks":{"Global":{"acquireCount":{"r":6}},"Mutex":{"acquireCount":{"r":5}}},"storage":{},"operationMetrics":{"docBytesRead":29,"docUnitsRead":1,"idxEntryBytesRead":3,"idxEntryUnitsRead":1,"docUnitsReturned":1,"cursorSeeks":3,"cpuNanos":6101484},"remote":"127.0.0.1:43070","protocol":"op_msg","durationMillis":27}



 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 [ 23/Jul/21 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57474 profile_operation_metrics.js queries yield less frequently

(cherry picked from commit cd1dde2d12606e2a5496bb5aad72ad1d0aa891d4)
Branch: v5.0
https://github.com/mongodb/mongo/commit/813087e4984d65e903a7ff98ae28799fac3fef88

Comment by Githook User [ 15/Jul/21 ]

Author:

{'name': 'Gregory Wlodarek', 'email': 'gregory.wlodarek@mongodb.com', 'username': 'GWlodarek'}

Message: SERVER-57474 profile_operation_metrics.js queries yield less frequently
Branch: master
https://github.com/mongodb/mongo/commit/cd1dde2d12606e2a5496bb5aad72ad1d0aa891d4

Comment by Gregory Wlodarek [ 07/Jun/21 ]

This test will be disabled by SERVER-57501 until a fix is found.

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