print funcgraph in stream

elf.go

@@ -26,6 +26,10 @@ func ParseOffsets(binPath string, wildcards []string) (entryOffsets, exitOffsets
 			matched := false
 			for _, wildcard := range wildcards {
 				if utils.MatchWildcard(wildcard, name) {
+					if _, ok := pcs[name]; ok {
+						// golang's dwarf bug: duplicate function entries
+						continue
+					}
 					matched = true
 					break
 				}

functracer.go

@@ -37,6 +37,6 @@ func (t *Functracer) DetachUprobes() {
 
 func (t *Functracer) CollectEvents(ctx context.Context) (err error) {
 	ch := t.bpf.PollEvents(ctx)
-	PrintFuncgraph(ch, t.binPath)
+	FuncgraphStream(ch, t.binPath)
 	return
 }

main.go

@@ -24,7 +24,7 @@ func main() {
 	help := flag.BoolP("help", "h", false, "print help")
 	flag.Parse()
 	if *help || len(flag.Args()) < 2 {
-		fmt.Println("Usage: ufuncgraph <executable> <wildcard> [<wildcard>...]\n")
+		fmt.Println("Usage: ufuncgraph <executable> <wildcard> [<wildcard>...]")
 		return
 	}
 	binPath := flag.Arg(0)

postprocess.go

@@ -1,6 +1,7 @@
 package main
 
 import (
+	"debug/elf"
 	"fmt"
 	"time"
 
@@ -13,65 +14,122 @@ type Symbol struct {
 	Offset uint64
 }
 
-func PrintFuncgraph(ch <-chan bpf.UfuncgraphEvent, binPath string) (err error) {
-	goroutine2events := map[uint64][]bpf.UfuncgraphEvent{}
-	ip2sym := map[uint64]*Symbol{}
-	for event := range ch {
-		fmt.Printf("%+v\n", event)
-		if event.Errno != 0 {
-			return fmt.Errorf("event error: %d", event.Errno)
-		}
+type Eventpool struct {
+	goroutine2events map[uint64][]bpf.UfuncgraphEvent
+	goroutine2stack  map[uint64]uint64
+	bootTime         time.Time
+}
 
-		if _, ok := goroutine2events[event.Goid]; !ok {
-			goroutine2events[event.Goid] = []bpf.UfuncgraphEvent{}
-		}
-		length := len(goroutine2events[event.Goid])
-		if length == 0 && event.HookPoint == 1 {
-			continue
-		}
-		if length > 0 && event.HookPoint == 0 && goroutine2events[event.Goid][length-1].HookPoint == 0 && goroutine2events[event.Goid][length-1].StackDepth == event.StackDepth {
-			continue
+func NewGevent() (_ *Eventpool, err error) {
+	host, err := sysinfo.Host()
+	if err != nil {
+		return
+	}
+	bootTime := host.Info().BootTime
+	return &Eventpool{
+		goroutine2events: map[uint64][]bpf.UfuncgraphEvent{},
+		goroutine2stack:  map[uint64]uint64{},
+		bootTime:         bootTime,
+	}, nil
+}
+
+func (p *Eventpool) Add(event bpf.UfuncgraphEvent) {
+	length := len(p.goroutine2events[event.Goid])
+	if length == 0 && event.HookPoint == 1 {
+		return
+	}
+	if length > 0 && event.HookPoint == 0 && p.goroutine2events[event.Goid][length-1].HookPoint == 0 && p.goroutine2events[event.Goid][length-1].StackDepth == event.StackDepth {
+		return
+	}
+	p.goroutine2events[event.Goid] = append(p.goroutine2events[event.Goid], event)
+	p.goroutine2stack[event.Goid] = p.goroutine2stack[event.Goid] - 2*uint64(event.HookPoint) + 1
+}
+
+func (p *Eventpool) StackCompleted(goid uint64) bool {
+	return p.goroutine2stack[goid] == 0
+}
+
+func (p *Eventpool) PrintStack(goid uint64, symInterp *SymInterp) {
+	ident := ""
+	println()
+	for _, event := range p.goroutine2events[goid] {
+		t := p.bootTime.Add(time.Duration(event.TimeNs)).Format("2006-01-02 15:04:05.0000")
+		if event.HookPoint == 0 {
+			fmt.Printf("%s %s %s { %s\n", t, ident, symInterp.Interp(event.Ip, withOffset(false)), symInterp.Interp(event.CallerIp, withOffset(true)))
+			ident += "  "
+		} else {
+			if len(ident) == 0 {
+				continue
+			}
+			ident = ident[:len(ident)-2]
+			fmt.Printf("%s %s } %s\n", t, ident, symInterp.Interp(event.Ip, withOffset(true)))
 		}
-		goroutine2events[event.Goid] = append(goroutine2events[event.Goid], event)
-		ip2sym[event.Ip] = &Symbol{Offset: 0xffffffffffffffff}
-		ip2sym[event.CallerIp] = &Symbol{Offset: 0xffffffffffffffff}
 	}
+	delete(p.goroutine2events, goid)
+	return
+}
+
+type SymInterp struct {
+	binPath string
+	syms    []elf.Symbol
+	cache   map[uint64]Symbol
+}
 
+type withOffset bool
+
+func NewSymInterp(binPath string) (_ *SymInterp, err error) {
 	syms, err := ParseSymtab(binPath)
 	if err != nil {
 		return
 	}
-	for _, sym := range syms {
-		for ip, symbol := range ip2sym {
+	return &SymInterp{
+		binPath: binPath,
+		syms:    syms,
+		cache:   map[uint64]Symbol{},
+	}, nil
+}
+
+func (i *SymInterp) Interp(ip uint64, withOffset withOffset) string {
+	if _, ok := i.cache[ip]; !ok {
+		symbol := Symbol{Offset: 0xffffffffffffffff}
+		for _, sym := range i.syms {
 			if ip-sym.Value < symbol.Offset {
 				symbol.Name = sym.Name
 				symbol.Offset = ip - sym.Value
 			}
 		}
+		i.cache[ip] = symbol
 	}
 
-	host, err := sysinfo.Host()
+	sym := i.cache[ip]
+	if withOffset {
+		return fmt.Sprintf("%s+%d", sym.Name, sym.Offset)
+	}
+	return sym.Name
+}
+
+func FuncgraphStream(ch <-chan bpf.UfuncgraphEvent, binPath string) (err error) {
+	symInterp, err := NewSymInterp(binPath)
 	if err != nil {
 		return
 	}
-	bootTime := host.Info().BootTime
-	fmt.Printf("%s\n", bootTime)
-	for _, events := range goroutine2events {
-		println("-----------------")
-		ident := ""
-		for _, event := range events {
-			t := bootTime.Add(time.Duration(event.TimeNs)).Format("2006-01-02 15:04:05.0000")
-			if event.HookPoint == 0 {
-				fmt.Printf("%s %s %s { %s+%d\n", t, ident, ip2sym[event.Ip].Name, ip2sym[event.CallerIp].Name, ip2sym[event.CallerIp].Offset)
-				ident += "  "
-			} else {
-				if len(ident) == 0 {
-					continue
-				}
-				ident = ident[:len(ident)-2]
-				fmt.Printf("%s %s } %s+%d\n", t, ident, ip2sym[event.Ip].Name, ip2sym[event.Ip].Offset)
-			}
+
+	pool, err := NewGevent()
+	if err != nil {
+		return
+	}
+
+	for event := range ch {
+		if event.Errno != 0 {
+			return fmt.Errorf("event error: %d", event.Errno)
+		}
+
+		pool.Add(event)
+		if pool.StackCompleted(event.Goid) {
+			pool.PrintStack(event.Goid, symInterp)
 		}
 	}
+
+	fmt.Printf("completed, detaching uprobes\n")
 	return
 }