1237368 - Opening the console causes requestAnimationFrame's latency to spike

Status: RESOLVED FIXED

(DevTools :: Console, defect)

Description

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

Attachment: webconsole-profile.json

Test case: https://www.msully.net/stuff/charlie-game/asdf.html

Observe that when the console is not open, things are regularly around 16ms-ish.

Opening the console causes huge spikes in latency.

I ran a profile, and 55% of time is spent in synchronous reflows for the webconsole's UI to put the scrolling at the bottom.

Comment 1

[Nick Fitzgerald [:fitzgen] [⏰PST; UTC-8]]

I guess this is a more stable URL for the same test case: https://www.msully.net/stuff/timers/

Comment 2

[Brian Grinstead [:bgrins]]

Attachment: console-faster-WIP.patch

Seeing some surprising increases by dropping the xul flex on the container and instead setting a px width based on the current width in js.  From my measurements in a local build with the test case, the scroll time goes from ~80ms once we hit 1000 elements without the patch to ~2ms with the patch.

Still would need to sort out resizes that aren't firing a resize event (like when the variables view opens or gets resized), but this looks promising.

Comment 3

[Brian Grinstead [:bgrins]]

Attachment: console-faster-WIP.patch

Victor, can you have a look at this?  As a result of trial and error we found that by setting a hardcoded width and dropping -moz-box-flex the layout time required to call node.scrollIntoView dropped massively.  And for some reason the output container needs to be wrapped in yet another block element (can't be direct child of hbox).  So, this patch does that.  A little gross, but if the perf gains hold across platforms as in Comment 2 I'd like to do it (going to do some further testing for this tomorrow).

Comment 4

[Brian Grinstead [:bgrins]]

Attachment: console-faster-logging.patch

Extra logging for the scroll function for testing

Comment 5

[Brian Grinstead [:bgrins]]

Here are some measurements I took across platforms.  There are two main measurements, and I took each one with/without the patch and with/without e10s:

1) Average time to call scrollIntoView in chrome code (over last 10 calls)
2) Average time for rAF to trigger on page (over last 100 calls)

The computers I tested were a low-powered Ubunutu VM, OSX 10.10 on an MBP, and Windows 8 on a fast desktop.  Didn't try to control the computers much so they were doing normal tasks during the test (although the VM is a clean install just for building Firefox and doesn't have much else running).

---

Ubuntu VM - Average scroll time:

                  Before patch  |   After patch
------------------------------------------------
With e10s      |    250-350ms   |     3-4ms
Without e10s   |    130-150ms   |     2-3ms


Ubuntu VM - Average rAF time:

                  Before patch  |   After patch
------------------------------------------------
With e10s      |       30ms     |      25ms
Without e10s   |       74ms     |      25ms


OSX - Average scroll time:

                  Before patch  |   After patch
------------------------------------------------
With e10s      |    140-160ms   |    1.5-2.5ms
Without e10s   |     90-100ms   |     1.5-2ms


OSX - Average rAF time:

                  Before patch  |   After patch
------------------------------------------------
With e10s      |       35ms     |      35ms
Without e10s   |       64ms     |      25ms


Windows 8 - Average scroll time:

                  Before patch  |   After patch
------------------------------------------------
With e10s      |    125-135ms   |    1-1.5ms
Without e10s   |    115-120ms   |    1-1.5ms


Windows 8 - Average rAF time:

                  Before patch  |   After patch
------------------------------------------------
With e10s      |       17ms     |      17ms
Without e10s   |       60ms     |      17ms

Comment 6

[Brian Grinstead [:bgrins]]

Attachment: console-faster.patch

Upgrading this patch to a review request since tests are passing (needed to update some tests that were relying on outputWrapper being the parentNode of outputNode).

Comment 7

[Brian Grinstead [:bgrins]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=c886479a9d0d

Comment 8

[Victor Porof [:vporof][:vp]]

Comment on attachment 8708582 [details] [diff] [review]
console-faster.patch

Review of attachment 8708582 [details] [diff] [review]:
-----------------------------------------------------------------

gross...

Comment 9

[Pulsebot]

https://hg.mozilla.org/integration/fx-team/rev/1aed451f1502

Comment 10

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/1aed451f1502

Comment 11

[Mayur Patil]

[bugday-20160323]

Status: RESOLVED,FIXED -> UNVERIFIED

Comments:
STR: Not clear.
Developer specific testing

Component: 
Name			Firefox
Version			46.0b9
Build ID		20160322075646
Update Channel          beta
User Agent		Mozilla/5.0 (Windows NT 6.1; WOW64; rv:46.0) Gecko/20100101 Firefox/46.0
OS			Windows 7 SP1 x86_64

Expected Results: 
Developer specific testing

Actual Results: 
As expected