Bug 145090 - Web Inspector: TimelineAgent needs to handle nested runloops
Summary: Web Inspector: TimelineAgent needs to handle nested runloops
Status: RESOLVED FIXED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Web Inspector (show other bugs)
Version: 528+ (Nightly build)
Hardware: All All
: P2 Normal
Assignee: Matt Baker
URL:
Keywords: InRadar
: 145089 (view as bug list)
Depends on:
Blocks: 145695
  Show dependency treegraph
 
Reported: 2015-05-15 20:05 PDT by Matt Baker
Modified: 2015-06-19 16:36 PDT (History)
11 users (show)

See Also:


Attachments
[Patch] Proposed Fix (4.54 KB, patch)
2015-05-18 10:03 PDT, Matt Baker
no flags Details | Formatted Diff | Diff
Archive of layout-test-results from ews101 for mac-mavericks (654.86 KB, application/zip)
2015-05-18 11:24 PDT, Build Bot
no flags Details
[Patch] Proposed Fix (5.76 KB, patch)
2015-06-19 14:48 PDT, Matt Baker
no flags Details | Formatted Diff | Diff
[Patch] Proposed Fix (8.89 KB, patch)
2015-06-19 14:55 PDT, Matt Baker
no flags Details | Formatted Diff | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description Matt Baker 2015-05-15 20:05:36 PDT
* SUMMARY
TimelineAgent needs to handle nested runloops.

Pausing script execution in the Web Inspector starts a nested runloop, which causes the TimelineAgent to pop the current rendering frame record before the outer runloop completes. We should track the runloop nesting level, and only push/pop rendering frame records when the stack depth is zero.

* STEPS TO REPRODUCE
Run the following inspector test: LayoutTests/inspector/timeline/debugger-paused-while-recording.html
Comment 1 Radar WebKit Bug Importer 2015-05-15 20:05:50 PDT
<rdar://problem/20986375>
Comment 2 Matt Baker 2015-05-15 20:21:50 PDT
*** Bug 145089 has been marked as a duplicate of this bug. ***
Comment 3 Matt Baker 2015-05-18 10:03:25 PDT
Created attachment 253329 [details]
[Patch] Proposed Fix
Comment 4 Build Bot 2015-05-18 11:24:37 PDT
Comment on attachment 253329 [details]
[Patch] Proposed Fix

Attachment 253329 [details] did not pass mac-ews (mac):
Output: http://webkit-queues.appspot.com/results/5030757328224256

New failing tests:
platform/mac/fast/text/font-weights.html
Comment 5 Build Bot 2015-05-18 11:24:40 PDT
Created attachment 253333 [details]
Archive of layout-test-results from ews101 for mac-mavericks

The attached test failures were seen while running run-webkit-tests on the mac-ews.
Bot: ews101  Port: mac-mavericks  Platform: Mac OS X 10.9.5
Comment 6 Joseph Pecoraro 2015-05-18 14:34:42 PDT
Comment on attachment 253329 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=253329&action=review

A subtle comment, otherwise I'm fine with this.

> Source/WebCore/inspector/InspectorTimelineAgent.cpp:170
> +        m_runLoopNestingLevel--;
> +        if (!m_runLoopNestingLevel)
> +            didCompleteCurrentRecord(TimelineRecordType::RenderingFrame);

I think this should be wrapped in a block / comment to prevent decrementing the counter below 0:

    // Avoid dropping below 0. If we are already at 0, then we are leaving a nested run loop we were not aware of.
    if (m_runLoopNestingLevel) {
        m_runLoopNestingLevel--;
        if (!m_runLoopNestingLevel)
            didCompleteCurrentRecord(TimelineRecordType::RenderingFrame);
    }

See comment below for how I think this might happen.  Normally this would be an ASSERT, but I don't think this is actually something we can know, so we just need to handle whatever happens gracefully.

> Source/WebCore/inspector/InspectorTimelineAgent.cpp:179
> +    m_runLoopNestingLevel = 1;

This deserves a comment. We are assuming we are in a single run loop, and not currently running in a nested run loop. I'm not sure if that is technically accurate.

For instance, would our nesting level be non-1 if we:

  1. Pause on a breakpoint
  2. Start a Timeline Recording (thus triggering InspectorTimelineAgent::internalStart)

I think then, the StopRunLoop handler will still decrement m_runLoopNestingLevel and likely end up in problematic territory.

> Source/WebCore/inspector/InspectorTimelineAgent.cpp:205
> +    if (m_runLoopNestingLevel) {
> +        m_runLoopNestingLevel = 0;

No need for the if, just an assignment is clearer.
Comment 7 Mark Lam 2015-06-05 12:00:14 PDT
Matt, I skipped tests in r185259: <http://trac.webkit.org/r185259> which are blocked on this bug.

You might want to take a look at those tests and see if they already satisfy the testing requirement for your patch.  If so, you can just unskip the tests and land your patch.
Comment 8 Matt Baker 2015-06-19 12:13:58 PDT
Comment on attachment 253329 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=253329&action=review

>> Source/WebCore/inspector/InspectorTimelineAgent.cpp:170
>> +            didCompleteCurrentRecord(TimelineRecordType::RenderingFrame);
> 
> I think this should be wrapped in a block / comment to prevent decrementing the counter below 0:
> 
>     // Avoid dropping below 0. If we are already at 0, then we are leaving a nested run loop we were not aware of.
>     if (m_runLoopNestingLevel) {
>         m_runLoopNestingLevel--;
>         if (!m_runLoopNestingLevel)
>             didCompleteCurrentRecord(TimelineRecordType::RenderingFrame);
>     }
> 
> See comment below for how I think this might happen.  Normally this would be an ASSERT, but I don't think this is actually something we can know, so we just need to handle whatever happens gracefully.

It shouldn't be possible for the nesting level to drop below zero, but I'll add an ASSERT as the same. See comment below.

>> Source/WebCore/inspector/InspectorTimelineAgent.cpp:179
>> +    m_runLoopNestingLevel = 1;
> 
> This deserves a comment. We are assuming we are in a single run loop, and not currently running in a nested run loop. I'm not sure if that is technically accurate.
> 
> For instance, would our nesting level be non-1 if we:
> 
>   1. Pause on a breakpoint
>   2. Start a Timeline Recording (thus triggering InspectorTimelineAgent::internalStart)
> 
> I think then, the StopRunLoop handler will still decrement m_runLoopNestingLevel and likely end up in problematic territory.

The runloop nesting level is relative to the runloop from which the debugging runloop executes. In the above example internalStart is executing in a nested runloop, but as long as the nesting level isn't updated while paused in the debugger the nesting level won't drop below zero.
Comment 9 Matt Baker 2015-06-19 12:15:28 PDT
(In reply to comment #7)
> Matt, I skipped tests in r185259: <http://trac.webkit.org/r185259> which are
> blocked on this bug.
> 
> You might want to take a look at those tests and see if they already satisfy
> the testing requirement for your patch.  If so, you can just unskip the
> tests and land your patch.

Looks like we don't need a separate test for this. Tests which execute the debugger will cover nested runloop cases.
Comment 10 Matt Baker 2015-06-19 12:19:51 PDT
(In reply to comment #9)
> (In reply to comment #7)
> > Matt, I skipped tests in r185259: <http://trac.webkit.org/r185259> which are
> > blocked on this bug.
> > 
> > You might want to take a look at those tests and see if they already satisfy
> > the testing requirement for your patch.  If so, you can just unskip the
> > tests and land your patch.
> 
> Looks like we don't need a separate test for this. Tests which execute the
> debugger will cover nested runloop cases.

I meant to say "Inspector tests which exercise the debugger". The tests in <http://trac.webkit.org/r185259> meet that requirement.
Comment 11 Matt Baker 2015-06-19 14:48:20 PDT
Created attachment 255228 [details]
[Patch] Proposed Fix
Comment 12 Matt Baker 2015-06-19 14:55:11 PDT
Created attachment 255232 [details]
[Patch] Proposed Fix
Comment 13 Joseph Pecoraro 2015-06-19 15:41:28 PDT
Comment on attachment 255232 [details]
[Patch] Proposed Fix

View in context: https://bugs.webkit.org/attachment.cgi?id=255232&action=review

Much better! r=me

> LayoutTests/TestExpectations:-527
> -webkit.org/b/145090 inspector/debugger/break-on-exception.html [ Skip ]

I'm not sure you can unstop tests. That would be nice but they are frequently flakey, likely an issue in the test harness.
Comment 14 Mark Lam 2015-06-19 15:45:35 PDT
(In reply to comment #13)
> I'm not sure you can unstop tests. That would be nice but they are
> frequently flakey, likely an issue in the test harness.

There is still a global skip of inspector/debugger (I think) fir the flakiness issue.  So unskipping these specific tests is the right thing to do (since they were blocked on this bug).
Comment 15 Matt Baker 2015-06-19 15:50:03 PDT
(In reply to comment #14)
> (In reply to comment #13)
> > I'm not sure you can unstop tests. That would be nice but they are
> > frequently flakey, likely an issue in the test harness.
> 
> There is still a global skip of inspector/debugger (I think) fir the
> flakiness issue.  So unskipping these specific tests is the right thing to
> do (since they were blocked on this bug).

Correct. From TestExpectations:
92: # These tests still mysteriously flake and/or time out.
93: webkit.org/b/137131 inspector/debugger [ Skip ]
Comment 16 Joseph Pecoraro 2015-06-19 16:06:52 PDT
Comment on attachment 255232 [details]
[Patch] Proposed Fix

Oops. kk!
Comment 17 WebKit Commit Bot 2015-06-19 16:36:37 PDT
Comment on attachment 255232 [details]
[Patch] Proposed Fix

Clearing flags on attachment: 255232

Committed r185777: <http://trac.webkit.org/changeset/185777>
Comment 18 WebKit Commit Bot 2015-06-19 16:36:42 PDT
All reviewed patches have been landed.  Closing bug.