1266735 - 2.42 - 4.58% tp5o / tp5o % Processor Time (windows7-32, windows8-64, windowsxp) regression on push b3b5be1d2027f915c3c54b966fb41de8444923ee (Thu Apr 21 2016)

Status: RESOLVED FIXED

(Core :: Networking, defect)

Description

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

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

This is a list of all known regressions and improvements related to the push:
https://treeherder.mozilla.org/perf.html#/alerts?id=961

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#tp5

Reproducing and debugging the regression:

If you would like to re-run this Talos test on a potential fix, use try with the following syntax:
try: -b o -p win32,win64 -u none -t tp5o-e10s[Windows 7,Windows XP,Windows 8],tp5o[Windows 7,Windows XP,Windows 8] --rebuild 5  # add "mozharness: --spsProfile" to generate profile data

(we suggest --rebuild 5 to be more confident in the results)

To run the test locally and do a more in-depth investigation, first set up a local Talos environment:
https://wiki.mozilla.lorg/Buildbot/Talos/Running#Running_locally_-_Source_Code

Then run the following command from the directory where you set up Talos:
talos --develop -e [path]/firefox -a tp5o

(add --e10s to run tests in e10s mode)

Making a decision:
As the patch author we need your feedback to help us handle this regression.
*** Please let us know your plans by Monday, 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

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

:hurley, can you take a look at this.  I assume this wasn't intentional, possibly there is an easy fix or an easy explanation :)

Comment 2

[u408661]

I'm not surprised by this (I expected a talos regression of some sort). Basically, this is the same thing that happened when we landed the original predictor (which that push added more features to) - we've added work that, in the talos world, gives us no improvement (in this case, we start prefetching things after so many loads of a page). So yeah, some extra CPU time is not in the least bit surprising. We didn't regress the actual pageload time (even though we're moving more bits around) because localhost has so much bandwidth available, our extra bit-moving doesn't matter there. But yeah, extra work to determine what to prefetch, plus the work of actually prefetching will use extra CPU cycles.

:jmaher, does this sound reasonable? I'll spend some time over the next few days figuring out if there's anything particularly egregious that I can fix that could reduce the impact, but I still expect there to be some impact no matter what.

Comment 3

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

thanks for the quick reply :hurley!  This makes a lot of sense.  Explaining regressions is half the battle.  While these regressions are not large, they are on windows and I am not seeing it on osx/linux- so if you do think of something to reduce the impact it would be really cool.  I think it would not be useful to spend a week of your time focusing on this trying to optimize it with a bunch of hacks.

Comment 4

[u408661]

There's nothing windows-specific about the code I landed. I could easily imagine, however, windows' socket implementation (or something else in the layers underneath us) being less efficient than the osx/linux implementations, which would account for the fact that we see this regression on windows only. Unfortunately, I don't (currently) have a windows machine available to me, but I'm working on it :) Once I get one, I should have some cycles to at least run this through a profiler to see what (if anything) can be done - perhaps I could tweak prefetch parallelism on windows, for example, to reduce the amount of work we'll do that competes with everything else. Just a thought, though, I don't want to get too crazy without having some real data about where the actual CPU usage lies.

Comment 5

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

this is now on aurora, so we should consider fixes for 48 (aurora) and 49 (trunk).

Comment 6

[u408661]

No longer relevant on aurora - prefetch has been disabled there (bug 1268208)

Comment 7

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

will we see this on beta when we uplift?

Comment 8

[u408661]

No, the feature has been disabled to give it a full nightly cycle before continuing along the trains

Comment 9

[Liz Henry (:lizzard) (relman/hg->git project)]

Tracking for 49 since this is a recent regression.  Marking as disabled for 48 too.

Comment 10

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

with the exception of the processor time, this regression seems to be fixed by bug 1273882, lets mark this as resolved fix.