In an effort to capture stack traces directly, we can glean some helpful pieces of information from the built-in runtime package.
Specifically, Go provides a couple of tools to give us insight into the invocation and/or breakpoints of a goroutine. The following are the functions within the runtime package:
We can utilize all three preceding tools to better describe the inner workings of any given goroutine and related errors.
Using the following code, we'll spawn some random goroutines doing random things and log not only the goroutine's log message, but also the stack trace and the goroutine's caller:
package main import ( "os" "fmt" "runtime" "strconv" "code.google.com/p/log4go" ) type LogItem struct { Message string } var LogItems []LogItem func saveLogs() { logFile := log4go.NewFileLogWriter("stack.log", false) logFile.SetFormat("%d %t - %M (%S)") logFile.SetRotate(false) logFile.SetRotateSize(0) logFile.SetRotateLines(0) logFile.SetRotateDaily(true) logStack := make(log4go.Logger) logStack.AddFilter("file", log4go.DEBUG, logFile) for i := range LogItems { fmt.Println(LogItems[i].Message) logStack.Info(LogItems[i].Message) } }
The saveLogs()
function merely takes our map of LogItems
and applies them to file per log4go, as we did earlier in the chapter. Next, we'll look at the function that supplies details on our goroutines:
func goDetails(done chan bool) { i := 0 for { var message string stackBuf := make([]byte,1024) stack := runtime.Stack(stackBuf, false) stack++ _, callerFile, callerLine, ok := runtime.Caller(0) message = "Goroutine from " + string(callerLine) + "" + string(callerFile) + " stack:" + string(stackBuf) openGoroutines := runtime.NumGoroutine() if (ok == true) { message = message + callerFile } message = message + strconv.FormatInt(int64(openGoroutines),10) + " goroutines active" li := LogItem{ Message: message} LogItems = append(LogItems,li) if i == 20 { done <- true break } i++ } }
This is where we gather more details about a goroutine. The runtime.Caller()
function provides a few returned values: its pointer, the filename of the caller, the line of the caller. The last return value indicates whether the caller could be found.
As mentioned previously, runtime.NumGoroutine()
gives us the number of extant goroutines that have not yet been closed.
Then, in runtime.Stack(stackBuf, false)
, we fill our buffer with the stack trace. Note that we're not trimming this byte array to length.
All three are passed into LogItem.Message
for later use. Let's look at the setup in the main()
function:
func main() { done := make(chan bool) go goDetails(done) for i:= 0; i < 10; i++ { go goDetails(done) } for { select { case d := <-done: if d == true { saveLogs() os.Exit(1) } } } }
Finally, we loop through some goroutines that are doing loops themselves and exit upon completion.
When we examine our logfile, we're given far more verbose details on our goroutines than we have previously, as shown in the following code:
04/16/14 23:25 - Goroutine from + /var/log/go/ch9_11_stacktrace.goch9_11_stacktrace.go stack:goroutine 4 [running]: main.goDetails(0xc08400b300) /var/log/go/ch9_11_stacktrace.goch9_11_stacktrace.go:41 +0x8e created by main.main /var/log/go/ch9_11_stacktrace.goch9_11_stacktrace.go:69 +0x4c /var/log/go/ch9_11_stacktrace.goch9_11_stacktrace.go14 goroutines active (main.saveLogs:31)
For more information on the runtime package, go to http://golang.org/pkg/runtime/.