1、首先通过defer机制实现函数调用栈的跟踪,Trace()调用后,首先显示"enter: #fucname#",然后将返回的闭包函数推后执行(注册到defer的函数栈中),exit时则会以LIFO的方式显示"exit : #fucname#"
// trace.go
package main
func Trace(name string) func() {
println("enter:", name)
return func() {
println("exit:", name)
}
}
func foo() {
defer Trace("foo")()
bar()
}
func bar() {
defer Trace("bar")()
}
func main() {
defer Trace("main")()
foo()
}
//输出结果如下:
enter: main
enter: foo
enter: bar
exit: bar
exit: foo
exit: main
2、优化
(1)、减少参数传入
在刚才的调用过程中,Trace()的参数都需要输入函数的名称,如果函数调用较多,那么会非常麻烦,因此,可以通过Go中的runtime.Caller获取到函数调用栈上的函数调用者信息(Caller(0)获取函数信息,Caller(1)获取函数调用者信息):
// trace1/trace.go
func Trace() func() {
pc, _, _, ok := runtime.Caller(1)
if !ok {
panic("not found caller")
}
fn := runtime.FuncForPC(pc)
name := fn.Name()
println("enter:", name)
return func() { println("exit:", name) }
}
func foo() {
defer Trace()()
bar()
}
func bar() {
defer Trace()()
}
func main() {
defer Trace()()
foo()
}
//结果输出如下:
enter: main.main
enter: main.foo
enter: main.bar
exit: main.bar
exit: main.foo
exit: main.main
这样,就能够无需向Trace中传入函数名称,而是被动态获取,之后的运行过程与1中相同。但是输出结果有所不同,输出还包含了跟踪函数所在的包名。
(2)、如何在Goroutine中同样适用?
在并发场景中,这种函数调用链的显示就显得非常复杂,很容易出现错乱。所以,为了考虑不同协程,应该要获取协程的ID。
// trace_v1.go
package main
import (
"bytes"
"fmt"
"runtime"
"strconv"
"sync"
)
var goroutineSpace = []byte("goroutine ")
func curGoroutineID() uint64 {
b := make([]byte, 64)
b = b[:runtime.Stack(b, false)]
// Parse the 4707 out of "goroutine 4707 ["
b = bytes.TrimPrefix(b, goroutineSpace)
i := bytes.IndexByte(b, ' ')
if i < 0 {
panic(fmt.Sprintf("No space found in %q", b))
}
b = b[:i]
n, err := strconv.ParseUint(string(b), 10, 64)
if err != nil {
panic(fmt.Sprintf("Failed to parse goroutine ID out of %q: %v", b, err))
}
return n
}
// trace2/trace.go
func Trace() func() {
pc, _, _, ok := runtime.Caller(1)
if !ok {
panic("not found caller")
}
fn := runtime.FuncForPC(pc)
name := fn.Name()
gid := curGoroutineID()
fmt.Printf("g[%05d]: enter: [%s]\n", gid, name)
return func() { fmt.Printf("g[%05d]: exit: [%s]\n", gid, name) }
}
func A1() {
defer Trace()()
B1()
}
func B1() {
defer Trace()()
C1()
}
func C1() {
defer Trace()()
D()
}
func D() {
defer Trace()()
}
func A2() {
defer Trace()()
B2()
}
func B2() {
defer Trace()()
C2()
}
func C2() {
defer Trace()()
D()
}
func main() {
var wg sync.WaitGroup
wg.Add(1)
go func() {
A2()
wg.Done()
}()
A1()
wg.Wait()
}
输出如下:
通过curGoroutineID()函数可以获取gid,从而开启多个协程时,能够将不同的调用链进行标识。可以看到主协程的调用链为A1 -> B1 -> C1 -> D,子协程的调用链为A2 -> B2 -> C2 -> D。但是有时会因为goroutine调度器的调度,多个协程交织在一起,所以可以将程序的输出重定向到一个本地文件中,然后通过 Goroutine ID 过滤出(可使用 grep 工具)你想查看的 groutine 的全部函数跟踪信息。
(3)让输出更有层次
//加入printTrace做到格式化输出
func printTrace(id uint64, name, arrow string, indent int) {
indents := ""
for i := 0; i < indent; i++ {
indents += " "
}
fmt.Printf("g[%05d]:%s%s%s\n", id, indents, arrow, name)
}
var mu sync.Mutex
var m = make(map[uint64]int)
func Trace() func() {
pc, _, _, ok := runtime.Caller(1)
if !ok {
panic("not found caller")
}
fn := runtime.FuncForPC(pc)
name := fn.Name()
gid := curGoroutineID()
mu.Lock()
indents := m[gid] // 获取当前gid对应的缩进层次
m[gid] = indents + 1 // 缩进层次+1后存入map
mu.Unlock()
printTrace(gid, name, "->", indents+1)
return func() {
mu.Lock()
indents := m[gid] // 获取当前gid对应的缩进层次
m[gid] = indents - 1 // 缩进层次-1后存入map
mu.Unlock()
printTrace(gid, name, "<-", indents)
}
}
g[00001]: ->main.A1
g[00001]: ->main.B1
g[00001]: ->main.C1
g[00001]: ->main.D
g[00001]: <-main.D
g[00001]: <-main.C1
g[00001]: <-main.B1
g[00001]: <-main.A1
g[00018]: ->main.A2
g[00018]: ->main.B2
g[00018]: ->main.C2
g[00018]: ->main.D
g[00018]: <-main.D
g[00018]: <-main.C2
g[00018]: <-main.B2
g[00018]: <-main.A2