這是一個建立於 的文章,其中的資訊可能已經有所發展或是發生改變。
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
12345678910 |
package mainfunc 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
123456789101112131415161718192021 |
Panic: Want stack tracegoroutine 1 [running]:main.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa) /Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/ temp/main.go:9 +0x64main.main() /Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/ temp/main.go:5 +0x85goroutine 2 [runnable]:runtime.forcegchelper() /Users/bill/go/src/runtime/proc.go:90runtime.goexit() /Users/bill/go/src/runtime/asm_amd64.s:2232 +0x1goroutine 3 [runnable]:runtime.bgsweep() /Users/bill/go/src/runtime/mgc0.go:82runtime.goexit() /Users/bill/go/src/runtime/asm_amd64.s:2232 +0x1 |
列表2顯示了panic發生時的所有的goroutine,每一個goroutine的狀態,每一個goroutine的狀態,以及相應的呼叫堆疊。導致panic的gotoutine在最上面,我們只看這它的堆棧資訊。
列表3
1234567 |
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 +0x64main.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
123456789 |
// Declarationmain.Example(slice []string, str string, i int)// Call to Example by main.slice := make([]string, 2, 4)Example(slice, “hello”, 10)// Stack tracemain.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa) |
列表4列舉了Example函數的聲明,調用以及傳遞給它的值的資訊。當你比較函數的聲明以及傳遞的值時,發現它們並不一致。函式宣告只接收三個參數,而堆棧中卻顯示6個16進位表示的值。理解這一點的關鍵是要知道每個參數類型的實現機制。
讓我們看第一個[]string類型的參數。slice是參考型別,這意味著那個值是一個指標的頭資訊(header value),它指向一個字串。對於slice,它的頭是三個word數,指向一個數組。因此前三個值代表這個slice。
列表5
12345678910111213 |
// Slice parameter valueslice := make([]string, 2, 4)// Slice header valuesPointer: 0x2080c3f50Length: 0x2Capacity: 0x4// Declarationmain.Example(slice []string, str string, i int)// Stack tracemain.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa) |
列表5顯示了0x2080c3f50代表第一個參數[]string的指標,0x2代表slice長度,0x4代表容量。這三個值代表第一個參數。
讓我們看看第二個參數,它是字串類型。字串也是參考型別,但是它的頭(header)是不可變的。這個頭包含兩個word類型,一個是指向底層位元組數組的指標,一個是字串的長度。
列表6
123456789101112 |
// String parameter value“hello”// String header valuesPointer: 0x425c0Length: 0x5// Declarationmain.Example(slice []string, str string, i int)// Stack tracemain.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa) |
列表6顯示堆疊追蹤資訊中的第4個和第5個參數代表字串的參數。0x425c0是指向這個字串底層數組的指標,0x5是"hello"字串的長度,他們倆作為第二個參數。
第三個參數是一個整數,它是一個簡單的word值。
列表7
1234567891011 |
// Integer parameter value10// Integer valueBase 16: 0xa// Declarationmain.Example(slice []string, str string, i int)// Stack tracemain.Example(0x2080c3f50, 0x2, 0x4, 0x425c0, 0x5, 0xa) |
列表7顯示堆棧中的最後一個參數就是Example聲明中的第三個參數,它的值是0xa,也就是整數10。
方法
讓我們稍微改動一下程式,讓Example變成方法。
列表8
1234567891011121314151617 |
package mainimport "fmt"type trace struct{}func main() {slice := make([]string, 2, 4)var t tracet.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
1234567891011 |
Receiver Address: 0x1553a8panic: Want stack tracegoroutine 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 +0x116main.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
123456789 |
package mainfunc 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
1234567 |
goroutine 1 [running]:main.Example(0x19010001) /Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/ temp/main.go:8 +0x64main.main() /Users/bill/Spaces/Go/Projects/src/github.com/goinaction/code/ temp/main.go:4 +0x32 |
可以看到四個值被打包成一個單一的值了0x19010001。
列表12
123456789101112131415 |
// Parameter valuestrue, false, true, 25// Word valueBits Binary Hex Value00-07 0000 0001 01 true08-15 0000 0000 00 false16-23 0000 0001 01 true24-31 0001 1001 19 25// Declarationmain.Example(b1, b2, b3 bool, i uint8)// Stack tracemain.Example(0x19010001) |
列表12顯示了堆棧的值如何和參數進行匹配的。true用1表示,佔8bit, false用0表示,佔8bit,uint8值25的16進位為x19,用8bit表示。我們課喲看到它們是如何表示成一個word值的。
結論
Go運行時提供了詳細的資訊來協助我們偵錯工具。本文我們關注堆疊追蹤資訊stack trace。解碼傳遞個堆棧中的方法的參數協助巨大。它不止一次協助我快速地定位bug。 現在你也知道了如何讀取這些堆疊追蹤資訊,希望你能在下一次的調試中應用這個方法。