1689703 - Fission visual metrics regression on Mac for Microsoft

Status: RESOLVED FIXED

(Core :: Performance: Navigation, defect, P2)

Description

[Randell Jesup [:jesup] (needinfo me)]

You can see a ~10-15% visualmetric regression for Microsoft on MacOS here: https://vismet.arewefastyet.com/mac/cold-page-load/overview?numDays=60

Comment 1

[Neha Kochar [:neha]]

Let's target fixing this in M8, unless it gets fixed by the perf improvements in M7 for reddit, yahoo mail or netflix.

Comment 2

[Randell Jesup [:jesup] (needinfo me)]

Profiles on MBPro 2018 i7 quad-core:
Synchronized, ~1.3s which is the time to get to 100% visually complete for e10s. Median profile (by SI measurement) from 15 iterations.
Commandline: python3 run_test.py --condition --visualmetrics --iterations 15 --webrender --desktop --profiles --path '/Applications/Firefox\ Nightly/Contents/MacOS/firefox'

E10s: https://share.firefox.dev/3tOwe4u
Fission: https://share.firefox.dev/2MP8a0Q

There's a big gap with little happening from about 0.625 to 0.825s in fission; there's a much smaller gap in e10s (0.54-0.575). There's a second gap at 0.90s which doesn't exist in e10s.

Comment 3

[Markus Stange [:mstange]]

(In reply to Randell Jesup [:jesup] (needinfo me) from comment #2)

There's a big gap with little happening from about 0.625 to 0.825s in fission;

It looks like we're waiting for setTimeout handlers to fire during those gaps, but they don't fire: https://share.firefox.dev/2NkdDMP

After each of the gaps, we run a setTimeout handler which was started with a 4ms interval. But you can clearly see, based on the runnable markers, that no code was running 4ms ago, so those timeouts must already have been waiting for a lot longer.

Olli, could these delays be caused by cross-process idle scheduling? However, I don't see any code running on the other processes during those gaps either.

Comment 4

[Olli Pettay [:smaug][[e-mail]]]

IPC profiling might give some useful information here.
And also the thread for PBackground in the parent process

Comment 5

[Olli Pettay [:smaug][[e-mail]]]

In the Fission profile there is a new process (pid=15835) launching around time 0.70, and that is when the other process (pid=15831) seems to have some delay with idle handling.

Comment 6

[Randell Jesup [:jesup] (needinfo me)]

Profiles from a local recording of microsoft, with IPC and pbackground:
e10s: https://share.firefox.dev/3qxZHha
fission: https://share.firefox.dev/3qEsOzr

The first big paint that's most of the speedindex result comes about 0.3675s on e10s, about 0.4515s on fission, maybe 5 frames later.

Comment 7

[Randell Jesup [:jesup] (needinfo me)]

Previous profiles were still missing IPC and the background thread. Here are updated ones:
e10s: https://share.firefox.dev/3qrKH4n
fission: https://share.firefox.dev/2NyJ6uY

Comment 8

[Olli Pettay [:smaug][[e-mail]]]

So there is the process 79231 launching at ~0.40. Does a process launch on Mac do some particularly blocking operations, I mean something which might block other processes.

Comment 9

[Randell Jesup [:jesup] (needinfo me)]

To be honest, I don't know, though process creation is always rather heavyweight. I'd be surprised if it blocked normal operations on other threads other than simply using a bunch of CPU. Perhaps Instruments would tell us.

Comment 10

[Randell Jesup [:jesup] (needinfo me)]

Attachment: 003-www.microsoft.com_en-us_.mp4

Comment 11

[Randell Jesup [:jesup] (needinfo me)]

New profiles. Local recording, median SI of 15 runs. Median SI was a 10% regression.

e10s: https://share.firefox.dev/3pMhEXM
fission: https://share.firefox.dev/3aHo6LE
Attached side-by-side video

Comment 13

[Randell Jesup [:jesup] (needinfo me)]

Note that the median SI regression for the live site was ~43%

Comment 14

[Randell Jesup [:jesup] (needinfo me)]

Live loads (43% regression):
e10s: https://share.firefox.dev/2OSz5Jx
fission: https://share.firefox.dev/3qKuib7

Comment 15

[Randell Jesup [:jesup] (needinfo me)]

Attachment: live sites video

Comment 16

[Randell Jesup [:jesup] (needinfo me)]

With the non-native theming turned on for mac, and the preallocation delay patch (bug 1694036), we're now apparently within 3-5% (depending on CSI, PSI, SI) of E10s. At this point I think we can close this bug