Skip to content

GoTip: New Stack Trace Output Wrong #46708

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

Closed
ardan-bkennedy opened this issue Jun 11, 2021 · 5 comments
Closed

GoTip: New Stack Trace Output Wrong #46708

ardan-bkennedy opened this issue Jun 11, 2021 · 5 comments

Comments

@ardan-bkennedy
Copy link

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

$ gotip version
go version devel go1.17-770f1de8c5 Thu Jun 10 20:20:58 2021 +0000 darwin/amd64

Does this issue reproduce with the latest release?

NO, this is fine in 1.16

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

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/Users/bill/Library/Caches/go-build"
GOENV="/Users/bill/Library/Application Support/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOINSECURE=""
GOMODCACHE="/Users/bill/code/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="darwin"
GOPATH="/Users/bill/code/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/darwin_amd64"
GOVCS=""
GOVERSION="go1.16.5"
GCCGO="gccgo"
AR="ar"
CC="clang"
CXX="clang++"
CGO_ENABLED="1"
GOMOD="/Users/bill/code/go/src/github.com/ardanlabs/gotraining/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 -arch x86_64 -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/6l/gplcbsd16y14gzx7wzyv_dtc0000gn/T/go-build4139548450=/tmp/go-build -gno-record-gcc-switches -fno-common"

What did you do?

Given this program
https://github.com/ardanlabs/gotraining/blob/master/topics/go/profiling/stack_trace/example1/example1.go

package main

func main() {
    example(make([]string, 2, 4), "hello", 10)
}

//go:noinline
func example(slice []string, str string, i int) error {
    panic("Want stack trace")
}

Running this program with 1.16, I get the following output.

$ go run example1.go
panic: Want stack trace

goroutine 1 [running]:
main.example(0xc000054738, 0x2, 0x4, 0x1073c53, 0x5, 0xa, 0x0, 0xc000054778)
	/Users/bill/code/go/src/github.com/ardanlabs/gotraining/topics/go/profiling/stack_trace/example1/example1.go:13 +0x39
main.main()
	/Users/bill/code/go/src/github.com/ardanlabs/gotraining/topics/go/profiling/stack_trace/example1/example1.go:8 +0x85
exit status 2

This is great, I can see the slice, string and integer that are passed in as parameters.

Slice:  0xc000054738, 0x2, 0x4
String: 0x1073c53, 0x5
Int:    0xa

Now I run this program with tip.

$ gotip run example1.go
panic: Want stack trace

goroutine 1 [running]:
main.example({0x60, 0x10bb6c0, 0xc0000002e8}, {0xc000024060, 0x0}, 0xc0000001a0)
	/Users/bill/code/go/src/github.com/ardanlabs/gotraining/topics/go/profiling/stack_trace/example1/example1.go:13 +0x27
main.main()
	/Users/bill/code/go/src/github.com/ardanlabs/gotraining/topics/go/profiling/stack_trace/example1/example1.go:8 +0x59
exit status 2

It seems I have different values than expected.

Slice:  0x60, 0x10bb6c0, 0xc0000002e8
String: 0xc000024060, 0x0
Int:    0xc0000001a0

I expected to see the same values from 1.16 but in the new format.

main.example({0xc000054738, 0x2, 0x4}, {0x1073c53, 0x5}, 0xa)

Is my assumption correct or am I not reading the stack trace properly?

@cherrymui
Copy link
Member

Dup of #45728. See also the release notes https://tip.golang.org/doc/go1.17#compiler . This is unfortunate.

Closing as a dup. Thanks.

@ardan-bkennedy
Copy link
Author

I read 45728. I’m not clear on the conclusion?

Is it being said that stack traces will no longer be accurate displaying input values moving forward because of the ABI change and a decision needs to be made to determine if it will be fixed?

@cherrymui
Copy link
Member

There are complex tradeoffs here. It is possible to more accurate values, or print something like "unknown" for cases we cannot accurately determine, but the costs are extra code complexity and (a non-trivial increase of) binary size.

The argument dump is best effort (e.g. gccgo never printed arguments) and mostly for debugging purpose (the hex dump isn't a user-friendly format). Given that previously it may already inaccurate (e.g. if a parameter is reassigned within the function, it may or may not get the update), I'm inclined to leave it as is for 1.17. We may improve it in the future.

@ardan-bkennedy
Copy link
Author

That’s fair. Thank you for the detailed response. I hope there is a way to provide this functionality again in the future. I’ve used it to effectively fix bugs.

@cherrymui
Copy link
Member

Thanks. Good to know that it was helpful to you.

Also note that if the arguments are actually used within the function (especially, used after the panic point), it is likely to be accurate (modulo reassignment as before). It is still possible to still be inaccurate, due to bugs (argument sometimes spill to wrong location) which we intend to fix but didn't get it done in 1.17, and will hopefully be fixed in 1.18.

@golang golang locked and limited conversation to collaborators Jun 11, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants