cmd/compile: long build time (45 seconds) for a small package (1500 source lines of code)

[thomaspeugeot]

Go version

go version go1.21.5 darwin/amd64

Output of go env in your module/workspace:

GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/Users/thomaspeugeot/Library/Caches/go-build'
GOENV='/Users/thomaspeugeot/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMODCACHE='/Users/thomaspeugeot/go/pkg/mod'
GONOPROXY='github.com/thomaspeugeot,github.com/fullstack-lang'
GONOSUMDB='github.com/thomaspeugeot,github.com/fullstack-lang'
GOOS='darwin'
GOPATH='/Users/thomaspeugeot/go'
GOPRIVATE='github.com/thomaspeugeot,github.com/fullstack-lang'
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/local/go'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go/pkg/tool/darwin_amd64'
GOVCS=''
GOVERSION='go1.21.5'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='clang'
CXX='clang++'
CGO_ENABLED='1'
GOMOD='/Users/thomaspeugeot/go/src/github.com/thomaspeugeot/thelongbuild/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/_r/bxjvdzc17mb6p56qc7nms1r80000gn/T/go-build65103854=/tmp/go-build -gno-record-gcc-switches -fno-common'

What did you do?

below are the steps to reproduce the timing result

on macos

rm -rf thelongbuild
git clone https://github.com/thomaspeugeot/thelongbuild.git
cd thelongbuild/go/tree
go clean -cache
time go build -v
sed -i '' 's/gongtree_buttons/gongtree_buttons_new/g' tree.go
time go build -v
cd ../../..

the sed command is to trick the compiler to dirty its cache.

note for other plateforms, the sed command is different, it is sed -i 's/gongtree_buttons/gongtree_buttons_new/g' tree.go

What did you see happen?

go build -v 46.99s user 2.44s system 371% cpu 13.320 total

What did you expect to see?

less than a few seconds

[seankhliao]

i believe this is working as expected as the standard library is not precompiled as part of the distribution but part of the user build cache.

[thomaspeugeot]

The first go build command reconstructs the cache, including the standard library. The second build command, the one that is timed, only builds the tree package. Therefore, i do not think this is the normal behavior. 

[cespare]

Reopening. Thanks for the easy reproducer @thomaspeugeot.

[seankhliao]

is there antivirus or other endpoint security software on the machine?

and where does it spend its time if you use go build -x

[thomaspeugeot]

is there antivirus or other endpoint security software on the machine?

No

[cespare]

I can reproduce locally on my Linux machine.

The time is spent actually running compile (i.e. gc).

I looked at a CPU profile and it's not obvious what's wrong, but there's a lot of GC. A heap profile shows a bunch of SSA-related allocations but I don't have enough experience debugging the compiler to know what's wrong based on that. The heap grows to 2.5 GB when compiling this which seems excessive? If I had to guess, something about this code causes the compiler to generate a rather large/inefficient internal representation of something.

[cespare]

BTW, it doesn't take 45s for me, but about 10s. I'm on a beefy desktop machine, though. I compared to a few other Go programs of similar size and compiling them (when deps are cached) takes roughly 200-500ms for me, so it's still >1 order of magnitude slower than I'd expect.

[seankhliao]

maybe it's the generics like with #51957 ? though there's less code here

[mauri870]

A brief look at cpu and mem profiles I can see that the compiler is taking a beating to compile all the switch statements over generics in the code.

Edit: a lot of time spent in ssa.Compile, cse, deadcode and prove passes