Debug weapon: Dump Goroutine's StackTrace

This is a creation in Article, where the information may have evolved or changed.

Stack trace refers to the stacking backtracking information, at the current time, starting at the point of execution of the current method, backtracking on the execution point of the method that called its method, and then continuing the backtracking so that the entire method's call can be traced, and we are more familiar with the tool that the JDK has. jstack You can print the stack trace of all Java threads.

What's the use of it? Very useful, when the application has some situation, such as a module does not execute, lock competition, CPU occupied very high problem, and not enough log information can be analyzed, then you can view the stack trace information, see the thread is blocked or run on those code, and then locate the problem.

For go development of the program, there is no jstack such a weapon, I have not seen yet, but we can also be easily through other means of output goroutine stack trace information.

This article introduces several methods, especially the last method is more useful.

Output stacktrace in case of abnormal exit

By panic

The program automatically prints the stack trace of the current goroutine if there are recover panic in the application or if the application runs at run time.

For example the following program, if you run will throw a panic.

1234567891011121314151617181920212223242526

Package mainimport ("Time")func Main () {go a () m1 ()}func M1 () { M2 ()}func m2 () {m3 ()}func m3 () {panic("Panic from M3")}func a () { Time. Sleep (time. Hour)}

Output the following stack trace:

123456789101112131415

DumpGoRun p.GoPanic:PanicFrom M3goroutine1[Running]:Panic(0X596A0,0XC42000A1A0)/usr/local/cellar/Go/1.7. 4/libexec/src/runtime/Panic.Go:+0X1A1MAIN.M3 ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go:+0X6DMAIN.M2 ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go:+0X14MAIN.M1 ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go:+0X14main.main ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go: 9+0X3aexit status2

From this message we can see that the 9th line of P.go is the main method, which calls the M1 method on this line, the M1 method calls the M2 method on line 13th, the M2 method calls the M3 method on line 17th, M3 method appears in 21st panic, they run in Goroutine 1, The current status of Goroutine 1 is the running state.

If you want it to output all the Goroutine information, you can set GOTRACEBACK=1 :

1234567891011121314151617181920212223

Gotraceback=1 GoRun p.GoPanic:PanicFrom M3goroutine1[Running]:Panic(0X596A0,0XC42000A1B0)/usr/local/cellar/Go/1.7. 4/libexec/src/runtime/Panic.Go:+0X1A1MAIN.M3 ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go:+0X6DMAIN.M2 ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go:+0X14MAIN.M1 ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go:+0X14main.main ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go: 9+0X3agoroutine4[Sleep]:time. Sleep(0x34630b8a000)/usr/local/cellar/Go/1.7. 4/libexec/src/runtime/time.Go:+0Xe1main.a ()/users/yuepan/Go/src/github.com/smallnest/dump/p.Go:+0X30created by main.main/users/yuepan/Go/src/github.com/smallnest/dump/p.Go: 8+0X35exit status2

You can also analyze the information of this stack trace, get the method call point, and this information will print out the two goroutine stack trace, and Goroutine 4 state is the sleep state.

The Go Official document describes this environment variable:

The Gotraceback variable controls the amount of output generated when a Go program fails due to an unrecovered panic or an Unexpected runtime condition. By default, a failure prints a stack trace for the current goroutine, eliding functions internal to the Run-time system, a nd then exits with exit code 2. The failure prints stack traces for all goroutines if there are no current goroutine or the failure are internal to the run- Time. Gotraceback=none omits the goroutine stack traces entirely. Gotraceback=single (the default) behaves as described above. Gotraceback=all adds stack traces for all user-created goroutines. Gotraceback=system is like ' all ' but adds stacks frames for run-time functions and shows goroutines created internally by T He run-time. Gotraceback=crash is the "system" but crashes in an operating system-specific manner instead of exiting. For example, on Unix systems, the crash raises SIGABRT to trigger a core dump. For historical reasons, the Gotraceback settings 0, 1, anD 2 is synonyms for none, all, and system, respectively. The Runtime/debug package ' s Settraceback function allows increasing the amount of output at run time, but it cannot reduce The amount below that specified by the environment variable. See https://golang.org/pkg/runtime/debug/#SetTraceback.

You can set,,,, none all system single crash , historical reasons, you can but set the number 0 ,, 1 2 , respectively, represent none , all system .

Via Sigquit Signal

If the program does not occur panic, but the program has a problem, "suspended animation" does not work, we want to see where there is a problem, you can send a SIGQUIT signal to the program, you can also output stack trace information.
For example, the following program:

1234567891011121314151617181920212223242526

Package mainimport ("Time")func Main () {go a () m1 ()}func M1 () { M2 ()}func m2 () {m3 ()}func m3 () {time. Sleep (time. Hour)}func A () {time. Sleep (time. Hour)}

You can run to kill -SIGQUIT <pid> kill this program, and the program outputs Strack trace when exiting.

Output StackTrace under normal conditions

The above situation requires the program to exit in order to print out the stack trace information, but sometimes we just need to trace the problem of analyzing the program, and do not want the program to be interrupted. So we need other ways to do that.

You can leak a command, an API, or listen to a signal and then call the appropriate method to print the stack trace.

Print out the current Goroutine StackTrace

The debug.PrintStack() method allows you to print the stack trace of the current goroutine, as in the following program.

12345678910111213141516171819202122232425262728

Package mainimport ("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)}

Print out the stacktrace of all Goroutine

You can pprof.Lookup("goroutine").WriteTo print all of the goroutine stack trace, as in the following program:

1234567891011121314151617181920212223242526272829

Package mainimport ("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)}

The more perfect output stacktrace

You can use the runtime.Stack stack trace information for all the Goroutine, which debug.PrintStack() is actually obtained in the previous way.

In order to get the application of all Goroutine stack trace information at any time, we can monitor the SIGUSER1 signal and print the stack trace when the signal is received. Sending the signal is also very simple, through the kill -SIGUSER1 <pid> can, do not have to worry about kill the program killed, it just sent a signal.

12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849

PackageMainImport("FMT""OS""Os/signal""Runtime""Syscall""Time")funcMain () {setupsigusr1trap ()GoA () M1 ()}funcM1 () {m2 ()}funcM2 () {m3 ()}funcM3 () {time. Sleep (time. Hour)}funcA () {time. Sleep (time. Hour)}funcSetupsigusr1trap () {c: = Make(ChanOs. Signal,1) signal. Notify (c, Syscall. SIGUSR1)Go func() { for RangeC {dumpstacks ()}} ()}funcDumpstacks () {buf: = Make([]byte,16384) BUF = Buf[:runtime. Stack (BUF,true)]fmt. Printf ("= = = BEGIN Goroutine stack dump ===\n%s\n=== END goroutine stack dump = = =", BUF)}

The output is intuitive and easy to check.

1234567891011121314151617181920212223242526272829303132333435363738394041424344454647484950

=== BEGIN goroutine stack dump = = =Goroutine $[Running]:main. Dumpstacks ()/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: -+0x77MAIN.SETUPSIGUSR1TRAP.FUNC1 (0xc420070060)/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: ++0x73Created bymain.setupsigusr1trap/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: the+0xecGoroutine1[Sleep]: Time.Sleep(0x34630b8a000)/usr/Local/cellar/Go/1.7. 4/libexec/src/runtime/ Time.Go: -+0xe1MAIN.M3 ()/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: -+0x30MAIN.M2 ()/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: -+0x14MAIN.M1 ()/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: -+0x14Main.main ()/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: -+0x3fGoroutine the[Syscall]:os/signal.signal_recv (0xff280)/usr/Local/cellar/Go/1.7. 4/libexec/src/runtime/sigqueue.Go: the+0x157Os/signal.loop ()/usr/Local/cellar/Go/1.7. 4/libexec/src/os/signal/signal_unix.Go: A+0x22Created byOs/signal.init. 1/usr/Local/cellar/Go/1.7. 4/libexec/src/os/signal/signal_unix.Go: -+0x41Goroutine *[Select, Locked toThread]:runtime.gopark (0XB5CC8,0x0,0xab3ef,0x6,0x18,0x2)/usr/Local/cellar/Go/1.7. 4/libexec/src/runtime/proc.Go:259+0x13aRuntime.selectgoimpl (0xc42008d730,0x0,0x18)/usr/Local/cellar/Go/1.7. 4/libexec/src/runtime/Select.Go:423+0x11d9Runtime.selectgo (0xc42008d730)/usr/Local/cellar/Go/1.7. 4/libexec/src/runtime/Select.Go:238+0x1cRUNTIME.ENSURESIGM.FUNC1 ()/usr/Local/cellar/Go/1.7. 4/libexec/src/runtime/signal1_unix.Go:304+0x2d1Runtime.goexit ()/usr/Local/cellar/Go/1.7. 4/LIBEXEC/SRC/RUNTIME/ASM_AMD64.S:2086+0x1GoroutinePanax Notoginseng[Sleep]: Time.Sleep(0x34630b8a000)/usr/Local/cellar/Go/1.7. 4/libexec/src/runtime/ Time.Go: -+0xe1Main.a ()/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: ++0x30Created bymain.main/users/yuepan/Go/src/github.com/smallnest/dump/d3.Go: the+0x3a===ENDGoroutine stack dump = = =

Of course, this code is not my original, this is a piece of code in the Docker code base, very simple, very powerful.

Reference documents

1. Http://stackoverflow.com/questions/19094099/how-to-dump-goroutine-stacktraces
2. https://golang.org/pkg/runtime/