1303328 - 2.05 - 4.55% sessionrestore / sessionrestore_no_auto_restore / tpaint / ts_paint (linux64, osx-10-10, windows7-32, windows8-64, windowsxp) regression on push c68f029d6c55 (Thu Sep 15 2016)

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

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

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

Regressions:

  5%  sessionrestore windows7-32 opt                          915.29 -> 956.92
  4%  ts_paint windows7-32 opt                                980.96 -> 1021.08
  4%  sessionrestore_no_auto_restore windows7-32 opt          965.92 -> 1004.5
  4%  sessionrestore_no_auto_restore windows8-64 opt          879.42 -> 911.58
  4%  sessionrestore windows8-64 opt                          843.08 -> 873.08
  4%  ts_paint windows8-64 opt e10s                           842.5 -> 872.42
  4%  sessionrestore windows8-64 opt e10s                     723.5 -> 749
  4%  ts_paint windows8-64 opt                                870.67 -> 901.17
  3%  sessionrestore_no_auto_restore windows8-64 opt e10s     759.5 -> 785.25
  3%  sessionrestore_no_auto_restore windowsxp opt            923.29 -> 954.17
  3%  sessionrestore_no_auto_restore windows7-32 opt e10s     843.92 -> 871.42
  3%  sessionrestore_no_auto_restore windowsxp opt e10s       766.08 -> 790.83
  3%  tpaint windows7-32 opt                                  292.67 -> 301.64
  3%  sessionrestore windowsxp opt                            892 -> 918.17
  3%  ts_paint windowsxp opt e10s                             905.5 -> 931.83
  3%  tpaint windows8-64 opt                                  278.04 -> 286.04
  3%  sessionrestore windows7-32 opt e10s                     808.12 -> 831.08
  3%  sessionrestore windowsxp opt e10s                       735 -> 755.83
  3%  ts_paint windows7-32 opt e10s                           970.25 -> 996.92
  3%  ts_paint windowsxp opt                                  958.71 -> 984.67
  2%  ts_paint linux64 opt                                    1576.62 -> 1609.25
  2%  sessionrestore_no_auto_restore osx-10-10 opt            1067.71 -> 1089.58


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

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

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

:sfink, as you are the author of the 3 patches which landed together in the same push, could you look into this?  Right now it looks like a perfect storm of all startup tests regressing.

Comment 2

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

I did a full set of retriggers on the reported push and the previous one, it is pretty clear this push is the culprit:
https://treeherder.mozilla.org/perf.html#/compare?originalProject=mozilla-inbound&originalRevision=b1df9ae6cce2&newProject=mozilla-inbound&newRevision=c68f029d6c55&framework=1

Comment 3

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

I also think AWFY found some regressions:
https://treeherder.mozilla.org/perf.html#/alerts?id=3210

^ that includes the previous push, not as granular, but possibly this data could help.

Comment 4

[Steve Fink [:sfink] [:s:]]

Ok, this is a fun one. All three of those bugs are *obviously* not the cause here. :-) (I bet you've heard that one before!)

Bug 1302125 is DEBUG only.

Bug 1298804 is OOM only.

Bug 1301764 checks an environment variable, which won't be set for talos or awfy, and otherwise does nothing (well, it adds a threshold == 0 branch to not very hot code, where threshold is always exactly zero.)

My money would be on bug 1301764, because it converts some code from DEBUG-only to always on. That code is for producing output that we never print out, but I wonder if it is getting generated and then discarded?

I will look. If you need something to back out to see if it fixes the regression, that'd be the one.

Comment 5

[Steve Fink [:sfink] [:s:]]

Attachment: Avoid constructing strings to feed to InferSpew if inactive

I have a regression from making TypeSet::TypeString and TypeSet::ObjectGroupString work in non-DEBUG builds. I suspect the problem is that we have some calls to something like

  InferSpew(channel, "foo %s", TypeSet::TypeString(ts));

so we're unconditionally constructing those strings to pass in, and I made them expensive.

It's not a huge deal; I can make my instrumentation DEBUG-only too. But I'd kind of like to have it in opt builds, so assuming this fixes the regression, do you think it would be ok to land this?

Comment 6

[Alison Shiue]

As a note, this regression patch has been merged into Aurora, so please make sure to uplift any fixes to Aurora, thank you.

Comment 7

[Alison Shiue]

For up to date results, see: 
https://treeherder.mozilla.org/perf.html#/alerts?id=3290
https://treeherder.mozilla.org/perf.html#/alerts?id=3292

Comment 8

[Jan de Mooij [:jandem]]

Steve, doesn't this patch only affect the DEBUG case, or am I missing something?

Comment 9

[Jan de Mooij [:jandem]]

Comment on attachment 8792711 [details] [diff] [review]
Avoid constructing strings to feed to InferSpew if inactive

Clearing review per comment 8.

Comment 10

[Steve Fink [:sfink] [:s:]]

Attachment: Avoid constructing strings to feed to InferSpew if inactive

Uh... yeah. That was DEBUG-only. I was thinking in circles; that patch would only speed up DEBUG.

Ok, so I could just #define InferSpew to do nothing in non-DEBUG, but I suppose making DEBUG faster is kind of nice too. Let me know if you'd prefer I split the two apart, or did it differently.

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/fe14b12b1c4c
Avoid constructing strings to feed to InferSpew if inactive, r=jandem

Comment 12

[Alison Shiue]

This fix shows improvements on perfherder, thank you!

https://treeherder.mozilla.org/perf.html#/alerts?id=3555

Improvements:

  4%  sessionrestore windows8-64 opt                     890.58 -> 852.58
  4%  sessionrestore_no_auto_restore windows8-64 opt     929.67 -> 892.17
  4%  ts_paint windows8-64 opt                           920.42 -> 883.5
  4%  sessionrestore_no_auto_restore windows7-32 opt     1031.71 -> 995.08
  3%  sessionrestore windows7-32 opt                     972.54 -> 941.67
  3%  tpaint windows8-64 opt                             288.31 -> 279.41
  3%  tpaint windows7-32 opt                             302.82 -> 294.18
  3%  sessionrestore windowsxp opt                       942.33 -> 916
  3%  sessionrestore_no_auto_restore windowsxp opt       979.5 -> 954.67
  2%  sessionrestore osx-10-10 opt                       1055.29 -> 1030.92
  2%  ts_paint osx-10-10 opt                             1143.33 -> 1117.92
  2%  tpaint windowsxp opt                               302.64 -> 296.16
  2%  sessionrestore_no_auto_restore osx-10-10 opt       1092.71 -> 1070.58

Will this patch uplift to aurora?

Comment 13

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/fe14b12b1c4c

Comment 14

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

thanks for sorting this out, :sfink, please help us determine if this should go to Aurora.

Comment 15

[Steve Fink [:sfink] [:s:]]

Comment on attachment 8796767 [details] [diff] [review]
Avoid constructing strings to feed to InferSpew if inactive

Approval Request Comment
[Feature/regressing bug #]: 1301764
[User impact if declined]: slowdown
[Describe test coverage new/current, TreeHerder]: perfherder results in comment 12 (thanks!)
[Risks and why]: none to speak of. This is a pretty trivial change. It uses some funky varargs macro stuff, but that is used elsewhere in the tree already
[String/UUID change made/needed]: none

Comment 16

[Gerry Chang [:gchang]]

Comment on attachment 8796767 [details] [diff] [review]
Avoid constructing strings to feed to InferSpew if inactive

Fix a regression. Take it in 51 aurora.

Comment 17

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/41593448b1ae

Comment 18

[Alison Shiue]

The perf improvements shows on aurora, thanks!

https://treeherder.mozilla.org/perf.html#/alerts?id=3596