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

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

go version :

go version go1.9.2 darwin/amd64

go env:

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"

我的示例代码是这样的：

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()
}

然后呢，我期望的结果：

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。

为什么会出现这种让人困惑的现象，通过查看go 官方issue 和 release note 发现下面解释：

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 都是正常的。

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

鼎铭

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