make.bash slower in master

[Daniel Martí]

Hi all,

As I continue to build master on a daily basis,
I've noticed that in the past few days it's gone from building in about 60s
to building in 80s or so. I haven't bisected nor investigated,
but my guess would be PGO, https://go-review.googlesource.com/c/go/+/497455.

Is this being tracked? I understand that the performance of the toolchain
likely takes precedence over the time it takes to bootstrap,
but I'm still surprised by the significant increase in time.

For some historical context, on a previous laptop with about half the power,
Go used to bootstrap in about 30s. When the better build caching landed
which required rebuilding the toolchain more times, it then jumped to those 60s.

Go still builds fast, but it would be nice to track the change over time :)

[peterGo]

Daniel Martí,

Changes in user time are significant.

---

Total Cores            10
# of Performance-cores  2
# of Efficient-cores    8
Total Threads          12

---

Go 1.21

~/go/src$ time ./make.bash
Building Go cmd/dist using /home/peter/go1.17.13. (go1.17.13 linux/amd64)
Building Go toolchain1 using /home/peter/go1.17.13.
Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1.
Building Go toolchain2 using go_bootstrap and Go toolchain1.
Building Go toolchain3 using go_bootstrap and Go toolchain2.
Building packages and commands for linux/amd64.
---
Installed Go for linux/amd64 in /home/peter/go
Installed commands in /home/peter/go/bin

real    0m53.063s
user    5m12.710s
sys     0m27.981s
~/go/src$ go version
go version devel go1.21-6f7824f7a4 Thu May 25 01:01:41 2023 +0000 linux/amd64
~/go/src$

---

Go 1.20

~/go1.20/src$ time ./make.bash
Building Go cmd/dist using /home/peter/go1.17.13. (go1.17.13 linux/amd64)
Building Go toolchain1 using /home/peter/go1.17.13.
Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1.
Building Go toolchain2 using go_bootstrap and Go toolchain1.
Building Go toolchain3 using go_bootstrap and Go toolchain2.
Building packages and commands for linux/amd64.
---
Installed Go for linux/amd64 in /home/peter/go1.20
Installed commands in /home/peter/go1.20/bin

real    0m51.260s
user    4m29.301s
sys     0m25.334s
~/go1.20/src$ go1.20 version
go version go1.20.4 linux/amd64
~/go1.20/src$ cd

---

Go 1.17

~/go1.17.13/src$ time ./make.bash
Building Go cmd/dist using /home/peter/go1.4. (go1.4-bootstrap-20170531 linux/amd64)
Building Go toolchain1 using /home/peter/go1.4.
Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1.
Building Go toolchain2 using go_bootstrap and Go toolchain1.
Building Go toolchain3 using go_bootstrap and Go toolchain2.
Building packages and commands for linux/amd64.
---
Installed Go for linux/amd64 in /home/peter/go1.17.13
Installed commands in /home/peter/go1.17.13/bin

real    1m2.477s
user    3m32.745s
sys     0m18.902s
~/go1.17.13/src$ go1.17 version
go version go1.17.13 linux/amd64
~/go1.17.13/src$

---

peter

[peterGo]

Daniel Martí,

For Go 1.21, I see a significant difference between clean and primed caches.

---

~/go/src$ go clean -cache && go clean -modcache && go clean -testcache

~/go/src$ time ./make.bash
Building Go cmd/dist using /home/peter/go1.17.13. (go1.17.13 linux/amd64)
Building Go toolchain1 using /home/peter/go1.17.13.
Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1.
Building Go toolchain2 using go_bootstrap and Go toolchain1.
Building Go toolchain3 using go_bootstrap and Go toolchain2.
Building packages and commands for linux/amd64.
---
Installed Go for linux/amd64 in /home/peter/go
Installed commands in /home/peter/go/bin

real    1m21.752s
user    9m5.356s
sys     0m46.307s

~/go/src$ time ./make.bash
Building Go cmd/dist using /home/peter/go1.17.13. (go1.17.13 linux/amd64)
Building Go toolchain1 using /home/peter/go1.17.13.
Building Go bootstrap cmd/go (go_bootstrap) using Go toolchain1.
Building Go toolchain2 using go_bootstrap and Go toolchain1.
Building Go toolchain3 using go_bootstrap and Go toolchain2.
Building packages and commands for linux/amd64.
---
Installed Go for linux/amd64 in /home/peter/go
Installed commands in /home/peter/go/bin

real    0m55.990s
user    5m38.761s
sys     0m30.368s

~/go/src$ go version
go version devel go1.21-6f7824f7a4 Thu May 25 01:01:41 2023 +0000 linux/amd64
~/go/src$

---

peter

On Thursday, May 25, 2023 at 4:12:46 AM UTC-4 Daniel Martí wrote:

[Michael Pratt]

https://go.dev/cl/497455 (PGO for cmd/compile) does (unsurprisingly) slow down make.bash. On my workstation:

             │ /tmp/before.benchfmt │        /tmp/after.benchfmt         │
             │         msec         │    msec      vs base               │
Task-clock:u            417.9k ± 2%   574.8k ± 1%  +37.53% (p=0.001 n=7)

                   │ /tmp/before.benchfmt │          /tmp/after.benchfmt          │
                   │         val          │     val       vs base                 │
Cycles:u                    1.397T ± 1%      1.995T ± 1%  +42.81% (p=0.001 n=7)
Instructions:u              1.586T ± 0%      2.181T ± 0%  +37.54% (p=0.001 n=7)

            │ /tmp/before.benchfmt │        /tmp/after.benchfmt        │
            │         sec          │    sec      vs base               │
Wall-time               79.02 ± 2%   93.38 ± 2%  +18.17% (p=0.001 n=7)
User-time               376.6 ± 2%   521.1 ± 0%  +38.39% (p=0.001 n=7)
System-time             42.49 ± 4%   54.79 ± 3%  +28.96% (p=0.001 n=7)
geomean                 108.1        138.7       +28.24%

There are a few contributors to this:

1. Adding PGO for cmd/compile means that all dependencies of cmd/compile must be built twice: once with the profile (for cmd/compile) and once without the profile (for everything else). This is unavoidable, so there will always be some slowdown.

2. PGO profile processing is quite inefficient today (https://go.dev/issue/58102). This is on our roadmap to fix, though obviously not soon given the freeze.

3. dist disables PGO for toolchain1, but I believe both toolchain2 and toolchain3 will build with PGO. I think we could skip PGO for toolchain2 if desired.

I'm not sure what the breakdown between these causes is, but we could figure it out.

Note that you can disable PGO with make.bash by setting GOFLAGS=-pgo=off.

--
You received this message because you are subscribed to the Google Groups "golang-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to golang-dev+...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/golang-dev/5f972844-3208-4862-98ba-f30eb80505a8n%40googlegroups.com.

[Michael Pratt]

I did some analysis to breakdown the three causes:

            │ nopgo.txt.benchfmt │ pgo_empty_toolchain3.txt.benchfmt │      pgo_empty.txt.benchfmt       │ pgo_full_toolchain3.txt.benchfmt  │       pgo_full.txt.benchfmt       │
            │        sec         │    sec      vs base               │    sec      vs base               │    sec      vs base               │    sec      vs base               │
Wall-time             78.62 ± 0%   85.57 ± 0%   +8.84% (p=0.002 n=6)   85.56 ± 2%   +8.83% (p=0.002 n=6)   90.77 ± 0%  +15.46% (p=0.002 n=6)   93.57 ± 1%  +19.02% (p=0.002 n=6)
User-time             379.5 ± 0%   459.6 ± 0%  +21.13% (p=0.002 n=6)   477.1 ± 0%  +25.72% (p=0.002 n=6)   489.2 ± 0%  +28.91% (p=0.002 n=6)   521.7 ± 0%  +37.49% (p=0.002 n=6)
System-time           43.04 ± 2%   49.15 ± 3%  +14.19% (p=0.002 n=6)   50.60 ± 1%  +17.56% (p=0.002 n=6)   52.98 ± 1%  +23.08% (p=0.002 n=6)   54.94 ± 2%  +27.65% (p=0.002 n=6)

In the names above, "full" means using the checked-in default.pgo, "empty" means using an empty default.pgo. "toolchain3" means that PGO is enabled only for the toolchain3 build (otherwise toolchain2 uses PGO as well).

The empty profile forces the package configuration split (case 1), but has no parsing cost (case 2), thus splitting those costs apart. The toolchain3 build of course splits the toolchain2+3 cost.

Ignoring toolchain3, case 1 costs ~7s wall / ~100s user time, and case 2 costs ~8s wall / ~45s user time. So we do have quite a bit of impact to be had from https://go.dev/issue/58102.

We can also consider limiting PGO to toolchain3, but the gain there is a bit more modest at ~2.75s wall / ~32s user time.

[Daniel Martí]

Thank you for digging!

I don't think a slow-down of 10-20% is worth stalling 1.21 for,
I was mainly worrying whether or not this was being tracked
like other performance metrics already are at
https://perf.golang.org/dashboard/.

I realise that the performance of "go build" is more important
than "./make.bash", but it could be good to track it as well :)

As one data point, in a couple of CI systems I test against Go master,
which is done by downloading a source archive and running make.bash.
That's gotten noticeably more expensive over the past few years,
to the point that I've started wondering if binary archives would be
a good idea. Hopefully we can keep make.bash fast instead.

> >> <https://groups.google.com/d/msgid/golang-dev/5f972844-3208-4862-98ba-f30eb80505a8n%40googlegroups.com?utm_medium=email&utm_source=footer>
> >> .
> >>
> >

[Michael Pratt]

On Tue, Jun 6, 2023 at 5:40 PM Daniel Martí <mv...@mvdan.cc> wrote:

Thank you for digging!

I don't think a slow-down of 10-20% is worth stalling 1.21 for,
I was mainly worrying whether or not this was being tracked
like other performance metrics already are at
https://perf.golang.org/dashboard/.

We don't explicitly track this, though we could potentially do so via a Sweet benchmark. We track a few "GoBuild" benchmarks for build times for Kubernetes, etc: https://perf.golang.org/dashboard/?benchmark=GoBuildKubelet