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: extra stack frames in Go 1.12beta2 compared to 1.11 #29919

Closed
bsiegert opened this issue Jan 24, 2019 · 5 comments

Comments

Projects
None yet
4 participants
@bsiegert
Copy link
Contributor

commented Jan 24, 2019

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

$ go version
go version devel +4b3f04c63b Thu Jan 10 18:15:48 2019 +0000 linux/amd64

(compiled at the go1.12beta2 tag)

Does this issue reproduce with the latest release?

This has broken some code that was working before, with Go 1.11.

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

go env Output
$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/usr/local/google/home/bsiegert/.cache/go-build"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/usr/local/google/home/bsiegert"
GOPROXY=""
GORACE=""
GOROOT="/usr/local/google/home/bsiegert/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/google/home/bsiegert/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
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-build007408240=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Here is a minimal test case. main.go:

package main

import _ "./package"

func main() {}

package/testcase.go:

package pkg

import "runtime/debug"

func init() {
	ps()
}

var v = ps()

func ps() int {
	debug.PrintStack()
	return 0
}

What did you expect to see?

Here is what this program prints with Go 1.11.2:

goroutine 1 [running, locked to thread]:
runtime/debug.Stack(0xc000046750, 0x47462e, 0x489c80)
	/usr/lib/google-golang/src/runtime/debug/stack.go:24 +0xa7
runtime/debug.PrintStack()
	/usr/lib/google-golang/src/runtime/debug/stack.go:16 +0x22
_/usr/local/google/home/bsiegert/go112/package.ps(0xc00001e060)
	/usr/local/google/home/bsiegert/go112/package/testcase.go:12 +0x20
goroutine 1 [running, locked to thread]:
runtime/debug.Stack(0x0, 0xc000046750, 0x474b0f)
	/usr/lib/google-golang/src/runtime/debug/stack.go:24 +0xa7
runtime/debug.PrintStack()
	/usr/lib/google-golang/src/runtime/debug/stack.go:16 +0x22
_/usr/local/google/home/bsiegert/go112/package.ps(0x474ce0)
	/usr/local/google/home/bsiegert/go112/package/testcase.go:12 +0x20
_/usr/local/google/home/bsiegert/go112/package.init.0()
	/usr/local/google/home/bsiegert/go112/package/testcase.go:6 +0x22

What did you see instead?

goroutine 1 [running, locked to thread]:
runtime/debug.Stack(0x1, 0xc000048750, 0x47377b)
	/usr/local/google/home/bsiegert/go/src/runtime/debug/stack.go:24 +0x9d
runtime/debug.PrintStack()
	/usr/local/google/home/bsiegert/go/src/runtime/debug/stack.go:16 +0x22
_/usr/local/google/home/bsiegert/go112/package.ps(0x0)
	/usr/local/google/home/bsiegert/go112/package/testcase.go:12 +0x20
_/usr/local/google/home/bsiegert/go112/package.init()
	/usr/local/google/home/bsiegert/go112/package/testcase.go:9 +0x4d
main.init()
	<autogenerated>:1 +0x45
goroutine 1 [running, locked to thread]:
runtime/debug.Stack(0xc00000e020, 0xc000090000, 0x21e)
	/usr/local/google/home/bsiegert/go/src/runtime/debug/stack.go:24 +0x9d
runtime/debug.PrintStack()
	/usr/local/google/home/bsiegert/go/src/runtime/debug/stack.go:16 +0x22
_/usr/local/google/home/bsiegert/go112/package.ps(...)
	/usr/local/google/home/bsiegert/go112/package/testcase.go:12
_/usr/local/google/home/bsiegert/go112/package.init.0()
	/usr/local/google/home/bsiegert/go112/package/testcase.go:6 +0x21
_/usr/local/google/home/bsiegert/go112/package.init()
	<autogenerated>:1 +0x5d
main.init()
	<autogenerated>:1 +0x45

There is an extra main.init frame in both traces, plus a package.init one. The top-level var initializer is now within package.init, whereas before, there was no mention in the backtrace.

Is this an actual regression in the face of the Go 1 compatibility promise? Or was it wrong for code to rely on this? (Note that our code was examining the result of runtime.Callers programmatically.)

@bcmills

This comment has been minimized.

Copy link
Member

commented Jan 24, 2019

CC @randall77

This is almost certainly a consequence of the fix for #28640.

@randall77

This comment has been minimized.

Copy link
Contributor

commented Jan 25, 2019

Yeah, this doesn't look right. I will try and fix.

Init functions are special because they contain some generated code and some user code. The decision to print the frame used to use the actual file/line of the location the call happened. Now it uses the file/line of the function definition. This normally wouldn't matter, but for init functions. Possibly we could go back to the old method, although it is tricky to get the information to where it is needed. Another fix would be to split out the user code into a separate function. The outer function would be wrapper and the inner function wouldn't be. From the code to generate init functions, we'd pull step 7 into a separate function:

//      var initdone· uint8                             (1)
//      func init() {                                   (2)
//              if initdone· > 1 {                      (3)
//                      return                          (3a)
//              }
//              if initdone· == 1 {                     (4)
//                      throw()                         (4a)
//              }
//              initdone· = 1                           (5)
//              // over all matching imported symbols
//                      <pkg>.init()                    (6)
//              { <init stmts> }                        (7)
//              init.<n>() // if any                    (8)
//              initdone· = 2                           (9)
//              return                                  (10)
//      }

@randall77 randall77 self-assigned this Jan 25, 2019

@randall77 randall77 added this to the Go1.12 milestone Jan 25, 2019

@gopherbot

This comment has been minimized.

Copy link

commented Jan 25, 2019

Change https://golang.org/cl/159717 mentions this issue: cmd/compile: hide init functions in tracebacks

@gopherbot gopherbot closed this in eafe9a1 Jan 27, 2019

@gopherbot

This comment has been minimized.

Copy link

commented Jan 28, 2019

Change https://golang.org/cl/159877 mentions this issue: doc: mention init traceback change in Go 1.12 release notes

gopherbot pushed a commit that referenced this issue Jan 28, 2019

doc: mention init traceback change in Go 1.12 release notes
Updates #29919

Change-Id: Ibf92c9957f71394f08c1203a29eae35a12021585
Reviewed-on: https://go-review.googlesource.com/c/159877
Run-TryBot: Ian Lance Taylor <iant@golang.org>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Reviewed-by: Keith Randall <khr@golang.org>
@gopherbot

This comment has been minimized.

Copy link

commented Mar 18, 2019

Change https://golang.org/cl/167780 mentions this issue: cmd/compile: rename init function from init.ializers back to init

gopherbot pushed a commit that referenced this issue Mar 18, 2019

cmd/compile: rename init function from init.ializers back to init
The name change init -> init.ializers was initially required for
initialization code.

With CL 161337 there's no wrapper code any more, there's a data
structure instead (named .inittask). So we can go back to just
plain init appearing in tracebacks.

RELNOTE=yes

Update #29919. Followon to CL 161337.

Change-Id: I5a4a49d286df24b53b2baa193dfda482f3ea82a5
Reviewed-on: https://go-review.googlesource.com/c/go/+/167780
Run-TryBot: Keith Randall <khr@golang.org>
Reviewed-by: Josh Bleecher Snyder <josharian@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.