[SERVER-29393] system.profile 'timeAcquiringMicros' value is much higher than the actual time spent Created: 27/May/17 Updated: 27/Oct/23 Resolved: 02/Jun/17 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Concurrency |
| Affects Version/s: | None |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | rocky | Assignee: | Mark Agarunov |
| Resolution: | Works as Designed | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Operating System: | ALL |
| Participants: |
| Description |
|
hi all: Pleace see below slow sql example,
|
| Comments |
| Comment by rocky [ 03/Jun/17 ] | |||||||||||||||||||||||||||
|
Hi, Mark , status: { $lt: 3 }}, batchSize: 0, projection: { _id: 1 }, sort: { time: -1 }} planSummary: IXSCAN { status: 1.0 }cursorid:635957131090 keysExamined:7 docsExamined:7 hasSortStage:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:138 locks:{ Global: { acquireCount: { r: 2 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 3928866 }}, Database: { acquireCount: { r: 1 }}, Collection: { acquireCount: { r: 1 } } } protocol:op_query 3929ms Thanks, | |||||||||||||||||||||||||||
| Comment by Mark Agarunov [ 02/Jun/17 ] | |||||||||||||||||||||||||||
|
Hello 514154167@qq.com, Thank you for providing the files. Looking over the data and logs, it appears that there may be a miscommunication as to the metric values. The timeAcquiringMicros value is in microseconds, while the millis metric is in milliseconds. From your initial example, the values are
If you convert the timeAcquiringMicros to milliseconds:
the values match as expected. Thanks, | |||||||||||||||||||||||||||
| Comment by rocky [ 02/Jun/17 ] | |||||||||||||||||||||||||||
|
hi,Mark | |||||||||||||||||||||||||||
| Comment by Mark Agarunov [ 01/Jun/17 ] | |||||||||||||||||||||||||||
|
Hello 514154167@qq.com, Thank you for providing this information. Unfortunately, without the diagnostic data and complete log files (Including the startup of mongod), the behavior is difficult to diagnose. I've created a secure upload portal so that you can upload these files privately. Any files uploaded to the portal can only be accessed by you or a MongoDB employee. To reitterate, please upload the following:
Additionally, I'd like to clarify what the 268ms response you mentioned is related to. Is this from the application or from MongoDB? Thanks, | |||||||||||||||||||||||||||
| Comment by rocky [ 01/Jun/17 ] | |||||||||||||||||||||||||||
|
hi Mark, Thanks & Best regards, 1.one document:
2.The complete logs
| |||||||||||||||||||||||||||
| Comment by Mark Agarunov [ 30/May/17 ] | |||||||||||||||||||||||||||
|
Hello 514154167@qq.com, Thank you for the report. To better investigate the behavior you've described, I'd like to request some additional information. Could you please provide the following:
Thanks, |