Bug 159577 – Web Inspector: Lots of time spent updating related resources in ResourceDetailsSidebar when loading a page with lots of resources

• Component: Web Inspector
• Status: RESOLVED FIXED

[Joseph Pecoraro]

Created attachment 283192 [details]
[IMAGE] Profile - 2s under createResourceLink

Summary:
Lots of time spent updating ResourceDetailsSidebar when loading a page

See attached screenshot, 2s spent under createResourceLink during a reload of the inspector.

Backtrace:

- createResourceLink
    - _refreshRelatedResourcesSection
        - event dispatch
            - addInitiatedResource

[Radar WebKit Bug Importer]

<rdar://problem/27251461>

[Matt Baker]

Created attachment 283583 [details]
[Patch] Proposed Fix

[Joseph Pecoraro]

Comment on attachment 283583 [details]
[Patch] Proposed Fix

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

> Source/WebInspectorUI/UserInterface/Views/ResourceDetailsSidebarPanel.js:180
> +            this._boundRefreshRelatedResourcesSection = this.debounce(250)._refreshRelatedResourcesSection;

We chatted briefly about this. The debounce will prevent any updates if some new request goes out every 250ms or so.

If we want this to update at _at least some interval_ we would need to move off of debounce. That said, maybe debounce is fine here in practice.

[Matt Baker]

(In reply to comment #3)
> Comment on attachment 283583 [details]
> [Patch] Proposed Fix
> 
> View in context:
> https://bugs.webkit.org/attachment.cgi?id=283583&action=review
> 
> > Source/WebInspectorUI/UserInterface/Views/ResourceDetailsSidebarPanel.js:180
> > +            this._boundRefreshRelatedResourcesSection = this.debounce(250)._refreshRelatedResourcesSection;
> 
> We chatted briefly about this. The debounce will prevent any updates if some
> new request goes out every 250ms or so.
> 
> If we want this to update at _at least some interval_ we would need to move
> off of debounce. That said, maybe debounce is fine here in practice.

It's probably fine in practice, but there is definitely room for improvement. What we actually want is to throttle, rather than debounce. I'll update our utilities.

[Blaze Burg]

Comment on attachment 283583 [details]
[Patch] Proposed Fix

Clearing r?, it seems an updated patch with throttle() is planned.

[Matt Baker]

Created attachment 284391 [details]
[Patch] Proposed Fix

[Joseph Pecoraro]

Comment on attachment 284391 [details]
[Patch] Proposed Fix

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

Have I misunderstood how throttling is supposed to work with leading/trailing? My expectation was:

    - leading should mean that a call should trigger immediately if none is scheduled and the last was > delay
    - trailing should mean that the last scheduled call happens
    - cancel throttle should define what it does with the last scheduled call, either it cancels or allows the trailing call

Either way, we need tests that cover actual throttling of >1 call, to more accurately test these behaviors.

> Source/WebInspectorUI/UserInterface/Base/Utilities.js:1320
> +                let previousTime = null;
> +                let previousArguments = null;

Hmm, the "previous" confused me here.

How about:

    let lastFireTime = 0;
    let mostRecentArguments = null;

> Source/WebInspectorUI/UserInterface/Base/Utilities.js:1342
> +                                if (original[throttleTimeoutSymbol] || options.trailing === false)
> +                                    return;
> +                                original[throttleTimeoutSymbol] = setTimeout(performWork, remaining);

I do not understand this. If options.trailing === false, we only only schedule the timeout once? This doesn't feel right.

I'd expect options.trailing to be checked on cancelThrottle, to either include / exclude the last scheduled work.

> LayoutTests/inspector/unit-tests/throttle.html:21
> +                    InspectorTest.expectThat(performance.now() - startTime >= 10, "Call delayed at least 10ms.");

If there was a leading call, it should not have been delayed.

> LayoutTests/inspector/unit-tests/throttle.html:31
> +            let throttleProxy = object.throttle(10);
> +            throttleProxy.test();
> +            throttleProxy.test();
> +            throttleProxy.test();
> +            throttleProxy.test();

This doesn't match my expectation of how throttling with leading / trailing should work. I'd expect two calls here:

    let now = performance.now();
    let throttleProxy = object.throttle(10);
    throttleProxy.test(); // leading call, should trigger immediately ("now")
    throttleProxy.test(); // schedule a throttled call 10ms from the leading
    throttleProxy.test(); // already scheduled
    throttleProxy.test(); // already scheduled
    // ... trailing call should have triggered at ("now" + 10ms)

> LayoutTests/inspector/unit-tests/throttle.html:71
> +    suite.addTestCase({

I'd like to see non-basic tests that verify throttling is happening on a >1 call basis.

// Leading and Trailing:

    let now = performance.now();

    let throttleProxy = object.throttle(20);
    throttleProxy.test();
    for (let i = 0; i < 110; ++i)
        setTimeout(() => { thottleProxy.test(); }, i);
    setTimeout(() => { throttleProxy.cancelThrottle(); }, 111);

    // Expect calls at deltas from "now" of:
    [0 (leading), 20, 40, 60, 80, 100, 120 (trailing)]

// Leading and no Trailing

    let now = performance.now();

    let throttleProxy = object.throttle(20, {trailing: false});
    throttleProxy.test();
    for (let i = 0; i < 110; ++i)
        setTimeout(() => { thottleProxy.test(); }, i);
    setTimeout(() => { throttleProxy.cancelThrottle(); }, 111);

    // Expect calls at deltas from "now" of:
    [0 (leading), 20, 40, 60, 80, 100]

// No leading / trailing

    let now = performance.now();

    let throttleProxy = object.throttle(20, {leading: false, trailing: false});
    throttleProxy.test();
    for (let i = 0; i < 110; ++i)
        setTimeout(() => { thottleProxy.test(); }, i);
    setTimeout(() => { throttleProxy.cancelThrottle(); }, 111); // DEBATE: Should this cancel the trailing timer, or not?

    // Expect calls at deltas from "now" of:
    [20, 40, 60, 80, 100]

// Unusual intervals:

    let now = performance.now();

    let throttleProxy = object.throttle(20);
    throttleProxy.test();
    for (let i = 0; i < 30; ++i)
        setTimeout(() => { thottleProxy.test(); }, i);
    for (let i = 70; i < 100; ++i)
        setTimeout(() => { thottleProxy.test(); }, i);
    setTimeout(() => { throttleProxy.cancelThrottle(); }, 100); // DEBATE: Should this cancel the trailing timer, or not?

    // Expect calls at deltas from "now" of:
    [(leading) 0, 20, 40, (new leading) 70, 90, 110 (trailing)]

// Likewise, a test where throttling is cancelled after the trailing call:

    let now = performance.now();

    let throttleProxy = object.throttle(20);
    throttleProxy.test();
    for (let i = 0; i < 50; ++i)
        setTimeout(() => { thottleProxy.test(); }, i);
    setTimeout(() => { throttleProxy.cancelThrottle(); }, 100);

    // Expect calls at deltas from "now" of:
    // NOTE: The "trailing call" happened at 60, since there was no tickle between 60 and 100, the "60" was trailing the last tickle.
    [0 (leading), 20, 40, 60]

[Devin Rousso]

Created attachment 361223 [details]
Patch

Update, now that `throttle` exists.

[Joseph Pecoraro]

Comment on attachment 361223 [details]
Patch

r=me

[WebKit Commit Bot]

Comment on attachment 361223 [details]
Patch

Clearing flags on attachment: 361223

Committed r241004: <https://trac.webkit.org/changeset/241004>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.