[SERVER-19312] Field 'executionTimeMillis' missing from explain execution stats output Created: 24/Apr/15 Updated: 05/Feb/16 Resolved: 08/Jul/15 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Querying |
| Affects Version/s: | None |
| Fix Version/s: | 3.1.6 |
| Type: | Bug | Priority: | Minor - P4 |
| Reporter: | Spencer Brody (Inactive) | Assignee: | Qingyang Chen |
| Resolution: | Done | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Attachments: |
|
| Backwards Compatibility: | Fully Compatible |
| Operating System: | ALL |
| Sprint: | Quint Iteration 4, Quint Iteration 5, Quint Iteration 6 |
| Participants: |
| Description |
|
22596ecf7f OS X 10.8 jsCore
|
| Comments |
| Comment by Githook User [ 08/Jul/15 ] |
|
Author: {u'username': u'coollog', u'name': u'Qingyang Chen', u'email': u'qingyang.chen@10gen.com'}Message: |
| Comment by J Rassi [ 06/Jul/15 ] |
|
Q, I think you're confusing the following two facts:
I believe that my analysis above is correct; let me know if you're still confused even after reading this clarification. |
| Comment by Qingyang Chen [ 06/Jul/15 ] |
|
It seems that Explain::generateExecStats already handles negative values for totalTimeMillis, so would it be better to just change the core/explain2.js to use explain.executionStats.executionTimeMillisEstimate if explina.executionStats.executionTimeMillis is not defined? |
| Comment by Spencer Brody (Inactive) [ 29/Apr/15 ] |
|
Changing priority to "minor" to get it out of the "needs triage" bucket in the buildbaron dashboard. |
| Comment by J Rassi [ 28/Apr/15 ] |
|
The root cause of this failure is that Explain::explainStages() does not expect CurOp::elapsedMillis() to return a negative value. I conclude that, during execution of this test, this machine's system administrator (or a script) set the system clock to be earlier than the current time. I would recommend the following as a fix:
As an alternative, we could make the CurOp "elapsed time" methods return an elapsed time of zero if the second call to curTimeMicros64() returns a smaller value than the first call. |
| Comment by Spencer Brody (Inactive) [ 28/Apr/15 ] |
|
Bumping to critical even though the test hasn't failed again in a while because they way it failed was that explain was missing an expected field, which seems bad and probably worth looking into. |
| Comment by Spencer Brody (Inactive) [ 24/Apr/15 ] |
|
Looks like the explain output has executionTimeMillisEstimate but not executionTimeMillis for some reason? |