调试利器：dump goroutine 的 stacktrace

Stack trace是指堆栈回溯信息，在当前时间，以当前方法的执行点开始，回溯调用它的方法的方法的执行点，然后继续回溯，这样就可以跟踪整个方法的调用,大家比较熟悉的是JDK所带的jstack工具，可以把Java的所有线程的stack trace都打印出来。

它有什么用呢？用处非常的大，当应用出现一些状况的时候，比如某个模块不执行， 锁竞争、CPU占用非常高等问题， 又没有足够的log信息可以分析，那么可以查看stack trace信息，看看线程都被阻塞或者运行在那些代码上，然后定位问题所在。

对于Go开发的程序，有没有类似jstack这样的利器呢，目前我还没有看到，但是我们可以通过其它途径也很方便的输出goroutine的stack trace信息。

本文介绍了几种方法，尤其是最后介绍的方法比较有用。

异常退出情况下输出stacktrace

通过panic

如果应用中有没recover的panic,或者应用在运行的时候出现运行时的异常，那么程序自动会将当前的goroutine的stack trace打印出来。

比如下面的程序，如果你运行会抛出一个panic。

package main
import (
    "time"
)
func main() {
    go a()
    m1()
}
func m1() {
    m2()
}
func m2() {
    m3()
}
func m3() {
    panic("panic from m3")
}
func a() {
    time.Sleep(time.Hour)
}

输出下面的stack trace:

dump go run p.go
panic: panic from m3
goroutine 1 [running]:
panic(0x596a0, 0xc42000a1a0)
    /usr/local/Cellar/go/1.7.4/libexec/src/runtime/panic.go:500 +0x1a1
main.m3()
    /Users/yuepan/go/src/github.com/smallnest/dump/p.go:21 +0x6d
main.m2()
    /Users/yuepan/go/src/github.com/smallnest/dump/p.go:17 +0x14
main.m1()
    /Users/yuepan/go/src/github.com/smallnest/dump/p.go:13 +0x14
main.main()
    /Users/yuepan/go/src/github.com/smallnest/dump/p.go:9 +0x3a
exit status 2

从这个信息中我们可以看到p.go的第9行是main方法，它在这一行调用m1方法，m1方法在第13行调用m2方法，m2方法在第17行调用m3方法，m3方法在第21出现panic， 它们运行在goroutine 1中，当前goroutine 1的状态是running状态。

如果想让它把所有的goroutine信息都输出出来，可以设置 GOTRACEBACK=1:

通过SIGQUIT信号

如果程序没有发生panic,但是程序有问题，"假死“不工作，我们想看看哪儿出现了问题，可以给程序发送SIGQUIT信号，也可以输出stack trace信息。

比如下面的程序:

package main
import (
    "time"
)
func main() {
    go a()
    m1()
}
func m1() {
    m2()
}
func m2() {
    m3()
}
func m3() {
    time.Sleep(time.Hour)
}
func a() {
    time.Sleep(time.Hour)
}

你可以运行kill -SIGQUIT <pid> 杀死这个程序，程序在退出的时候输出strack trace。（kill -3 pid）

正常情况下输出stacktrace

上面的情况是必须要求程序退出才能打印出stack trace信息，但是有时候我们只是需要跟踪分析一下程序的问题，而不希望程序中断运行。所以我们需要其它的方法来执行。

你可以暴漏一个命令、一个API或者监听一个信号，然后调用相应的方法把stack trace打印出来。

打印出当前goroutine的 stacktrace

通过debug.PrintStack()方法可以将当前所在的goroutine的stack trace打印出来，如下面的程序。

package main
import (
    "runtime/debug"
    "time"
)
func main() {
    go a()
    m1()
}
func m1() {
    m2()
}
func m2() {
    m3()
}
func m3() {
    debug.PrintStack()
    time.Sleep(time.Hour)
}
func a() {
    time.Sleep(time.Hour)
}

打印出所有goroutine的 stacktrace

可以通过pprof.Lookup("goroutine").WriteTo将所有的goroutine的stack trace都打印出来，如下面的程序：

package main
import (
    "os"
    "runtime/pprof"
    "time"
)
func main() {
    go a()
    m1()
}
func m1() {
    m2()
}
func m2() {
    m3()
}
func m3() {
    pprof.Lookup("goroutine").WriteTo(os.Stdout, 1)
    time.Sleep(time.Hour)
}
func a() {
    time.Sleep(time.Hour)
}

较完美的输出 stacktrace

你可以使用runtime.Stack得到所有的goroutine的stack trace信息，事实上前面debug.PrintStack()也是通过这个方法获得的。

为了更方便的随时的得到应用所有的goroutine的stack trace信息，我们可以监听SIGUSER1信号，当收到这个信号的时候就将stack trace打印出来。发送信号也很简单，通过kill -SIGUSER1 <pid>就可以，不必担心kill会将程序杀死，它只是发了一个信号而已。

package main
import (
    "fmt"
    "os"
    "os/signal"
    "runtime"
    "syscall"
    "time"
)
func main() {
    setupSigusr1Trap()
    go a()
    m1()
}
func m1() {
    m2()
}
func m2() {
    m3()
}
func m3() {
    time.Sleep(time.Hour)
}
func a() {
    time.Sleep(time.Hour)
}
func setupSigusr1Trap() {
    c := make(chan os.Signal, 1)
    signal.Notify(c, syscall.SIGUSR1)
    go func() {
        for range c {
            DumpStacks()
        }
    }()
}
func DumpStacks() {
    buf := make([]byte, 16384)
    buf = buf[:runtime.Stack(buf, true)]
    fmt.Printf("=== BEGIN goroutine stack dump ===\n%s\n=== END goroutine stack dump ===", buf)
}

配置 http/pprof

如果你的代码中配置了 http/pprof,你可以通过下面的地址访问所有的groutine的堆栈：

http://localhost:8888/debug/pprof/goroutine?debug=2.