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: runtime.Caller returns invalid zero frame #24108

Closed
ohler opened this issue Feb 25, 2018 · 6 comments
Closed

runtime: runtime.Caller returns invalid zero frame #24108

ohler opened this issue Feb 25, 2018 · 6 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@ohler
Copy link

ohler commented Feb 25, 2018

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

1.10

Does this issue reproduce with the latest release?

yes

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

playground

What did you do?

https://play.golang.org/p/GwgbEnX3_7N

What did you expect to see?

missingFunction (see the link) should be among the return values of runtime.Caller(k) for some k but is not.

What did you see instead?

runtime.Caller returns ok=true but zero values for pc, filePath, and line for the value of k where missingFunction should be.

runtime.Callers does not have this problem.

output from runtime.Caller(k) for k=0..6:

869823 /tmp/sandbox093329260/main.go 16 true main.st.M
0  0 true   <-- this looks wrong
0  0 false 
871455 /tmp/sandbox093329260/main.go 50 true main.main  <-- these duplicates are
871455 /tmp/sandbox093329260/main.go 50 true main.main  <-- also surprising
341311 /usr/local/go/src/runtime/proc.go 198 true runtime.main
562560 /usr/local/go/src/runtime/asm_amd64p32.s 968 true runtime.goexit

output from runtime.Callers/CallersFrames:

{158111 0x130e18 runtime.Callers /usr/local/go/src/runtime/extern.go 212 158016}
{870559 0x16bbd4 main.st.M /tmp/sandbox093329260/main.go 25 869760}
{871167 0x16bc6c main.missingFunction /tmp/sandbox093329260/main.go 44 871040}
{871455 0x16bcd0 main.main /tmp/sandbox093329260/main.go 50 871232}
{341311 0x13f304 runtime.main /usr/local/go/src/runtime/proc.go 198 340576}
{562560 0x14fe18 runtime.goexit /usr/local/go/src/runtime/asm_amd64p32.s 968 562560}

This is a regression in 1.10; for 1.9.2, the program prints

17381142 /Users/ohler/tmp/go-bug/foo.go 16 true main.st.M
17382754 <autogenerated> 1 true main.(*st).M
17382859 <autogenerated> 1 true main.(*wrapper).M
17382379 /Users/ohler/tmp/go-bug/foo.go 44 true main.missingFunction
17382585 /Users/ohler/tmp/go-bug/foo.go 50 true main.main
[...]
@ianlancetaylor ianlancetaylor added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Feb 25, 2018
@ianlancetaylor ianlancetaylor added this to the Go1.10.1 milestone Feb 25, 2018
@odeke-em
Copy link
Member

/cc @aclements @davidlazar

@FiloSottile
Copy link
Contributor

@gopherbot please open a backport tracking issue, as this is a 1.10 regression.

@gopherbot
Copy link

Backport issue(s) opened: #25041 (for 1.10).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

@odeke-em
Copy link
Member

On examining the history of the runtime.Caller edits in extern.go [1]
runtimeexterneditshistory

  1. At 0ea120a, the posted repro panics
$ go run main.go 
devel +0ea120a70c Tue Apr 18 19:56:30 2017 +0000

4717371 /home/emmanuel/Desktop/opensrc/bugs/golang/24108/main.go 24 true main.st.M
4718642 <autogenerated> 1 true main.(*st).M
4718747 <autogenerated> 1 true main.(*wrapper).M
4717275 /home/emmanuel/Desktop/opensrc/bugs/golang/24108/main.go 15 true main.missingFunction
4717145 /home/emmanuel/Desktop/opensrc/bugs/golang/24108/main.go 11 true main.main
4359668 /home/emmanuel/go/src/go.googlesource.com/go/src/runtime/proc.go 185 true runtime.main
4524096 /home/emmanuel/go/src/go.googlesource.com/go/src/runtime/asm_amd64.s 2347 true runtime.goexit
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x4402e2]

goroutine 1 [running]:
main.st.M()
	/home/emmanuel/Desktop/opensrc/bugs/golang/24108/main.go:25 +0xaf
main.(*st).M(0x533078)
	<autogenerated>:1 +0x33
main.(*wrapper).M(0xc42000e2a0)
	<autogenerated>:1 +0x3c
main.missingFunction()
	/home/emmanuel/Desktop/opensrc/bugs/golang/24108/main.go:15 +0x6c
main.main()
	/home/emmanuel/Desktop/opensrc/bugs/golang/24108/main.go:11 +0xba
exit status 2
  1. 032678e is the origin story of the current report

@aclements
Copy link
Member

I've spent a while thinking about this one now, and I'm worried we've managed to back ourselves into a corner with the skip count and how tracebacking is currently structured. The logic behind ignoring frames in CallersFrames (internally, the stackExpander) is pretty complicated. However, the skip count isn't handled by stackExpander; it's handled much earlier, in gentraceback when it's walking the stack. That's why skipping N frames is different from getting the whole traceback and then discarding the first N frames.

It's hard to make these agree. I would love to make stack unwinding internally demand-driven (not unlike CallersFrames), but right now it's all sort of inside-out. Then the unwinder wouldn't have to worry about skips at all and runtime.Caller could just apply all of the frame filtering, discard the first N frames of the filtered stream, and return the next frame. But that's a really complicated change.

As a stop-gap, it may be possible to keep runtime.Caller efficient in the common case of small skip values by unwinding some of the stack without any skip and taking the Nth frame if there is one. If it turns out we didn't unwind enough of the stack, just unwind it again with a larger buffer. We could keep small unwinds on the stack and only heap-allocate for large skip values, which should be incredible rare.

The exact same problem affects runtime.Callers' skip count, and I think the solution there would be roughly the same.

@ianlancetaylor ianlancetaylor modified the milestones: Go1.11, Go1.12 Jul 10, 2018
@randall77
Copy link
Contributor

This should now be fixed by https://go-review.googlesource.com/c/go/+/152537

@golang golang locked and limited conversation to collaborators Dec 28, 2019
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.
Projects
None yet
Development

No branches or pull requests

8 participants