记一次golang堆栈打印行号无法对应

前言

由于golang没有原生的try catch，项目里对panic recover做了封装，因为runtime.Stack不能跳过部分堆栈，这会导致每次封装的函数也被打印出来，也没有输出函数名称，所以项目采用了facebookgo/stack这个包做堆栈打印。

这个打印大部分时间是靠谱的，只是偶尔看到一些异常的情况下会对应不上代码的行号。代码文件是对的上的，导致err的代码也就是在附近几行，所以就一直没管。
前几天测试截了个图，明明err的内容是slice越界相关的，异常的行号却提到了一行执行过程中完全不会被调用的代码。

于是就打算趁这次机会一探究竟，可以的话也顺便改造一波项目中的堆栈打印。

复现

简化了代码做了个测试，输出的信息都简化为直接用fmt.Println输出到控制台，测试代码如下

/*
author: zhonghuihong
date: 2022/6/20
*/
package main

import (
	"fmt"
	"github.com/facebookgo/stack"
)

func Try(fun func()) {
	defer func() {
		if err := recover(); err != nil {
			c := stack.Callers(0)
			fmt.Println(err)
			fmt.Println(c.String())
		}
	}()
	fun()
}

func testTryGet() int {
	m := map[int]int{1: 2}
	if _, ok := m[1]; ok {
		return 1
	}
	if len(m) == 0 {
		panic("impossible")
	}
	panic("test")
}

func main() {
	ints := make([]int, 0)
	Try(func() {
		testTryGet()
		println(ints[1])
	})
}

打印出的堆栈内容如下

runtime error: index out of range [1] with length 0
C:/Users/zhonghuihong/go/src/playground/stack.go:15 Try.func1
C:/Go/src/runtime/panic.go:1038                      gopanic
C:/Go/src/runtime/panic.go:90                        goPanicIndex
C:/Users/zhonghuihong/go/src/playground/stack.go:28 testTryGet
C:/Users/zhonghuihong/go/src/playground/stack.go:20 Try
C:/Users/zhonghuihong/go/src/playground/stack.go:36 main
C:/Go/src/runtime/proc.go:255                        main
C:/Go/src/runtime/asm_amd64.s:1581                   goexit

可以看到其中的一行堆栈信息居然指向了testTryGet这个函数的最后一行。但是很明显的是，这行panic函数是不会在执行过程中被调用到的。

查看实现

查看facbookgo/stack包中的Callers实现如下

func Callers(skip int) Stack {
	pcs := make([]uintptr, maxStackSize)
	num := runtime.Callers(skip+2, pcs)
	stack := make(Stack, num)
	for i, pc := range pcs[:num] {
		fun := runtime.FuncForPC(pc)
		file, line := fun.FileLine(pc - 1)
		stack[i].File = StripGOPATH(file)
		stack[i].Line = line
		stack[i].Name = StripPackage(fun.Name())
	}
	return stack
}

可以看到首先调用了runtime包中的Callers返回了pc切片，然后用FuncForPc这个函数去查找对应的函数文件信息、行号、函数名称。

查看了FuncForPc这个函数的实现，在上面的注释发现了端倪

// If pc represents multiple functions because of inlining, it returns
// the *Func describing the innermost function, but with an entry of
// the outermost function.

也就是说如果函数被编译器内联，返回的函数信息是最里层的函数，entry是最外层的函数。也就是被内联后，打印的行号以及函数名称是不准的。

探索解决方案

查了下资料，在编译时加上参数-gcflags="-l"可以禁用内联优化，禁用后的输出如下

runtime error: index out of range [1] with length 0
C:/Users/zhonghuihong/go/src/playground/stack.go:15 Try.func1
C:/Go/src/runtime/panic.go:1038                      gopanic
C:/Go/src/runtime/panic.go:90                        goPanicIndex
C:/Users/zhonghuihong/go/src/playground/stack.go:38 main.func1
C:/Users/zhonghuihong/go/src/playground/stack.go:20 Try
C:/Users/zhonghuihong/go/src/playground/stack.go:36 main
C:/Go/src/runtime/proc.go:255                        main
C:/Go/src/runtime/asm_amd64.s:1581                   goexit

这下行号跟函数就都能对应得上了，可以得出就是编译器内联优化，导致这种堆栈打印的信息跟原始的代码对应不上。

不过内联优化还是对代码的执行速度有提升的，解决方案肯定不能是关掉内联优化，只能再看看golang源码的一些注释了。

看了下runtime.Callers函数的注释提到了CallerFrames函数可以返回内联前的信息，FuncForPC则不行。

// To translate these PCs into symbolic information such as function
// names and line numbers, use CallersFrames. CallersFrames accounts
// for inlined functions and adjusts the return program counters into
// call program counters. Iterating over the returned slice of PCs
// directly is discouraged, as is using FuncForPC on any of the
// returned PCs, since these cannot account for inlining or return
// program counter adjustment.

仿照facebookgo/stack的实现写了个测试代码，打印信息也直接简化为在函数中用fmt.Println输出。

func Callers(skip int) {
	pcs := make([]uintptr, 1024)
	runtime.Callers(skip+2, pcs)
	frames := runtime.CallersFrames(pcs)
	for {
		frame, more := frames.Next()
		fmt.Println(frame.File+":"+strconv.Itoa(frame.Line), frame.Function)
		if !more {
			break
		}
	}
}

测试了一下，这样输出的堆栈信息就能完美对应行号了。