1408836 - 5.63 - 14.8% build times (windows2012-32, windows2012-32-rusttests, windows2012-64) regression on push 95dff4968a191f64341700d28fa954d898cd8367 (Sat Oct 14 2017)

Status: RESOLVED 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/pushloghtml?changeset=95dff4968a191f64341700d28fa954d898cd8367

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

Regressions:

 15%  build times summary windows2012-64 opt static-analysis taskcluster-c4.4xlarge     2,627.71 -> 3,016.69
 13%  build times summary windows2012-32 opt static-analysis taskcluster-c4.4xlarge     2,549.04 -> 2,886.88
 13%  build times summary windows2012-32-rusttests opt taskcluster-c4.4xlarge           2,350.66 -> 2,646.14
 12%  build times summary windows2012-32 opt taskcluster-c4.4xlarge                     2,670.84 -> 2,982.84
 10%  build times summary windows2012-64 opt taskcluster-c4.4xlarge                     2,722.51 -> 2,990.57
  7%  build times summary windows2012-64 pgo taskcluster-c4.4xlarge                     5,310.73 -> 5,676.06
  6%  build times summary windows2012-32 pgo taskcluster-c4.4xlarge                     5,024.18 -> 5,306.97

Improvements:

100%  sccache hit rate summary windows2012-64 opt static-analysis taskcluster-c4.4xlarge     0.79 -> 0.00
100%  sccache hit rate summary windows2012-32 debug static-analysis taskcluster-c4.4xlarge   0.76 -> 0.00
 91%  sccache hit rate summary windows2012-64 debug static-analysis taskcluster-c4.4xlarge   0.85 -> 0.08
 84%  sccache hit rate summary windows2012-32 opt static-analysis taskcluster-c4.4xlarge     0.84 -> 0.14
  6%  sccache hit rate summary windows2012-32-rusttests opt taskcluster-c4.4xlarge           0.99 -> 0.92
  6%  sccache hit rate summary windows2012-32 opt taskcluster-c4.4xlarge                     0.98 -> 0.92
  6%  sccache hit rate summary windows2012-64 opt taskcluster-c4.4xlarge                     0.99 -> 0.93
  6%  sccache hit rate summary windows2012-64 debug taskcluster-c4.4xlarge                   0.97 -> 0.92


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

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]]

:rillian FYI Updating Rust to 1.20.0 increased the build times on Windows platform.

Comment 2

[Mike Hommey [:glandium]]

It looks like there are a lot of sccache misses on rust (quick glance suggests 100% miss) since the upgrade.

Comment 3

[Ralph Giles (:rillian)]

(In reply to Mike Hommey [:glandium] from comment #2)
> It looks like there are a lot of sccache misses on rust (quick glance
> suggests 100% miss) since the upgrade.

Indeed it does. Thanks for the heads-up.

Rust 1.21.0 is on autoland now. Hopefully that will be an improvement.

Comment 4

[Ralph Giles (:rillian)]

Looking at the couple of builds we got before the trees closed, builds with rust 1.21 had the same 100% miss rate.

Comment 5

[(not currently active) Ted Mielczarek]

I found time to look at this today, and testing with sccache and a simple Rust crate showed that I was getting zero cache hits on Windows. Digging in a little bit showed that the root cause was that sccache includes all environment variables starting with CARGO_ in the cache key, and since cargo gained jobserver support it passes an env var like `CARGO_MAKEFLAGS=--jobserver-fds=__rust_jobserver_semaphore_992383377 --jobserver-auth=__rust_jobserver_semaphore_992383377` which is very non-cacheable.

I'm going to write a small patch to filter out `CARGO_MAKEFLAGS` from sccache's hash key generation, and also write an sccache test that tests Rust compilation via cargo.

Comment 6

[(not currently active) Ted Mielczarek]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=12bcb80296003126c2a7e0d939cf75b864fa837b

Comment 7

[(not currently active) Ted Mielczarek]

I landed my sccache fix (along with a test) and released 0.2.2 on crates.io:
https://github.com/mozilla/sccache/commit/2d9bdc1e8fb1fa5a531da2930670bbfcb66f78a0

Comment 8

[(not currently active) Ted Mielczarek]

Attachment: bug 1408836 - update sccache to 0.2.2 to fix a Rust caching regression from Rust 1.20.

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

Comment 9

[Mike Hommey [:glandium]]

Comment on attachment 8922148 [details]
bug 1408836 - update sccache to 0.2.2 to fix a Rust caching regression from Rust 1.20.

https://reviewboard.mozilla.org/r/193148/#review198388

::: taskcluster/scripts/misc/build-sccache.sh:5
(Diff revision 1)
>  #!/bin/bash
>  set -x -e -v
>  
> +# 0.2.2
>  SCCACHE_REVISION=df04fa530d6b7d79fef8c848879d47dcc4d95b32

You're not changing the sha1.

Comment 10

[(not currently active) Ted Mielczarek]

Comment on attachment 8922148 [details]
bug 1408836 - update sccache to 0.2.2 to fix a Rust caching regression from Rust 1.20.

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/193148/diff/1-2/

Comment 11

[(not currently active) Ted Mielczarek]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=7bc536d9f94e48aed873d7c61e24c6ebbb2927ee

Comment 12

[Mike Hommey [:glandium]]

Comment on attachment 8922148 [details]
bug 1408836 - update sccache to 0.2.2 to fix a Rust caching regression from Rust 1.20.

https://reviewboard.mozilla.org/r/193148/#review198394

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c3fb1be6aca0
update sccache to 0.2.2 to fix a Rust caching regression from Rust 1.20. r=glandium

Comment 14

[Attila Craciun [:arny]]

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

Comment 15

[(not currently active) Ted Mielczarek]

The build times are pretty noisy:
https://treeherder.mozilla.org/perf.html#/graphs?series=autoland,1460334,1,2&highlightedRevisions=c3fb1be6aca0&highlightedRevisions=95dff4968a19

as are the cache hit rate:
https://treeherder.mozilla.org/perf.html#/graphs?series=autoland,1530942,1,2&series=autoland,1484860,1,2&series=autoland,1530957,1,2&series=autoland,1484863,1,2&highlightedRevisions=c3fb1be6aca0&highlightedRevisions=95dff4968a19

...but I think this is fixed?

Comment 16

[Mike Hommey [:glandium]]

Is it? If you look at the bigger picture, you can see the lower bound increased:
https://treeherder.mozilla.org/perf.html#/graphs?timerange=2592000&series=autoland,1460334,1,2&highlightedRevisions=c3fb1be6aca0&highlightedRevisions=95dff4968a19

Comment 18

[Ionuț Goldan [:igoldan]]

I noticed this small improvement:

== Change summary for alert #10184 (as of Thu, 26 Oct 2017 00:30:39 GMT) ==

Improvements:

  5%  build times summary windows2012-32 opt static-analysis taskcluster-c4.4xlarge     2,685.00 -> 2,555.24

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

Comment 19

[Ionuț Goldan [:igoldan]]

However, most of the regressions remained.