Go Stack Trace
William Kennedy寫了兩篇關于Go 調試的文章,非常不錯,特意翻譯了一下,加深記憶。本文是其中的一篇: Stack Traces In Go。 另一篇是 Scheduler Tracing In Go。
Stack Trace表示堆棧跟蹤,這是一個或多個堆棧幀的有序的集合。在程序出現panic的時候你會看到控制臺有Stack Trace信息打印出來。
介紹
擁有基本的調試Go程序技能可以節省程序員很大的時間來發現問題。我當然相信你可以使用log信息來跟蹤問題,但是有時候panic發生的時候log信息并沒有提供充足的信息。如果你理解堆棧跟蹤的信息,你可以即時的找出bug, 這和傳統的利用日志追蹤bug有很大的不同, 因為利用日志的話你需要增加更多的log然后再等待相同的錯誤發生。
自打我開始寫Go程序的時候我就一直看堆棧跟蹤信息。有些地方我們寫了傻傻的代碼導致運行時殺死了我們的程序并且拋出堆棧跟蹤信息。我將演示堆棧跟蹤信息能提供些什么信息,包括怎么找到我們傳遞給函數的參數的值。
函數
列表1
列表1
package main
func main() {
slice := make([]string, 2, 4)
Example(slice, “hello”, 10)
}
func Example(slice []string, str string, i int) {
panic(“Want stack trace”)
}
列表1是一個簡單的程序, main函數在第5行調用Example函數。Example函數在第8行聲明,它有三個參數,一個字符串slice,一個字符串和一個整數。它的方法體也很簡單,只有一行,拋出一個panic,這會立即產生一個堆棧跟蹤信息:
列表2
Panic: Want stack trace
goroutine 1 [running]:
main.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa)
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:9 +0x64
main.main()
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:5 +0x85
goroutine 2 [runnable]:
runtime.forcegchelper()
/Users/bill/go/src/runtime/proc.go:90
runtime.goexit()
/Users/bill/go/src/runtime/asm_amd64.s:2232 +0x1
goroutine 3 [runnable]:
runtime.bgsweep()
/Users/bill/go/src/runtime/mgc0.go:82
runtime.goexit()
/Users/bill/go/src/runtime/asm_amd64.s:2232 +0x1
列表2顯示了panic發生時的所有的goroutine,每一個goroutine的狀態,每一個goroutine的狀態,以及相應的調用堆棧。導致panic的gotoutine在最上面,我們只看這它的堆棧信息。
列表3
goroutine 1 [running]:
main.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa)
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:9 +0x64
main.main()
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:5 +0x85
我在Go 1.6版本下測試,堆棧跟蹤信息只顯示了當前panic的堆棧信息,沒有顯示其它的goroutine的信息。
列表3的第一行顯示panic發生前運行的goroutine是id為 1的goroutine。第二行是發生panic的代碼位置,位于main package下的Example函數。它也顯示了代碼所在的文件和路徑,以及panic發生的行數(第9行)。
Line 03也調用Example的函數的名字,它是main package的main函數。它也顯示了文件名和路徑,以及調用Example函數的行數。
堆棧跟蹤信息顯示了 panic發生時的這個goroutine的函數調用鏈。現在讓我們看看傳遞給Example的參數的值。
列表4
// Declaration
main.Example(slice []string, str string, i int)
// Call to Example by main.
slice := make([]string, 2, 4)
Example(slice, “hello”, 10)
// Stack trace
main.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa)
|
列表4列舉了Example函數的聲明,調用以及傳遞給它的值的信息。當你比較函數的聲明以及傳遞的值時,發現它們并不一致。函數聲明只接收三個參數,而堆棧中卻顯示6個16進制表示的值。理解這一點的關鍵是要知道每個參數類型的實現機制。
讓我們看第一個[]string類型的參數。slice是引用類型,這意味著那個值是一個指針的頭信息(header value),它指向一個字符串。對于slice,它的頭是三個word數,指向一個數組。因此前三個值代表這個slice。
列表5
// Slice parameter value
slice := make([]string, 2, 4)
// Slice header values
Pointer: 0x2080c3f50
Length: 0x2
Capacity: 0x4
// Declaration
main.Example(slice []string, str string, i int)
// Stack trace
main.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa)
列表5顯示了0x2080c3f50
代表第一個參數[]string的指針,0x2
代表slice長度,0x4
代表容量。這三個值代表第一個參數。
Figure 1
讓我們看看第二個參數,它是字符串類型。字符串也是引用類型,但是它的頭(header)是不可變的。這個頭包含兩個word類型,一個是指向底層字節數組的指針,一個是字符串的長度。
列表6
String parameter value
“hello”
// String header values
Pointer: 0x425c0
Length: 0x5
// Declaration
main.Example(slice []string, str string, i int)
// Stack trace
main.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa)
列表6顯示堆棧跟蹤信息中的第4個和第5個參數代表字符串的參數。0x425c0
是指向這個字符串底層數組的指針,0x5
是"hello"字符串的長度,他們倆作為第二個參數。
Figure 2
第三個參數是一個整數,它是一個簡單的word值。
列表7
// Integer parameter value
10
// Integer value
Base 16: 0xa
// Declaration
main.Example(slice []string, str string, i int)
// Stack trace
main.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa)
列表7顯示堆棧中的最后一個參數就是Example聲明中的第三個參數,它的值是0xa
,也就是整數10。
Figure 3
方法
讓我們稍微改動一下程序,讓Example變成方法。
列表8
package main
import "fmt"
type trace struct{}
func main() {
slice := make([]string, 2, 4)
var t trace
t.Example(slice, "hello", 10)
}
func (t *trace) Example(slice []string, str string, i int) {
fmt.Printf("Receiver Address: %p\n", t)
panic("Want stack trace")
}
列表8在第5行新增加了一個類型trace,在第14將example改變為trace的pointer receiver的一個方法。第10行聲明t的類型為trace,第11行調用它的方法。
因為這個方法聲明為pointer receiver的方法,Go使用t的指針來支持receiver type,即使代碼中使用值來調用這個方法。當程序運行時,堆棧跟蹤信息如下:
列表9
Receiver Address: 0x1553a8
panic: Want stack trace
goroutine 1 [running]:
main.(*trace).Example(0x1553a8, 0x2081b7f50, 0x2, 0x4, 0xdc1d0, 0x5, 0xa)
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:16 +0x116
main.main()
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:11 +0xae
列表9的第5行清晰的表明方法的receiver為pointer type。方法名和報包名中間有(*trace)。第二個值得注意的是堆棧信息中方法的第一個參數為receiver的值。方法調用總是轉換成函數調用,并將receiver的值作為函數的第一個參數。我們可以總堆棧信息中看到實現的細節。
因為Example其它地方沒有改變,其它的值保持一樣。行號顯示新的代碼中的行號。
Packing
當函數的參數可以填充到一個單一的word類型中時,參數的值會被打包在一起。
列表10
package main
func main() {
Example(true, false, true, 25)
}
func Example(b1, b2, b3 bool, i uint8) {
panic("Want stack trace")
}
列表10改變Example的方法,讓它接收4個參數。前三個參數是布爾類型的,第四個參數是8bit無符號整數。布爾類型也是8bit表示的,所以這四個參數可以被打包成一個word,包括32位架構和64位架構。當程序運行的時候,會產生有趣的堆棧:
列表11
goroutine 1 [running]:
main.Example(0x19010001)
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:8 +0x64
main.main()
/Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/
temp/main.go:4 +0x32
可以看到四個值被打包成一個單一的值了0x19010001
。
列表12
// Parameter values
true, false, true, 25
// Word value
Bits Binary Hex Value
00-07 0000 0001 01 true
08-15 0000 0000 00 false
16-23 0000 0001 01 true
24-31 0001 1001 19 25
// Declaration
main.Example(b1, b2, b3 bool, i uint8)
// Stack trace
main.Example(0x19010001)
列表12顯示了堆棧的值如何和參數進行匹配的。true用1表示,占8bit, false用0表示,占8bit,uint8值25的16進制為x19,用8bit表示。我們課喲看到它們是如何表示成一個word值的。
結論
Go運行時提供了詳細的信息來幫助我們調試陳旭。本文我們關注堆棧跟蹤信息stack trace。解碼傳遞個堆棧中的方法的參數幫助巨大。它不止一次幫助我快速地定位bug。 現在你也知道了如何讀取這些堆棧跟蹤信息,希望你能在下一次的調試中應用這個方法。
來源:http://colobu.com/2016/04/19/Stack-Traces-In-Go/