Golang controlling the depth of the panic stack trace

Origin

During the Golang development process, there was a problem: An exception occurred while running a program written by Golang, with the following information:

bjlvxin@bjlvxin-Vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$ go versiongo version go1.10.3 linux/amd64bjlvxin@bjlvxin-Vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$ ./build.sh bjlvxin@bjlvxin-Vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$ ./mygate panic: http: multiple registrations for /debug/requestsgoroutine 1 [running]:net/http.(*ServeMux).Handle(0x149f340, 0xdbfe9b, 0xf, 0xe524a0, 0xdf2318)    /software/servers/go1.10.3/src/net/http/server.go:2353 +0x239net/http.(*ServeMux).HandleFunc(0x149f340, 0xdbfe9b, 0xf, 0xdf2318)    /software/servers/go1.10.3/src/net/http/server.go:2368 +0x55net/http.HandleFunc(0xdbfe9b, 0xf, 0xdf2318)    /software/servers/go1.10.3/src/net/http/server.go:2380 +0x4bgolang.org/x/net/trace.init.0()    /sourcecode/go/work/src/golang.org/x/net/trace/trace.go:115 +0x42

Seeing such a stack of errors, I was also drunk and had no real value at all. It is not visible from the error stack which package is referenced to cause duplicate registration of/debug/requests.

Solution Solutions

There are two scenarios that can solve this problem and thus show more error stack information:

Scenario One: Reduce the Golang version

The version of Golang I used earlier was: 1.10.3, after replacing the Golang version with 1.9.0, recompiling and running, you can see that more information is printed:

bjlvxin@bjlvxin-vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$ Go Versiongo version go1.9.2 linux/ amd64bjlvxin@bjlvxin-vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$./build.shbjlvxin@ bjlvxin-vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$./mygate panic:http:multiple Registrations For/debug/requestsgoroutine 1 [running]:net/http. (*servemux). Handle (0x152e9c0, 0xe32ad5, 0xf, 0x13617e0, 0xe64468)/software/servers/go1.9.2/src/net/http/server.go:2270 + 0x627net/http. (*servemux). Handlefunc (0x152e9c0, 0xe32ad5, 0xf, 0xe64468)/software/servers/go1.9.2/src/net/http/server.go:2302 +0x55net/http. Handlefunc (0xe32ad5, 0xf, 0xe64468)/software/servers/go1.9.2/src/net/http/server.go:2314 +0x4bgolang.org/x/net/    trace.init.0 ()/sourcecode/go/work/src/golang.org/x/net/trace/trace.go:115 +0x42golang.org/x/net/trace.init () <autogenerated>:1 +0x1cdgoogle.golang.org/grpc.init () <autogenerated>:1 +0x9bvitess.io/vitess/go/vt/cAllinfo.init () <autogenerated>:1 +0x53github.com/tiger/mygate/gate.init () <autogenerated>:1 + 0xaamain.init () <autogenerated>:1 +0x4e

As you can see from the output above, after changing the version of Golang to 1.9.0, more error stack information is printed, and as you can see, the problem is caused by the execution of the Gate.init () method.

Scenario Two: Setting environment variables: Export Gotraceback=system

By studying the official documentation, we found that you can control how much information the Golang panic stack trace outputs by setting the environment variable Gotraceback. The description is as follows:
The environment variable Gotraceback can control how much information the Go program produces because of an unrecoverable panic or unexpected other run-time exception that results from an incorrect stack output. By default (single), when an error occurs, only the exception stack of the exception goroutine is printed, and all goroutine stacks are printed when there is no current goroutine or panic caused by an error inside the runtime. There are several settings for Gotraceback, which are explained below:
Export Gotraceback=none: Completely omit the panic stack traces.
Export Gotraceback=single (default) prints only part of the stack traces for the current goroutine. All goroutine stacks are printed when there is no current goroutine or panic caused by errors inside the runtime.
Export Gotraceback=all: Prints the stack trace of all goroutine created by the user.
Export Gotraceback=system: Similar to all, except that the Stace trace of the runtime's Goroutine is also shown, and all goroutine created inside the runtime are also displayed.
Export Gotraceback=crash: Similar to the behavior of "system", except that when the program is crash, it is not exited directly, but can be processed in the way specified by the operating system.
For example, in a UNIX operating system, crash sends a SIGABRT signal to trigger core dump. For historical reasons, when the system environment variable gotraceback is set to: 0, 1, and 2, each represents none, all, and system. You can also set the value of the Gotraceback to control the contents of the output stack trace by Settraceback the method in package Runtime/debug, but with this method, You cannot set a value that is lower than the level of the system environment variable. And the level of high and low order is:
None<single<all<system<crash
The specific Settraceback method can be consulted: https://golang.org/pkg/runtime/debug/#SetTraceback.

Add an environment variable to the ~/.BASHRC file #在 gotraceback:export gotraceback=systembjlvxin@bjlvxin-vostro-270:/sourcecode/go/work/src/ github.com/tiger/mygate/cmd$ Vim ~/.bashrcbjlvxin@bjlvxin-vostro-270:/sourcecode/go/work/src/github.com/tiger/ mygate/cmd$ source ~/.bashrcbjlvxin@bjlvxin-vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$./ build.sh bjlvxin@bjlvxin-vostro-270:/sourcecode/go/work/src/github.com/tiger/mygate/cmd$./mygate panic:http: Multiple registrations For/debug/requestsgoroutine 1 [running]:p anic (0xc2e240, 0xc4200315d0)/software/servers/ go1.10.3/src/runtime/panic.go:551 +0x3c1 fp=0xc42007bdd8 sp=0xc42007bd38 pc=0x42b681net/http. (*servemux). Handle (0x149f340, 0xdbfe9b, 0xf, 0xe524a0, 0xdf2318)/software/servers/go1.10.3/src/net/http/server.go:2353 +0x239 FP =0xc42007be38 Sp=0xc42007bdd8 pc=0x8642c9net/http. (*servemux). Handlefunc (0x149f340, 0xdbfe9b, 0xf, 0xdf2318)/software/servers/go1.10.3/src/net/http/server.go:2368 +0x55 fp= 0xc42007be70 Sp=0xc42007be38 pc=0x864375net/hTtp. Handlefunc (0xdbfe9b, 0xf, 0xdf2318)/software/servers/go1.10.3/src/net/http/server.go:2380 +0x4b fp=0xc42007bea0 sp= 0xc42007be70 pc=0x8643dbgolang.org/x/net/trace.init.0 ()/sourcecode/go/work/src/golang.org/x/net/trace/trace.go : +0x42 fp=0xc42007bec8 sp=0xc42007bea0 pc=0x9d3c92golang.org/x/net/trace.init () <autogenerated>:1 +0x158 FP =0XC42007BEF0 Sp=0xc42007bec8 pc=0x9d9088google.golang.org/grpc.init () <autogenerated>:1 +0x9b fp= 0xc42007bf28 sp=0xc42007bef0 pc=0xa39eebvitess.io/vitess/go/vt/callinfo.init () <autogenerated>:1 +0x53 fp= 0xc42007bf38 sp=0xc42007bf28 pc=0xa3c5d3github.com/tiger/mygate/gate.init () <autogenerated>:1 +0xaa fp= 0xc42007bf78 sp=0xc42007bf38 pc=0xba060amain.init () <autogenerated>:1 +0x4e fp=0xc42007bf88 sp=0xc42007bf78 pc= 0xba21aeruntime.main ()/software/servers/go1.10.3/src/runtime/proc.go:186 +0x1ca fp=0xc42007bfe0 sp=0xc42007bf88 pc =0x42d34aruntime.goexit ()/software/servers/go1.10.3/src/runtime/asm_amd64.s:2361 +0x1 Fp=0xc42007bfe8 sp=0xc42007bfe0 pc=0x457fa1goroutine 2 [Force GC (Idle)]:runtime.gopark (0xdf2ed0, 0x149d570, 0xdc053a, 0xf, 0xdf2d14, 0x1)/software/servers/go1.10.3/src/runtime/proc.go:291 +0x11a fp=0xc420058768 sp= 0xc420058748 Pc=0x42d7earuntime.goparkunlock (0x149d570, 0xdc053a, 0xf, 0x14, 0x1)/software/servers/go1.10.3/src/ runtime/proc.go:297 +0x5e fp=0xc4200587a8 sp=0xc420058768 pc=0x42d89eruntime.forcegchelper ()/software/servers/ go1.10.3/src/runtime/proc.go:248 +0xcc fp=0xc4200587e0 sp=0xc4200587a8 pc=0x42d62cruntime.goexit ()/software/ servers/go1.10.3/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc4200587e8 sp=0xc4200587e0 pc=0x457fa1created by runtime.init.4/software/servers/go1.10.3/src/runtime/proc.go:237 +0x35goroutine 3 [GC sweep Wait]:runtime.gopark ( 0xdf2ed0, 0x149dea0, 0xdbe7ab, 0xd, 0x420014, 0x1)/software/servers/go1.10.3/src/runtime/proc.go:291 +0x11a fp=0xc420 058f60 sp=0xc420058f40 Pc=0x42d7earuntime.goparkunlock (0x149dea0, 0XDBE7AB, 0XD, 0x14, 0x1)/software/servers/go1.10.3/src/runtime/proc.go:297 +0x5e fp=0xc420058fa0 sp=0xc420058f60 pc= 0x42d89eruntime.bgsweep (0xc4200440e0)/software/servers/go1.10.3/src/runtime/mgcsweep.go:52 +0xa3 Fp=0xc420058fd8 Sp=0xc420058fa0 pc=0x420073runtime.goexit ()/software/servers/go1.10.3/src/runtime/asm_amd64.s:2361 +0x1 fp= 0xc420058fe0 Sp=0xc420058fd8 pc=0x457fa1created by Runtime.gcenable/software/servers/go1.10.3/src/runtime/mgc.go : 216 +0x58goroutine 4 [Finalizer Wait]:runtime.gopark (0xdf2ed0, 0x14bd6a8, 0xdbf876, 0xe, 0x14, 0x1)/software/servers/ go1.10.3/src/runtime/proc.go:291 +0x11a fp=0xc420059718 sp=0xc4200596f8 pc=0x42d7earuntime.goparkunlock (0X14BD6A8, 0xdbf876, 0xe, 0x14, 0x1)/software/servers/go1.10.3/src/runtime/proc.go:297 +0x5e fp=0xc420059758 sp=0xc420059718 pc= 0x42d89eruntime.runfinq ()/software/servers/go1.10.3/src/runtime/mfinal.go:175 +0xad fp=0xc4200597e0 sp= 0xc420059758 pc=0x41711druntime.goexit ()/software/servers/go1.10.3/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc4200597e8 sp=0xc4200597e0 pc=0x457fa1created by runtime.createfing/software/servers/ go1.10.3/src/runtime/mfinal.go:156 +0x62goroutine 5 [Chan Receive]:runtime.gopark (0xdf2ed0, 0xc4200e4058, 0xdbe01e, 0XC, 0xc420049317, 0x3)/software/servers/go1.10.3/src/runtime/proc.go:291 +0x11a fp=0xc420059e88 sp=0xc420059e68 pc= 0x42d7earuntime.goparkunlock (0xc4200e4058, 0xdbe01e, 0xc, 0x17, 0x3)/software/servers/go1.10.3/src/runtime/proc.go : 297 +0x5e Fp=0xc420059ec8 sp=0xc420059e88 pc=0x42d89eruntime.chanrecv (0xc4200e4000, 0xc420059fb0, 0xc4200e8001, 0xc4200e4000)/software/servers/go1.10.3/src/runtime/chan.go:518 +0x2f2 fp=0xc420059f60 Sp=0xc420059ec8 pc= 0x406082runtime.chanrecv2 (0xc4200e4000, 0xc420059fb0, 0x0)/software/servers/go1.10.3/src/runtime/chan.go:405 + 0x2b fp=0xc420059f90 sp=0xc420059f60 Pc=0x405d7bgithub.com/golang/glog. (*loggingt). Flushdaemon (0X149FC20)/sourcecode/go/work/src/github.com/golang/glog/glog.go:882 +0x8b fp= 0xc420059fd8 sP=0xc420059f90 pc=0x589ebbruntime.goexit ()/software/servers/go1.10.3/src/runtime/asm_amd64.s:2361 +0x1 fp= 0xc420059fe0 Sp=0xc420059fd8 pc=0x457fa1created by github.com/golang/glog.init.0/sourcecode/go/work/src/github.com /golang/glog/glog.go:410 +0x203goroutine [Syscall]:runtime.notetsleepg (0x14a3e20, 0x6fc233bba, 0x0)/software/ servers/go1.10.3/src/runtime/lock_futex.go:227 +0x42 fp=0xc420054760 sp=0xc420054730 Pc=0x410d82runtime.timerproc ( 0x14a3e00)/software/servers/go1.10.3/src/runtime/time.go:261 +0x2e7 fp=0xc4200547d8 sp=0xc420054760 pc= 0x4493a7runtime.goexit ()/software/servers/go1.10.3/src/runtime/asm_amd64.s:2361 +0x1 fp=0xc4200547e0 sp= 0xc4200547d8 pc=0x457fa1created by runtime. (*timersbucket). addtimerlocked/software/servers/go1.10.3/src/runtime/time.go:160 +0x107goroutine 6 [syscall]: RUNTIME.NOTETSLEEPG (0x14bdcc0, 0XFFFFFFFFFFFFFFFF, 0x0)/software/servers/go1.10.3/src/runtime/lock_futex.go:227 + 0x42 fp=0xc42005a780 sp=0xc42005a750 Pc=0x410d82os/sigNAL.SIGNAL_RECV (0x0)/software/servers/go1.10.3/src/runtime/sigqueue.go:139 +0xa6 fp=0xc42005a7a8 sp=0xc42005a780 Pc=0x4414e6os/signal.loop ()/software/servers/go1.10.3/src/os/signal/signal_unix.go:22 +0x22 fp=0xc42005a7e0 sp= 0xc42005a7a8 pc=0x99f782runtime.goexit ()/software/servers/go1.10.3/src/runtime/asm_amd64.s:2361 +0x1 fp= 0xc42005a7e8 sp=0xc42005a7e0 pc=0x457fa1created by os/signal.init.0/software/servers/go1.10.3/src/os/signal/signal _unix.go:28 +0x41

As you can see from the output above, in addition to printing out the error stack information you see in scenario one, you also print stack information in addition to the other goroutine.

Summarize

Do not know why, by default, golang1.10.3 printing error stack information is less than 1.9.0 error stack information, I do not see Golang specific source code, interested classmates, can study the source code of Golang. But we can see that there are two ways to get more goroutine stack information:
(1) Use Golang 1.9.0 version
(2) Export Gotraceback=system

Reference

https://golang.org/pkg/runtime/
https://golang.org/pkg/runtime/debug/#SetTraceback

Lu Xin Personal Original, reproduced please indicate the source