Closed Bug 1237368 Opened 4 years ago Closed 4 years ago

Opening the console causes requestAnimationFrame's latency to spike

Categories

(DevTools :: Console, defect)

defect
Not set

Tracking

(firefox46 fixed)

RESOLVED FIXED
Firefox 46
Tracking Status
firefox46 --- fixed

People

(Reporter: fitzgen, Assigned: bgrins)

References

(Blocks 1 open bug)

Details

Attachments

(3 files, 2 obsolete files)

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.
I guess this is a more stable URL for the same test case: https://www.msully.net/stuff/timers/
Attached patch console-faster-WIP.patch (obsolete) — Splinter Review
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.
Attached patch console-faster-WIP.patch (obsolete) — Splinter Review
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).
Attachment #8707682 - Attachment is obsolete: true
Attachment #8707704 - Flags: feedback?(vporof)
Extra logging for the scroll function for testing
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
Assignee: nobody → bgrinstead
Status: NEW → ASSIGNED
See Also: → 1239750
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).
Attachment #8707704 - Attachment is obsolete: true
Attachment #8707704 - Flags: feedback?(vporof)
Attachment #8708582 - Flags: review?(vporof)
Comment on attachment 8708582 [details] [diff] [review]
console-faster.patch

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

gross...
Attachment #8708582 - Flags: review?(vporof) → review+
https://hg.mozilla.org/mozilla-central/rev/1aed451f1502
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 46
Depends on: 1248301
Depends on: 1250633
Depends on: 1260071
Depends on: 1260821
Depends on: 1260822
Depends on: 1260839
Depends on: 1261533
[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
Depends on: 1268734
Depends on: 1327375
Depends on: 1358393
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.