Bug 152418 - Web Inspector: Make WebInspector.ConsoleMessageView faster
Summary: Web Inspector: Make WebInspector.ConsoleMessageView faster
Status: RESOLVED CONFIGURATION CHANGED
Alias: None
Product: WebKit
Classification: Unclassified
Component: Web Inspector (show other bugs)
Version: WebKit Local Build
Hardware: All All
: P2 Normal
Assignee: Nobody
URL:
Keywords: InRadar
Depends on: 152422
Blocks: 152220
  Show dependency treegraph
 
Reported: 2015-12-17 21:49 PST by Nikita Vasilyev
Modified: 2019-01-13 17:33 PST (History)
4 users (show)

See Also:


Attachments
[Image] Stacktrace in Timelines (407.36 KB, image/png)
2015-12-17 21:49 PST, Nikita Vasilyev
no flags Details
[Image] _clearFocusableChildren (167.59 KB, image/png)
2015-12-17 23:14 PST, Nikita Vasilyev
no flags Details
[Image] Timelines (384.13 KB, image/png)
2019-01-13 17:31 PST, Nikita Vasilyev
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Nikita Vasilyev 2015-12-17 21:49:31 PST
Created attachment 267609 [details]
[Image] Stacktrace in Timelines

Web Inspector spends on average takes 23ms in WebInspector.ConsoleMessageView [1].
It's too slow to add one message per every requestAnimationFrame.

1: JS code used:

    console.info(Math.random())

I'm running this on MacBook Pro 2.8 GHz i7, mid 2014.
Comment 1 Nikita Vasilyev 2015-12-17 22:04:42 PST
(In reply to comment #0)
> Created attachment 267609 [details]
> [Image] Stacktrace in Timelines

This timeline recording shows that _appendLocationLink takes 23.13ms
out of 23.43ms of ConsoleMessageView execution time. That's 98.7%!
98.7% of ConsoleMessageView execution time spent on adding the source link.

I don't understand what happens in addEventListener selected on the image.
Timelines doesn't tell me why *adding* an event listener takes so long.
Comment 2 Nikita Vasilyev 2015-12-17 23:14:35 PST
Created attachment 267612 [details]
[Image] _clearFocusableChildren

Less severe bottleneck is querySelectorAll("[tabindex]"):

    _clearFocusableChildren()
    {
        var focusableElements = this.messagesElement.querySelectorAll("[tabindex]");
        for (var i = 0, count = focusableElements.length; i < count; ++i)
            focusableElements[i].removeAttribute("tabindex");
    }

It's called twice for every didAppendConsoleMessageView.
Comment 3 Nikita Vasilyev 2015-12-17 23:17:27 PST
And finally, isScrolledToBottom is slow.

It gets executed even if the console isn't visible. We should check WebInspector.consoleContentView.visible.
Comment 4 Nikita Vasilyev 2015-12-17 23:56:18 PST
(In reply to comment #1)
> (In reply to comment #0)
> > Created attachment 267609 [details]
> > [Image] Stacktrace in Timelines
> 
> This timeline recording shows that _appendLocationLink takes 23.13ms
> out of 23.43ms of ConsoleMessageView execution time. That's 98.7%!
> 98.7% of ConsoleMessageView execution time spent on adding the source link.
> 
> I don't understand what happens in addEventListener selected on the image.
> Timelines doesn't tell me why *adding* an event listener takes so long.

Our addEventListener is O(n).

        for (var i = 0; i < listeners.length; ++i) {
            if (listeners[i].listener === listener && listeners[i].thisObject === thisObject)
                return;
        }

Put it in a loop and it's O(n^2)!
Comment 5 Radar WebKit Bug Importer 2016-01-19 12:21:57 PST
<rdar://problem/24243579>
Comment 6 Nikita Vasilyev 2017-03-10 11:36:05 PST
(In reply to comment #4)
> (In reply to comment #1)
> > (In reply to comment #0)
> > > Created attachment 267609 [details]
> > > [Image] Stacktrace in Timelines
> > 
> > This timeline recording shows that _appendLocationLink takes 23.13ms
> > out of 23.43ms of ConsoleMessageView execution time. That's 98.7%!
> > 98.7% of ConsoleMessageView execution time spent on adding the source link.
> > 
> > I don't understand what happens in addEventListener selected on the image.
> > Timelines doesn't tell me why *adding* an event listener takes so long.
> 
> Our addEventListener is O(n).
> 
>         for (var i = 0; i < listeners.length; ++i) {
>             if (listeners[i].listener === listener &&
> listeners[i].thisObject === thisObject)
>                 return;
>         }
> 
> Put it in a loop and it's O(n^2)!

This was addressed over a year ago.

However, issues mentioned in comments 1–3 weren't.
Comment 7 Devin Rousso 2019-01-09 08:37:48 PST
(In reply to Nikita Vasilyev from comment #6)
> However, issues mentioned in comments 1–3 weren't.
@Nikita I just tried to reproduce your results, and no matter what I try, I can't get `_clearFocusableChildren` or `isScrolledToBottom` to even appear in my profiles.  Can you still reproduce?
Comment 8 Nikita Vasilyev 2019-01-13 17:31:58 PST
Created attachment 359009 [details]
[Image] Timelines

No, I can no longer reproduce it. This is a test page I used: http://nv.github.io/webkit-inspector-bugs/slow-console/

Console with 5k messages is still slow to interact, but it's a separate issue.
Comment 9 Nikita Vasilyev 2019-01-13 17:33:30 PST
Closing. WebKit and/or our hardware have became faster.