1474524 - 43.94% build times (linux64) regression on push d6120c2bb51e2057df51f4d52510bb5f4e8b4ca5 (Fri Jun 29 2018)

Status: VERIFIED FIXED

(Firefox Build System :: General, defect)

Description

[Ionuț Goldan [:igoldan]]

We have detected a build metrics regression from push:

https://hg.mozilla.org/integration/mozilla-inbound/rev/d6120c2bb51e2057df51f4d52510bb5f4e8b4ca5

As author of one of the patches included in that push, we need your help to address this regression.

Regressions:

 44%  build times linux64 opt artifact taskcluster-m5d.4xlarge     90.71 -> 130.57


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

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 jobs in a pushlog format.

To learn more about the regressing test(s), please see: https://developer.mozilla.org/en-US/docs/Mozilla/Performance/Automated_Performance_Testing_and_Sheriffing/Build_Metrics

Comment 1

[Ionuț Goldan [:igoldan]]

:kmag I noticed build time increases on all Linux AWS machines and also on at least one Windows machine. Are there plans for fixing this or at least doing some :optimizations?

Comment 2

[Ionuț Goldan [:igoldan]]

Note: there is a lot of noise in my graphs and builds on multiple types of AWS machines is making it even harder to track down regressions. With that said, if I identified the wrong bug, just let me know.

I am 70% sure I got this right.

Comment 3

[Michael Shal [:mshal]]

We have bug 1470240 as a followup to generalize and ideally improve the built_in_addons.json construction. The reason for the large delta in artifact build times is that artifact builds don't do much work currently, and the built_in_addons.json script takes a long time to run.

Comment 4

[Kris Maglione [:kmag]]

I'm planning to improve it, yes. I need to do some profiling. We might just need to pre-filter the manifest paths we use to populate the file registries. I'll try to get this done before bug 1470240, since I agree it's pretty annoying for artifact builds.

Comment 5

[Ionuț Goldan [:igoldan]]

:kmag do you have updates on this?

Comment 6

[Gregory Szorc [:gps]]

Is this bug a duplicate of bug 1472110?

Comment 7

[Ionuț Goldan [:igoldan]]

(In reply to Gregory Szorc [:gps] from comment #6)
> Is this bug a duplicate of bug 1472110?

We're not entirely sure the regressions from bug 1472110 where caused by either bug 1459004 or bug 1453691.

Comment 8

[Kris Maglione [:kmag]]

(In reply to Ionuț Goldan [:igoldan], Performance Sheriffing from comment #7)
> (In reply to Gregory Szorc [:gps] from comment #6)
> > Is this bug a duplicate of bug 1472110?
> 
> We're not entirely sure the regressions from bug 1472110 where caused by
> either bug 1459004 or bug 1453691.

They were caused by bug 1453691.

Comment 9

[Kris Maglione [:kmag]]

Attachment: Bug 1474524: Don't call contains() before adding an entry to the registry.

It turns out that this check is the major bottleneck in this task. Simply
catching the error caused by the duplicate files has the same effect, but is
several orders of magnitude faster.

Review commit: https://reviewboard.mozilla.org/r/261450/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/261450/

Comment 10

[Ionuț Goldan [:igoldan]]

(In reply to Kris Maglione [:kmag] from comment #8)
> (In reply to Ionuț Goldan [:igoldan], Performance Sheriffing from comment #7)
> > (In reply to Gregory Szorc [:gps] from comment #6)
> > > Is this bug a duplicate of bug 1472110?
> > 
> > We're not entirely sure the regressions from bug 1472110 where caused by
> > either bug 1459004 or bug 1453691.
> 
> They were caused by bug 1453691.

Then I guess this answers :gps' question: bug 1474524 is not a duplicate of bug 1472110.

Comment 11

[Michael Shal [:mshal]]

Comment on attachment 8997735 [details]
Bug 1474524: Don't call contains() before adding an entry to the registry.

https://reviewboard.mozilla.org/r/261450/#review268832

Wow, it's amazing how much overhead is in contains(). Thanks for fixing this!

Comment 12

[Kris Maglione [:kmag]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/31f260db9192b9965b19736b5d5007fa49283807
Bug 1474524: Don't call contains() before adding an entry to the registry. r=mshal

Comment 13

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/31f260db9192

Comment 14

[Gregory Szorc [:gps]]

Comment on attachment 8997735 [details]
Bug 1474524: Don't call contains() before adding an entry to the registry.

https://reviewboard.mozilla.org/r/261450/#review268832

It is because `contains()` operates on match patterns: it isn't a strict membership test. Checking for `registry[x]` raising `KeyError` would be much faster and would probably perform the same as the patch as coded. But the patch as coded is fine.

Comment 15

[Ionuț Goldan [:igoldan]]

This resolved the regression from comment 0 and also brought many improvements on Windows:

== Change summary for alert #14801 (as of Tue, 07 Aug 2018 16:16:51 GMT) ==

Improvements:

  4%  build times windows2012-64 debug plain taskcluster-c5.4xlarge     1,318.48 -> 1,260.62
  4%  build times windows2012-64 debug plain taskcluster-c4.4xlarge     1,645.74 -> 1,576.79
  4%  build times windows2012-64 opt plain taskcluster-c4.4xlarge       1,734.18 -> 1,668.03
  4%  build times windows2012-64-noopt debug taskcluster-c4.4xlarge     1,512.09 -> 1,455.31
  4%  build times windows2012-32-noopt debug taskcluster-c4.4xlarge     1,453.43 -> 1,400.96
  3%  build times windows2012-64 opt taskcluster-c4.4xlarge             2,166.73 -> 2,099.20
  2%  build times windows2012-32 opt static-analysis taskcluster-c4.4xlarge2,317.46 -> 2,266.77
  2%  build times windows2012-64 debug taskcluster-c4.4xlarge           2,160.11 -> 2,113.89
  2%  build times windows2012-64 opt static-analysis taskcluster-c4.4xlarge2,497.09 -> 2,445.19
  2%  build times windows2012-64 pgo taskcluster-c4.4xlarge             5,025.97 -> 4,925.35

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