Skip to content

Commit ea1f483

Browse files
hyangahhyangah
committed
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 <hyangah@gmail.com> TryBot-Result: Gobot Gobot <gobot@golang.org> Reviewed-by: Andrew Bonventre <andybons@golang.org> Reviewed-by: Heschi Kreinick <heschi@google.com>
1 parent d2dd2e1 commit ea1f483

File tree

1 file changed

+175
-59
lines changed

1 file changed

+175
-59
lines changed

‎src/cmd/trace/goroutines.go‎

Lines changed: 175 additions & 59 deletions
Original file line numberDiff line numberDiff line change
@@ -10,10 +10,13 @@ import (
1010
"fmt"
1111
"html/template"
1212
"internal/trace"
13+
"log"
1314
"net/http"
15+
"reflect"
1416
"sort"
1517
"strconv"
1618
"sync"
19+
"time"
1720
)
1821

1922
func init() {
@@ -29,34 +32,6 @@ type gtype struct {
2932
ExecTime int64 // Total execution time of all goroutines in this group.
3033
}
3134

32-
type gtypeList []gtype
33-
34-
func (l gtypeList) Len() int {
35-
return len(l)
36-
}
37-
38-
func (l gtypeList) Less(i, j int) bool {
39-
return l[i].ExecTime > l[j].ExecTime
40-
}
41-
42-
func (l gtypeList) Swap(i, j int) {
43-
l[i], l[j] = l[j], l[i]
44-
}
45-
46-
type gdescList []*trace.GDesc
47-
48-
func (l gdescList) Len() int {
49-
return len(l)
50-
}
51-
52-
func (l gdescList) Less(i, j int) bool {
53-
return l[i].TotalTime > l[j].TotalTime
54-
}
55-
56-
func (l gdescList) Swap(i, j int) {
57-
l[i], l[j] = l[j], l[i]
58-
}
59-
6035
var (
6136
gsInit sync.Once
6237
gs map[uint64]*trace.GDesc
@@ -86,13 +61,17 @@ func httpGoroutines(w http.ResponseWriter, r *http.Request) {
8661
gs1.ExecTime += g.ExecTime
8762
gss[g.PC] = gs1
8863
}
89-
var glist gtypeList
64+
var glist []gtype
9065
for k, v := range gss {
9166
v.ID = k
9267
glist = append(glist, v)
9368
}
94-
sort.Sort(glist)
95-
templGoroutines.Execute(w, glist)
69+
sort.Slice(glist, func(i, j int) bool { return glist[i].ExecTime > glist[j].ExecTime })
70+
w.Header().Set("Content-Type", "text/html;charset=utf-8")
71+
if err := templGoroutines.Execute(w, glist); err != nil {
72+
log.Printf("failed to execute template: %v", err)
73+
return
74+
}
9675
}
9776

9877
var templGoroutines = template.Must(template.New("").Parse(`
@@ -108,64 +87,201 @@ Goroutines: <br>
10887

10988
// httpGoroutine serves list of goroutines in a particular group.
11089
func httpGoroutine(w http.ResponseWriter, r *http.Request) {
90+
// TODO(hyangah): support format=csv (raw data)
91+
11192
events, err := parseEvents()
11293
if err != nil {
11394
http.Error(w, err.Error(), http.StatusInternalServerError)
11495
return
11596
}
97+
11698
pc, err := strconv.ParseUint(r.FormValue("id"), 10, 64)
11799
if err != nil {
118100
http.Error(w, fmt.Sprintf("failed to parse id parameter '%v': %v", r.FormValue("id"), err), http.StatusInternalServerError)
119101
return
120102
}
121103
analyzeGoroutines(events)
122-
var glist gdescList
104+
var (
105+
glist []*trace.GDesc
106+
name string
107+
totalExecTime, execTime int64
108+
maxTotalTime int64
109+
)
110+
123111
for _, g := range gs {
112+
totalExecTime += g.ExecTime
113+
124114
if g.PC != pc {
125115
continue
126116
}
127117
glist = append(glist, g)
118+
name = g.Name
119+
execTime += g.ExecTime
120+
if maxTotalTime < g.TotalTime {
121+
maxTotalTime = g.TotalTime
122+
}
128123
}
129-
sort.Sort(glist)
124+
125+
execTimePercent := ""
126+
if totalExecTime > 0 {
127+
execTimePercent = fmt.Sprintf("%.2f%%", float64(execTime)/float64(totalExecTime)*100)
128+
}
129+
130+
sortby := r.FormValue("sortby")
131+
_, ok := reflect.TypeOf(trace.GDesc{}).FieldByNameFunc(func(s string) bool {
132+
return s == sortby
133+
})
134+
if !ok {
135+
sortby = "TotalTime"
136+
}
137+
138+
sort.Slice(glist, func(i, j int) bool {
139+
ival := reflect.ValueOf(glist[i]).Elem().FieldByName(sortby).Int()
140+
jval := reflect.ValueOf(glist[j]).Elem().FieldByName(sortby).Int()
141+
return ival > jval
142+
})
143+
130144
err = templGoroutine.Execute(w, struct {
131-
PC uint64
132-
GList gdescList
133-
}{pc, glist})
145+
Name string
146+
PC uint64
147+
N int
148+
ExecTimePercent string
149+
MaxTotal int64
150+
GList []*trace.GDesc
151+
}{
152+
Name: name,
153+
PC: pc,
154+
N: len(glist),
155+
ExecTimePercent: execTimePercent,
156+
MaxTotal: maxTotalTime,
157+
GList: glist})
134158
if err != nil {
135159
http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError)
136160
return
137161
}
138162
}
139163

140-
var templGoroutine = template.Must(template.New("").Parse(`
141-
<html>
142-
<body>
143-
<table border="1" sortable="1">
164+
var templGoroutine = template.Must(template.New("").Funcs(template.FuncMap{
165+
"prettyDuration": func(nsec int64) template.HTML {
166+
d := time.Duration(nsec) * time.Nanosecond
167+
return template.HTML(niceDuration(d))
168+
},
169+
"percent": func(dividened, divisor int64) template.HTML {
170+
if divisor == 0 {
171+
return ""
172+
}
173+
return template.HTML(fmt.Sprintf("(%.1f%%)", float64(dividened)/float64(divisor)*100))
174+
},
175+
"barLen": func(dividened, divisor int64) template.HTML {
176+
if divisor == 0 {
177+
return "0"
178+
}
179+
return template.HTML(fmt.Sprintf("%.2f%%", float64(dividened)/float64(divisor)*100))
180+
},
181+
"unknownTime": func(desc *trace.GDesc) int64 {
182+
sum := desc.ExecTime + desc.IOTime + desc.BlockTime + desc.SyscallTime + desc.SchedWaitTime
183+
if sum < desc.TotalTime {
184+
return desc.TotalTime - sum
185+
}
186+
return 0
187+
},
188+
}).Parse(`
189+
<!DOCTYPE html>
190+
<title>Goroutine {{.Name}}</title>
191+
<style>
192+
th {
193+
background-color: #050505;
194+
color: #fff;
195+
}
196+
table {
197+
border-collapse: collapse;
198+
}
199+
.details tr:hover {
200+
background-color: #f2f2f2;
201+
}
202+
.details td {
203+
text-align: right;
204+
border: 1px solid black;
205+
}
206+
.details td.id {
207+
text-align: left;
208+
}
209+
.stacked-bar-graph {
210+
width: 300px;
211+
height: 10px;
212+
color: #414042;
213+
white-space: nowrap;
214+
font-size: 5px;
215+
}
216+
.stacked-bar-graph span {
217+
display: inline-block;
218+
width: 100%;
219+
height: 100%;
220+
box-sizing: border-box;
221+
float: left;
222+
padding: 0;
223+
}
224+
.unknown-time { background-color: #636363; }
225+
.exec-time { background-color: #d7191c; }
226+
.io-time { background-color: #fdae61; }
227+
.block-time { background-color: #d01c8b; }
228+
.syscall-time { background-color: #7b3294; }
229+
.sched-time { background-color: #2c7bb6; }
230+
</style>
231+
232+
<script>
233+
function reloadTable(key, value) {
234+
let params = new URLSearchParams(window.location.search);
235+
params.set(key, value);
236+
window.location.search = params.toString();
237+
}
238+
</script>
239+
240+
<table class="summary">
241+
<tr><td>Goroutine Name:</td><td>{{.Name}}</td></tr>
242+
<tr><td>Number of Goroutines:</td><td>{{.N}}</td></tr>
243+
<tr><td>Execution Time:</td><td>{{.ExecTimePercent}} of total program execution time </td> </tr>
244+
<tr><td>Network Wait Time:</td><td> <a href="/io?id={{.PC}}">graph</a><a href="/io?id={{.PC}}&raw=1" download="io.profile">(download)</a></td></tr>
245+
<tr><td>Sync Block Time:</td><td> <a href="/block?id={{.PC}}">graph</a><a href="/block?id={{.PC}}&raw=1" download="block.profile">(download)</a></td></tr>
246+
<tr><td>Blocking Syscall Time:</td><td> <a href="/syscall?id={{.PC}}">graph</a><a href="/syscall?id={{.PC}}&raw=1" download="syscall.profile">(download)</a></td></tr>
247+
<tr><td>Scheduler Wait Time:</td><td> <a href="/sched?id={{.PC}}">graph</a><a href="/sched?id={{.PC}}&raw=1" download="sched.profile">(download)</a></td></tr>
248+
</table>
249+
<p>
250+
<table class="details">
144251
<tr>
145-
<th> Goroutine </th>
146-
<th> Total time, ns </th>
147-
<th> Execution time, ns </th>
148-
<th> <a href="/io?id={{.PC}}">Network wait time, ns</a><a href="/io?id={{.PC}}&raw=1" download="io.profile">⬇</a> </th>
149-
<th> <a href="/block?id={{.PC}}">Sync block time, ns</a><a href="/block?id={{.PC}}&raw=1" download="block.profile">⬇</a> </th>
150-
<th> <a href="/syscall?id={{.PC}}">Blocking syscall time, ns</a><a href="/syscall?id={{.PC}}&raw=1" download="syscall.profile">⬇</a> </th>
151-
<th> <a href="/sched?id={{.PC}}">Scheduler wait time, ns</a><a href="/sched?id={{.PC}}&raw=1" download="sched.profile">⬇</a> </th>
152-
<th> GC sweeping time, ns </th>
153-
<th> GC pause time, ns </th>
252+
<th> Goroutine</th>
253+
<th onclick="reloadTable('sortby', 'TotalTime')"> Total</th>
254+
<th></th>
255+
<th onclick="reloadTable('sortby', 'ExecTime')" class="exec-time"> Execution</th>
256+
<th onclick="reloadTable('sortby', 'IOTime')" class="io-time"> Network wait</th>
257+
<th onclick="reloadTable('sortby', 'BlockTime')" class="block-time"> Sync block </th>
258+
<th onclick="reloadTable('sortby', 'SyscallTime')" class="syscall-time"> Blocking syscall</th>
259+
<th onclick="reloadTable('sortby', 'SchedWaitTime')" class="sched-time"> Scheduler wait</th>
260+
<th onclick="reloadTable('sortby', 'SweepTime')"> GC sweeping</th>
261+
<th onclick="reloadTable('sortby', 'GCTime')"> GC pause</th>
154262
</tr>
155263
{{range .GList}}
156264
<tr>
157265
<td> <a href="/trace?goid={{.ID}}">{{.ID}}</a> </td>
158-
<td> {{.TotalTime}} </td>
159-
<td> {{.ExecTime}} </td>
160-
<td> {{.IOTime}} </td>
161-
<td> {{.BlockTime}} </td>
162-
<td> {{.SyscallTime}} </td>
163-
<td> {{.SchedWaitTime}} </td>
164-
<td> {{.SweepTime}} </td>
165-
<td> {{.GCTime}} </td>
266+
<td> {{prettyDuration .TotalTime}} </td>
267+
<td>
268+
<div class="stacked-bar-graph">
269+
{{if unknownTime .}}<span style="width:{{barLen (unknownTime .) $.MaxTotal}}" class="unknown-time">&nbsp;</span>{{end}}
270+
{{if .ExecTime}}<span style="width:{{barLen .ExecTime $.MaxTotal}}" class="exec-time">&nbsp;</span>{{end}}
271+
{{if .IOTime}}<span style="width:{{barLen .IOTime $.MaxTotal}}" class="io-time">&nbsp;</span>{{end}}
272+
{{if .BlockTime}}<span style="width:{{barLen .BlockTime $.MaxTotal}}" class="block-time">&nbsp;</span>{{end}}
273+
{{if .SyscallTime}}<span style="width:{{barLen .SyscallTime $.MaxTotal}}" class="syscall-time">&nbsp;</span>{{end}}
274+
{{if .SchedWaitTime}}<span style="width:{{barLen .SchedWaitTime $.MaxTotal}}" class="sched-time">&nbsp;</span>{{end}}
275+
</div>
276+
</td>
277+
<td> {{prettyDuration .ExecTime}}</td>
278+
<td> {{prettyDuration .IOTime}}</td>
279+
<td> {{prettyDuration .BlockTime}}</td>
280+
<td> {{prettyDuration .SyscallTime}}</td>
281+
<td> {{prettyDuration .SchedWaitTime}}</td>
282+
<td> {{prettyDuration .SweepTime}} {{percent .SweepTime .TotalTime}}</td>
283+
<td> {{prettyDuration .GCTime}} {{percent .GCTime .TotalTime}}</td>
166284
</tr>
167285
{{end}}
168286
</table>
169-
</body>
170-
</html>
171287
`))

0 commit comments

Comments
 (0)