Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

runtime: setting GODEBUG=*trace=1 during go build causes the printed output to be cached for future builds #41973

Closed
zikaeroh opened this issue Oct 14, 2020 · 7 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.

Comments

@zikaeroh
Copy link
Contributor

What version of Go are you using (go version)?

$ go version
go version devel +a3bc52b786 Wed Oct 14 13:38:41 2020 +0000 linux/amd64

Does this issue reproduce with the latest release?

On tip, yes.

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/jake/.cache/go-build"
GOENV="/home/jake/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/jake/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/jake/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/jake/sdk/gotip"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/jake/sdk/gotip/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/jake/zikaeroh/hortbot/hortbot2/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build221597016=/tmp/go-build -gno-record-gcc-switches"
GOROOT/bin/go version: go version devel +a3bc52b786 Wed Oct 14 13:38:41 2020 +0000 linux/amd64
GOROOT/bin/go tool compile -V: compile version devel +a3bc52b786 Wed Oct 14 13:38:41 2020 +0000
uname -sr: Linux 5.8.14-zen1-1-zen
/usr/lib/libc.so.6: GNU C Library (GNU libc) release release version 2.32.
gdb --version: GNU gdb (GDB) 9.2

What did you do?

I was trying out the new GODEBUG=inittrace=1 support, so I ran GODEBUG=inittrace=1 gotip build. This was probably a mistake; I really just wanted to test it on the output binary. No problem, I just ran the resulting binary with the option instead and saw the output I wanted.

Later, I ran gotip build again.

What did you expect to see?

A blank output.

What did you see instead?

I was surprised to see that the init tracing was still enabled, even though I didn't have GODEBUG set in my environment. The packages being listed were the packages I had previously built.

It seems like this option might be missing from a cache hash somewhere. Clearing the build cache (or updating gotip) fixes the issue. But, I've read the CL, and it doesn't seem to modify the compiler in any way, so I have no idea what's going on.

@martisch

@zikaeroh zikaeroh changed the title runtime: setting GODEBUG=inittrace=1 during go build causes it the setting to be cached for future builds runtime: setting GODEBUG=inittrace=1 during go build causes the setting to be cached for future builds Oct 14, 2020
@martisch
Copy link
Contributor

martisch commented Oct 14, 2020

This is odd because inittrace is purely a runtime thing it should not effect the build process. Can you reproduce the behaviour with 'gctrace' too?

What might happen is that stdout somehow gets mixed into some permanent build output but that would be a general problem.

@cherrymui
Copy link
Member

cherrymui commented Oct 14, 2020

I guess it caches the inittrace of the compiler/assembler/linker.

#27628 should address this.

@zikaeroh
Copy link
Contributor Author

zikaeroh commented Oct 14, 2020

Yep, same thing happens with gctrace. Repeating my steps again:

$ gotip clean -cache

$ GODEBUG=gctrace=1 gotip build
# lots of trace output

$ gotip build
# trace output for the packages in my project (and deps, though no stdlib?)

So this isn't just restricted to the new inittrace.

@martisch
Copy link
Contributor

martisch commented Oct 14, 2020

I ran the commands from above starting with a clean 'go get golang.org/dl/gotip' and then 'gotip download' and then the sequence of above commands posted and I can not reproduce the problem on a toy hello world program on darwin.

Not sure how complex the program is gotip build is compiling but can you reproduce this with a toy hello world program? It might be that some more sophisticated part of the toolchain somehow includes standard error into some build artifact. Maybe its just the linker as cherrymui points out. Not sure how we can check its the same issue and fixing #27628 will also fix your specific case.

@martisch martisch added NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided. labels Oct 14, 2020
@zikaeroh
Copy link
Contributor Author

zikaeroh commented Oct 14, 2020

All of the packages printed in the second gotip build are for non-stdlib dependencies. If you import something external, it appears to matter. My guess is that the stdlib has already been compiled by the bootstrap process, though that'd seem like it'd negatively affect the trace (if it was skipped for already-built packages), so that's probably not fully true.

Try this reproducer:

package main

import (
	"fmt"

	"rsc.io/quote/v3"
)

func main() {
	fmt.Println(quote.GoV3())
}

Running my steps above, the last gotip build gives me: https://gist.github.com/zikaeroh/ef7c689bc36798fee9e5ca112b6b126b

@martisch
Copy link
Contributor

ack. can reproduce this way.

@martisch martisch changed the title runtime: setting GODEBUG=inittrace=1 during go build causes the setting to be cached for future builds runtime: setting GODEBUG=*trace=1 during go build causes the printed output to be cached for future builds Oct 14, 2020
@rsc
Copy link
Contributor

rsc commented Oct 14, 2020

Duplicate of #27628.

@rsc rsc closed this as completed Oct 14, 2020
@golang golang locked and limited conversation to collaborators Oct 14, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. WaitingForInfo Issue is not actionable because of missing required information, which needs to be provided.
Projects
None yet
Development

No branches or pull requests

5 participants