1289002 - 18.19 - 23.43% tp5n main_startup_fileio (windows7-32) regression on push 28f30533c6359655335ac5a09e37847ef54dc6ae (Thu Jul 21 2016)

Status: RESOLVED WONTFIX

(Core :: JavaScript Engine, defect)

Description

[Alison Shiue]

Talos has detected a Firefox performance regression from push 28f30533c6359655335ac5a09e37847ef54dc6ae. As author of one of the patches included in that push, we need your help to address this regression.

Summary of tests that regressed:

  tp5n main_startup_fileio windows7-32 opt - 23.43% worse
  tp5n main_startup_fileio windows7-32 opt e10s - 23.37% worse
  tp5n main_startup_fileio windows7-32 pgo e10s - 18.19% worse
  tp5n main_startup_fileio windows7-32 pgo - 18.25% worse


You can find links to graphs and comparsion views for each of the above tests at: https://treeherder.mozilla.org/perf.html#/alerts?id=1965

On the page above you can see an alert for each affected platform as well as a link to a graph showing the history of scores for this test. There is also a link to a treeherder page showing the Talos jobs in a pushlog format.

To learn more about the regressing test(s), please see: https://wiki.mozilla.org/Buildbot/Talos/Tests

For information on reproducing and debugging the regression, either on try or locally, see: https://wiki.mozilla.org/Buildbot/Talos/Running

*** Please let us know your plans within 3 business days, or the offending patch(es) will be backed out! ***

Our wiki page outlines the common responses and expectations: https://wiki.mozilla.org/Buildbot/Talos/RegressionBugsHandling

Comment 1

[Alison Shiue]

Multiple alerts(1965, 1676, 1978, 1994, and 2009) related to following pushes:
https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=0affe22555807bf2b349f94e115ce0f038ff989d&tochange=28f30533c6359655335ac5a09e37847ef54dc6ae

After checking the aurora alert (https://treeherder.mozilla.org/perf.html#/alerts?id=2009), we can found this perf regression is caused by 661d3548825aff461b50901da7ec5e32a8366bf4.
https://hg.mozilla.org/releases/mozilla-aurora/pushloghtml?fromchange=f8b494dbf1ea9c6dca06c6c820ff5160bffccdd7&tochange=661d3548825aff461b50901da7ec5e32a8366bf4

Hi Nicholas, as you are the patch author, can you take a look at this and determine what is the root cause? Thanks!

Comment 2

[Nicholas Nethercote [inactive]]

The patch definitely changes IO patterns at startup on Windows -- there's 10 MiB of data that I moved from a separate file into the binary. But this just reversed the change that 1239083 introduced.

I'm not sure what main_startup_fileio windows7-32 is measuring because that test doesn't appear to be described at https://wiki.mozilla.org/Buildbot/Talos/Tests.

Ted, were there Windows file IO improvements in that bug? With my patch landed are we now back in exactly the pre-1239083 state, or is it somehow different to the old situation?

Comment 3

[(not currently active) Ted Mielczarek]

So humorously there was a regression from my patch as well. This doesn't put us exactly back where we were--prior to my patch we had a separate icudt52.dll that we linked to. Presumably with your patch that has been linked into xul.dll.

We preload all of xul.dll on startup, so anything that gets added to it would show up as a startup fileio regression.

Comment 4

[Joel Maher ( :jmaher ) (UTC -8)]

looking back on trunk and aurora, I don't see an improvement that would be anything close to related to this regression.  I was looking specifically around early April, but even looking at a lot of history, I don't see anything:
https://treeherder.mozilla.org/perf.html#/graphs?timerange=31536000&series=%5Bmozilla-aurora,12945b0b398d773c03a01f2a8eb7006e2be4ca82,1,1%5D&series=%5Bmozilla-inbound,12945b0b398d773c03a01f2a8eb7006e2be4ca82,1,1%5D&zoom=1455907046634.4412,1469415098000,46853160.078197606,72392193.53544667

main_startup_fileio is measured as part of xperf:
https://wiki.mozilla.org/Buildbot/Talos/Tests#xperf

in this case we are looking at the main thread and the fileio (reads/writes in bytes) for the duration up until we get to the end of our marker indicating startup complete:
https://dxr.mozilla.org/mozilla-central/source/toolkit/components/startup/mozprofilerprobe.mof#10

Comment 5

[(not currently active) Ted Mielczarek]

bug 1262492 was the other regression.

Comment 6

[Nicholas Nethercote [inactive]]

So, just to give the overall picture...

- Originally, the 10 MiB of ICU data was in a separate DLL, icudt52.dll.

- Bug 1239083 move the ICU data into a separate file, icudt56l.dat. (Full details are in bug 1262492 comment 2.) Consequences of this:
  * There was 2.6% regression in tp5n main_startup_fileio (windows7-32) (bug 1262492).
  * For some installations the file was missing or corrupted (probably missing, but we're not certain) which prevented Firefox from starting. This was a topcrash on Beta, and a bad one, so...

- Bug 1262731 moved the ICU data back into a DLL in the simplest possible way, but due to other changes made in bug 1239083 it's now in xul.dll. Consequences:
  * 18--23% regression in tp5n main_startup_fileio windows7-32* (this bug).

jmaher: what unit are the fileio measurements using -- looks like it is disk read/write counters? Is this actually affecting startup time?

Comment 7

[Joel Maher ( :jmaher ) (UTC -8)]

this didn't afffect our startup time metrics, only the files read.  The change is in bytes, and we measure all access, even if it is already prefetched.

from the sounds of this, there might not be much to do?

Comment 8

[Nicholas Nethercote [inactive]]

(In reply to Joel Maher ( :jmaher ) from comment #7)
> this didn't afffect our startup time metrics, only the files read.  The
> change is in bytes, and we measure all access, even if it is already
> prefetched.

Thank you for the clarification.
 
> from the sounds of this, there might not be much to do?

I agree. It's a significant rearrangement of on-disk data, so it's not surprising that file IO counts were affected, but if it doesn't affect startup time then it doesn't really matter.

Comment 9

[(not currently active) Ted Mielczarek]

Humorously I came across the following comment while reviewing a patch today:
https://dxr.mozilla.org/mozilla-central/rev/db3ed1fdbbeaf5ab1e8fe454780146e7499be3db/toolkit/library/dependentlibs.py#107