GO “jstack”

314 阅读4分钟

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 杀死这个程序,程序在退出的时候输出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 就可以,不必担心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.