Profiling the `go` tool itself?

161 views
Skip to first unread message

opennota

unread,
Oct 2, 2024, 1:11:10 PM10/2/24
to golang-nuts
Cold-start builds are slow af on my machine (think tens of minutes), and have been like that since around Go 1.20. (See also maybe related https://github.com/golang/go/issues/38939). Is there a way to profile `go build` to determine why it takes it so long to build even a simple hello-world program?

Thanks.

Ian Lance Taylor

unread,
Oct 2, 2024, 1:21:30 PM10/2/24
to opennota, golang-nuts
On Wed, Oct 2, 2024 at 10:11 AM opennota <open...@gmail.com> wrote:
>
> Cold-start builds are slow af on my machine (think tens of minutes), and have been like that since around Go 1.20. (See also maybe related https://github.com/golang/go/issues/38939). Is there a way to profile `go build` to determine why it takes it so long to build even a simple hello-world program?

In some cases you can get an initial look by running "go build -x
-toolexec time PROG". Although the output is a bit cluttered, that
will show you the commands being executed and how long they take to
run. Perhaps that will suggest something.

Ian

opennota

unread,
Oct 2, 2024, 2:53:18 PM10/2/24
to golang-nuts
I'm seeing lots of GOCACHE accesses, but there's a considerable delay after `go build -x -toolexec time` prints `WORK=/tmp/go-build329465119` and before it starts to print all the other commands/package names/times.

Ian Lance Taylor

unread,
Oct 2, 2024, 4:25:57 PM10/2/24
to opennota, golang-nuts
On Wed, Oct 2, 2024 at 11:53 AM opennota <open...@gmail.com> wrote:
>
> I'm seeing lots of GOCACHE accesses, but there's a considerable delay after `go build -x -toolexec time` prints `WORK=/tmp/go-build329465119` and before it starts to print all the other commands/package names/times.

Hmmm, OK, then maybe you do need to profile cmd/go. I don't think
there is any trivial way to do that. You could do it by editing
cmd/go/main.go to create a CPU profile (see
runtime/pprof.StartCPUProfile), but as far as I know that code isn't
already there.

Most likely your module graph is very large, but tens of minutes is an
unreasonable length of time. How long are your go.mod and go.sum
files? Have you run "go mod tidy"?

Ian



> On Thursday 3 October 2024 at 00:21:30 UTC+7 Ian Lance Taylor wrote:
>>
>> On Wed, Oct 2, 2024 at 10:11 AM opennota <open...@gmail.com> wrote:
>> >
>> > Cold-start builds are slow af on my machine (think tens of minutes), and have been like that since around Go 1.20. (See also maybe related https://github.com/golang/go/issues/38939). Is there a way to profile `go build` to determine why it takes it so long to build even a simple hello-world program?
>>
>> In some cases you can get an initial look by running "go build -x
>> -toolexec time PROG". Although the output is a bit cluttered, that
>> will show you the commands being executed and how long they take to
>> run. Perhaps that will suggest something.
>>
>> Ian
>
> --
> You received this message because you are subscribed to the Google Groups "golang-nuts" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/e30076ba-a442-4faa-a87c-40dab866c388n%40googlegroups.com.

Brian Candler

unread,
Oct 2, 2024, 5:30:38 PM10/2/24
to golang-nuts
On Wednesday 2 October 2024 at 18:11:10 UTC+1 opennota wrote:
Cold-start builds are slow af on my machine (think tens of minutes), and have been like that since around Go 1.20.

Have you ruled out that it's not anything to do with the automatic fetching of toolchains, introduced in 1.21 I think? But it still shouldn't take "tens of minutes" unless you have a very slow connection.

It's very weird if even "hello world" is affected. You could try:

strace -f -tt go build hello.go 2>strace.out

and then look in strace.out to see if there are any long pauses, and if so, what was going on around that time.

opennota

unread,
Oct 25, 2024, 12:04:57 AM10/25/24
to golang-nuts
Tentatively, most of the slowdown was caused by the eCryptFS layer (encrypted $HOME). But it probably means Go does too many FS syscalls, since Rust was tenfold faster.

jake...@gmail.com

unread,
Oct 25, 2024, 8:33:36 AM10/25/24
to golang-nuts
May be related to this gonuts post. As of go 1.19 I (and others) get slow builds on Windows, apparently because of excessive file reads on every build. I was getting 2,000 standard library files read, in their entirety, to build hello world every time.
Reply all
Reply to author
Forward
0 new messages