一个go1.9.x 编译器内联引发的栈信息错乱的问题分析

    背景是在写个日志库,日志库有个很重要的功能就是要打印出调用栈,知道具体是哪一个文件,哪一个函数调用的Info 等。 而后在测试中发现了一种写法,我本身本机测试一直ok, 可是业务使用的时候调用栈始终不对,打的调用栈少了一层。莫名其妙的,后来对比发现,咱们就是go version 不同。git

    go version :github

go version go1.9.2 darwin/amd64

   go env:golang

GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="darwin"
GOOS="darwin"
GOPATH="/Users/didi/Desktop/didi"
GORACE=""
GOROOT="/usr/local/go1.9.2"
GOTOOLDIR="/usr/local/go1.9.2/pkg/tool/darwin_amd64"
GCCGO="gccgo"
CC="clang"
GOGCCFLAGS="-fPIC -m64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/var/folders/2w/tt1p_4td3yq9xlbl7c2t4jn00000gn/T/go-build427754844=/tmp/go-build -gno-record-gcc-switches -fno-common"
CXX="clang++"
CGO_ENABLED="1"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"

个人示例代码是这样的:bash

package main

import (
	"fmt"
	"runtime"
)

var i []byte

type AAA struct {
}

func (a *AAA) test1() *AAA {
	buf := make([]byte, 1<<20)
	runtime.Stack(buf, true)
	fmt.Printf("\n%s", buf)
	return a
}

func (a *AAA) test2() *AAA {
	i = append(i, "test2"...)
	return a
}

func test() {
	a := AAA{}
	a.test1().test2()
}

func main() {
	test()
}

而后呢,我指望的结果:app

goroutine 1 [running]:
main.(*AAA).test1(0xc420045f60, 0x1003a4c)
	/Users/didi/Desktop/didi/src/test/testCall/main.go:15 +0x87
main.test()
	/Users/didi/Desktop/didi/src/test/testCall/main.go:27 +0x2f
main.main()
	/Users/didi/Desktop/didi/src/test/testCall/main.go:31 +0x20

可是真实结果是这样的:函数

goroutine 1 [running]:
main.(*AAA).test1(0xc42003df48, 0xc42003df70)
	/Users/didi/Desktop/didi/src/test/testCall/main.go:15 +0x87
main.(*AAA).test2(...)
	/Users/didi/Desktop/didi/src/test/testCall/main.go:27
main.test()
	/Users/didi/Desktop/didi/src/test/testCall/main.go:27 +0x2f
main.main()
	/Users/didi/Desktop/didi/src/test/testCall/main.go:31 +0x20

    问题来了,我日志库封装要是有这种相似逻辑,那打印的日志全都是有问题的,怎么多是test2调用test1? 莫名其妙的。。。测试

    初步怀疑是内联引发的问题,这里现象看着很像。编译,加上不容许内联后,问题解决,  解决方式蛮简单的,函数前加个 // go:noinline。ui

    为何会出现这种让人困惑的现象,经过查看go 官方issue 和 release note  发现下面解释:debug

Users of runtime.Callers should avoid directly inspecting the resulting PC slice and instead use runtime.CallersFrames to get a complete view of the call stack, or runtime.Caller to get information about a single caller. This is because an individual element of the PC slice cannot account for inlined frames or other nuances of the call stack.
// 使用runtime.Caller 不能显示内联的细微区别。

Specifically, code that directly iterates over the PC slice and uses functions such as runtime.FuncForPC to resolve each PC individually will miss inlined frames. To get a complete view of the stack, such code should instead use CallersFrames. Likewise, code should not assume that the length returned by Callers is any indication of the call depth. It should instead count the number of frames returned by CallersFrames.

Code that queries a single caller at a specific depth should use Caller rather than passing a slice of length 1 to Callers.

runtime.CallersFrames has been available since Go 1.7, so code can be updated prior to upgrading to Go 1.9.

   而后官方有人提了这个issue, https://github.com/golang/go/issues/22916。总结就是,官方在1.9 的时候以为1.8及之前版本的不对,Caller 应该将内联栈也算进去。而后后来你们以为这种使用不符合习惯,在1.10 又改回去了。我我的试了下,1.10.x, 1.11.x 都是正常的。3d

    这种问题,大多数人应该遇不上,一个是要求链式调用的写法,第二个得关心调用栈,才会遇到这种奇怪现象。

相关文章
相关标签/搜索