在Golang 游戲leaf系列(七) 監(jiān)聽關(guān)閉的destroy中看到如下代碼
func destroy(m *module) {
defer func() {
if r := recover(); r != nil {
if conf.LenStackBuf > 0 {
buf := make([]byte, conf.LenStackBuf)
l := runtime.Stack(buf, false)
log.Error("%v: %s", r, buf[:l])
} else {
log.Error("%v", r)
}
}
}()
m.mi.OnDestroy()
}
參考配置conf.LenStackBuf=4096脊髓,這段關(guān)于錯誤處理的代碼脱茉,在leaf別的地方也有遇到大莫,到底是干啥的
參考
調(diào)試?yán)鳎篸ump goroutine 的 stacktrace
Stack trace是指堆椄岱桑回溯信息,在當(dāng)前時間枝誊,以當(dāng)前方法的執(zhí)行點開始,回溯調(diào)用它的方法的方法的執(zhí)行點惜纸,然后繼續(xù)回溯叶撒,這樣就可以跟蹤整個方法的調(diào)用,大家比較熟悉的是JDK所帶的jstack工具,可以把Java的所有線程的stack trace都打印出來耐版。
它有什么用呢痊乾?用處非常的大,當(dāng)應(yīng)用出現(xiàn)一些狀況的時候椭更,比如某個模塊不執(zhí)行哪审, 鎖競爭、CPU占用非常高等問題虑瀑, 又沒有足夠的log信息可以分析湿滓,那么可以查看stack trace信息,看看線程都被阻塞或者運行在那些代碼上舌狗,然后定位問題所在叽奥。
一、正常情況下輸出stacktrace
1.runtime/debug.PrintStack()打出當(dāng)前goroutine的stacktrace
package main
import (
"fmt"
"runtime/debug"
)
func test1() {
test2()
}
func test2() {
test3()
}
func test3() {
fmt.Printf("%s", debug.Stack())
debug.PrintStack()
}
func main() {
test1()
}
-----------
$ go run test_stacktrace.go
goroutine 1 [running]:
runtime/debug.Stack(0x0, 0x0, 0x0)
/usr/lib/golang/src/runtime/debug/stack.go:24 +0x80
main.test3()
/tmp/test_stacktrace.go:17 +0x24
main.test2()
/tmp/test_stacktrace.go:13 +0x14
main.test1()
/tmp/test_stacktrace.go:9 +0x14
main.main()
/tmp/test_stacktrace.go:22 +0x14
從上面代碼可以看出痛侍,可以通過 debug.PrintStack() 直接打印朝氓,也可以通過 debug.Stack() 方法獲取堆棧然后自己打印。
2.pprof打印出所有g(shù)oroutine的 stacktrace
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)
}
3.通過系統(tǒng)信號
你可以使用runtime.Stack
得到所有的goroutine的stack trace信息主届,事實上前面debug.PrintStack()也是通過這個方法獲得的赵哲。
為了更方便的隨時的得到應(yīng)用所有的goroutine的stack trace信息,我們可以監(jiān)聽SIGUSER1信號君丁,當(dāng)收到這個信號的時候就將stack trace打印出來枫夺。發(fā)送信號也很簡單,通過kill -SIGUSER1 <pid>就可以绘闷,不必?fù)?dān)心kill會將程序殺死橡庞,它只是發(fā)了一個信號而已较坛。
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)
}
這是docker代碼庫中的一段代碼,很簡單扒最,也很強大丑勤。
要注意的是,buf需要先指定大小吧趣,然后才能使用runtime.Stack(buf, true)
法竞。然后就是第二個參數(shù)是個bool變量,如果為true是獲取所有g(shù)oroutine的stacktrace再菊,為false則是獲取當(dāng)前的。
現(xiàn)在看看leaf那段代碼颜曾,能看懂了吧
defer func() {
if r := recover(); r != nil {
if conf.LenStackBuf > 0 {
buf := make([]byte, conf.LenStackBuf)
l := runtime.Stack(buf, false)
log.Error("%v: %s", r, buf[:l])
} else {
log.Error("%v", r)
}
}
}()
如果有錯誤需要recover纠拔,就把stacktrace內(nèi)容輸出到log.Error里。
二泛豪、異常退出情況下輸出stacktrace
1.通過panic
如果應(yīng)用中有沒recover的panic,或者應(yīng)用在運行的時候出現(xiàn)運行時的異常稠诲,那么程序自動會將當(dāng)前的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)
}
-----------------------------
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方法,它在這一行調(diào)用m1方法价卤,m1方法在第13行調(diào)用m2方法劝萤,m2方法在第17行調(diào)用m3方法,m3方法在第21出現(xiàn)panic慎璧, 它們運行在goroutine 1中床嫌,當(dāng)前goroutine 1的狀態(tài)是running狀態(tài)。
如果想讓它把所有的goroutine信息都輸出出來胸私,可以設(shè)置 GOTRACEBACK=1:
GOTRACEBACK=1 go run p.go
panic: panic from m3
goroutine 1 [running]:
panic(0x596a0, 0xc42000a1b0)
/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
goroutine 4 [sleep]:
time.Sleep(0x34630b8a000)
/usr/local/Cellar/go/1.7.4/libexec/src/runtime/time.go:59 +0xe1
main.a()
/Users/yuepan/go/src/github.com/smallnest/dump/p.go:25 +0x30
created by main.main
/Users/yuepan/go/src/github.com/smallnest/dump/p.go:8 +0x35
exit status 2
同樣你也可以分析這個stack trace的信息厌处,得到方法調(diào)用點的情況,同時這個信息將兩個goroutine的stack trace都打印出來了岁疼,而且goroutine 4的狀態(tài)是sleep狀態(tài)阔涉。
Go官方文檔對這個環(huán)境變量有介紹:
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, and then exits with exit code 2. The failure prints stack traces for all goroutines if there is no current goroutine or the failure is 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 stack frames for run-time functions and shows goroutines created internally by the run-time. GOTRACEBACK=crash is like “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 are 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.
你可以設(shè)置 none、all捷绒、system瑰排、single、crash暖侨,歷史原因凶伙, 你可以設(shè)置數(shù)字0、1它碎、2函荣,分別代表none显押、all、system傻挂。
2.通過SIGQUIT信號
如果程序沒有發(fā)生panic,但是程序有問題乘碑,"假死“不工作,我們想看看哪兒出現(xiàn)了問題金拒,可以給程序發(fā)送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资铡。