From ea1f4832401afb6bd89bf145db3791e7de6cadc4 Mon Sep 17 00:00:00 2001 From: "Hana (Hyang-Ah) Kim" Date: Thu, 22 Mar 2018 12:51:13 -0400 Subject: [PATCH] cmd/trace: beautify goroutine page - Summary: also includes links to pprof data. - Sortable table: sorting is done on server-side. The intention is that later, I want to add pagination feature and limit the page size the browser has to handle. - Stacked horizontal bar graph to present total time breakdown. - Human-friendly time representation. - No dependency on external fancy javascript libraries to allow it to function without an internet connection. Change-Id: I91e5c26746e59ad0329dfb61e096e11f768c7b73 Reviewed-on: https://go-review.googlesource.com/102156 Run-TryBot: Hyang-Ah Hana Kim TryBot-Result: Gobot Gobot Reviewed-by: Andrew Bonventre Reviewed-by: Heschi Kreinick --- src/cmd/trace/goroutines.go | 234 +++++++++++++++++++++++++++--------- 1 file changed, 175 insertions(+), 59 deletions(-) diff --git a/src/cmd/trace/goroutines.go b/src/cmd/trace/goroutines.go index d0d428cbe2..548871a82c 100644 --- a/src/cmd/trace/goroutines.go +++ b/src/cmd/trace/goroutines.go @@ -10,10 +10,13 @@ import ( "fmt" "html/template" "internal/trace" + "log" "net/http" + "reflect" "sort" "strconv" "sync" + "time" ) func init() { @@ -29,34 +32,6 @@ type gtype struct { ExecTime int64 // Total execution time of all goroutines in this group. } -type gtypeList []gtype - -func (l gtypeList) Len() int { - return len(l) -} - -func (l gtypeList) Less(i, j int) bool { - return l[i].ExecTime > l[j].ExecTime -} - -func (l gtypeList) Swap(i, j int) { - l[i], l[j] = l[j], l[i] -} - -type gdescList []*trace.GDesc - -func (l gdescList) Len() int { - return len(l) -} - -func (l gdescList) Less(i, j int) bool { - return l[i].TotalTime > l[j].TotalTime -} - -func (l gdescList) Swap(i, j int) { - l[i], l[j] = l[j], l[i] -} - var ( gsInit sync.Once gs map[uint64]*trace.GDesc @@ -86,13 +61,17 @@ func httpGoroutines(w http.ResponseWriter, r *http.Request) { gs1.ExecTime += g.ExecTime gss[g.PC] = gs1 } - var glist gtypeList + var glist []gtype for k, v := range gss { v.ID = k glist = append(glist, v) } - sort.Sort(glist) - templGoroutines.Execute(w, glist) + sort.Slice(glist, func(i, j int) bool { return glist[i].ExecTime > glist[j].ExecTime }) + w.Header().Set("Content-Type", "text/html;charset=utf-8") + if err := templGoroutines.Execute(w, glist); err != nil { + log.Printf("failed to execute template: %v", err) + return + } } var templGoroutines = template.Must(template.New("").Parse(` @@ -108,64 +87,201 @@ Goroutines:
// httpGoroutine serves list of goroutines in a particular group. func httpGoroutine(w http.ResponseWriter, r *http.Request) { + // TODO(hyangah): support format=csv (raw data) + events, err := parseEvents() if err != nil { http.Error(w, err.Error(), http.StatusInternalServerError) return } + pc, err := strconv.ParseUint(r.FormValue("id"), 10, 64) if err != nil { http.Error(w, fmt.Sprintf("failed to parse id parameter '%v': %v", r.FormValue("id"), err), http.StatusInternalServerError) return } analyzeGoroutines(events) - var glist gdescList + var ( + glist []*trace.GDesc + name string + totalExecTime, execTime int64 + maxTotalTime int64 + ) + for _, g := range gs { + totalExecTime += g.ExecTime + if g.PC != pc { continue } glist = append(glist, g) + name = g.Name + execTime += g.ExecTime + if maxTotalTime < g.TotalTime { + maxTotalTime = g.TotalTime + } } - sort.Sort(glist) + + execTimePercent := "" + if totalExecTime > 0 { + execTimePercent = fmt.Sprintf("%.2f%%", float64(execTime)/float64(totalExecTime)*100) + } + + sortby := r.FormValue("sortby") + _, ok := reflect.TypeOf(trace.GDesc{}).FieldByNameFunc(func(s string) bool { + return s == sortby + }) + if !ok { + sortby = "TotalTime" + } + + sort.Slice(glist, func(i, j int) bool { + ival := reflect.ValueOf(glist[i]).Elem().FieldByName(sortby).Int() + jval := reflect.ValueOf(glist[j]).Elem().FieldByName(sortby).Int() + return ival > jval + }) + err = templGoroutine.Execute(w, struct { - PC uint64 - GList gdescList - }{pc, glist}) + Name string + PC uint64 + N int + ExecTimePercent string + MaxTotal int64 + GList []*trace.GDesc + }{ + Name: name, + PC: pc, + N: len(glist), + ExecTimePercent: execTimePercent, + MaxTotal: maxTotalTime, + GList: glist}) if err != nil { http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError) return } } -var templGoroutine = template.Must(template.New("").Parse(` - - - +var templGoroutine = template.Must(template.New("").Funcs(template.FuncMap{ + "prettyDuration": func(nsec int64) template.HTML { + d := time.Duration(nsec) * time.Nanosecond + return template.HTML(niceDuration(d)) + }, + "percent": func(dividened, divisor int64) template.HTML { + if divisor == 0 { + return "" + } + return template.HTML(fmt.Sprintf("(%.1f%%)", float64(dividened)/float64(divisor)*100)) + }, + "barLen": func(dividened, divisor int64) template.HTML { + if divisor == 0 { + return "0" + } + return template.HTML(fmt.Sprintf("%.2f%%", float64(dividened)/float64(divisor)*100)) + }, + "unknownTime": func(desc *trace.GDesc) int64 { + sum := desc.ExecTime + desc.IOTime + desc.BlockTime + desc.SyscallTime + desc.SchedWaitTime + if sum < desc.TotalTime { + return desc.TotalTime - sum + } + return 0 + }, +}).Parse(` + +Goroutine {{.Name}} + + + + +
+ + + + + + + +
Goroutine Name:{{.Name}}
Number of Goroutines:{{.N}}
Execution Time:{{.ExecTimePercent}} of total program execution time
Network Wait Time: graph(download)
Sync Block Time: graph(download)
Blocking Syscall Time: graph(download)
Scheduler Wait Time: graph(download)
+

+ - - - - - - - - - + + + + + + + + + + {{range .GList}} - - - - - - - - + + + + + + + + + {{end}}
Goroutine Total time, ns Execution time, ns Network wait time, ns⬇ Sync block time, ns⬇ Blocking syscall time, ns⬇ Scheduler wait time, ns⬇ GC sweeping time, ns GC pause time, ns Goroutine Total Execution Network wait Sync block Blocking syscall Scheduler wait GC sweeping GC pause
{{.ID}} {{.TotalTime}} {{.ExecTime}} {{.IOTime}} {{.BlockTime}} {{.SyscallTime}} {{.SchedWaitTime}} {{.SweepTime}} {{.GCTime}} {{prettyDuration .TotalTime}} +
+ {{if unknownTime .}} {{end}} + {{if .ExecTime}} {{end}} + {{if .IOTime}} {{end}} + {{if .BlockTime}} {{end}} + {{if .SyscallTime}} {{end}} + {{if .SchedWaitTime}} {{end}} +
+
{{prettyDuration .ExecTime}} {{prettyDuration .IOTime}} {{prettyDuration .BlockTime}} {{prettyDuration .SyscallTime}} {{prettyDuration .SchedWaitTime}} {{prettyDuration .SweepTime}} {{percent .SweepTime .TotalTime}} {{prettyDuration .GCTime}} {{percent .GCTime .TotalTime}}
- - `)) -- 2.48.1