diff options
| author | Carlos Amedee <carlos@golang.org> | 2024-05-07 10:37:48 -0400 |
|---|---|---|
| committer | Carlos Amedee <carlos@golang.org> | 2024-05-17 17:15:58 +0000 |
| commit | 01ad44bc08c7ea3b8a7d1d989051046c77b6a63d (patch) | |
| tree | 95f13942c0060668b197f4f84dda287914e4dbe6 /src/cmd/trace/annotations.go | |
| parent | 003683f41d667c8942657d6fd8bbf9e7c6925c87 (diff) | |
| download | go-01ad44bc08c7ea3b8a7d1d989051046c77b6a63d.tar.xz | |
cmd/trace: collapse v2 directory into trace
This change removes the old trace code and replaces it with the new tracer.
It does the following:
- Moves the contents of the v2 directory into the parent trace directory.
- Combines the old tracer main file with the new main file.
- Replaces any existing files with the corresponding v2 files.
- Removes any unused files.
Updates #67367
Change-Id: I2237920e13588258a2442b639d562cf7f8a8e944
Reviewed-on: https://go-review.googlesource.com/c/go/+/584536
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Michael Knyszek <mknyszek@google.com>
Diffstat (limited to 'src/cmd/trace/annotations.go')
| -rw-r--r-- | src/cmd/trace/annotations.go | 1196 |
1 files changed, 0 insertions, 1196 deletions
diff --git a/src/cmd/trace/annotations.go b/src/cmd/trace/annotations.go deleted file mode 100644 index df194a7598..0000000000 --- a/src/cmd/trace/annotations.go +++ /dev/null @@ -1,1196 +0,0 @@ -// Copyright 2018 The Go Authors. All rights reserved. -// Use of this source code is governed by a BSD-style -// license that can be found in the LICENSE file. - -package main - -import ( - "bytes" - "fmt" - "html/template" - "internal/trace" - "internal/trace/traceviewer" - "log" - "net/http" - "net/url" - "reflect" - "sort" - "strconv" - "strings" - "time" -) - -func init() { - http.HandleFunc("/usertasks", httpUserTasks) - http.HandleFunc("/usertask", httpUserTask) - http.HandleFunc("/userregions", httpUserRegions) - http.HandleFunc("/userregion", httpUserRegion) -} - -// httpUserTasks reports all tasks found in the trace. -func httpUserTasks(w http.ResponseWriter, r *http.Request) { - res, err := analyzeAnnotations() - if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } - - tasks := res.tasks - summary := make(map[string]taskStats) - for _, task := range tasks { - stats, ok := summary[task.name] - if !ok { - stats.Type = task.name - } - - stats.add(task) - summary[task.name] = stats - } - - // Sort tasks by type. - userTasks := make([]taskStats, 0, len(summary)) - for _, stats := range summary { - userTasks = append(userTasks, stats) - } - sort.Slice(userTasks, func(i, j int) bool { - return userTasks[i].Type < userTasks[j].Type - }) - - // Emit table. - err = templUserTaskTypes.Execute(w, userTasks) - if err != nil { - http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError) - return - } -} - -func httpUserRegions(w http.ResponseWriter, r *http.Request) { - res, err := analyzeAnnotations() - if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } - allRegions := res.regions - - summary := make(map[regionTypeID]regionStats) - for id, regions := range allRegions { - stats, ok := summary[id] - if !ok { - stats.regionTypeID = id - } - for _, s := range regions { - stats.add(s) - } - summary[id] = stats - } - // Sort regions by pc and name - userRegions := make([]regionStats, 0, len(summary)) - for _, stats := range summary { - userRegions = append(userRegions, stats) - } - sort.Slice(userRegions, func(i, j int) bool { - if userRegions[i].Type != userRegions[j].Type { - return userRegions[i].Type < userRegions[j].Type - } - return userRegions[i].Frame.PC < userRegions[j].Frame.PC - }) - // Emit table. - err = templUserRegionTypes.Execute(w, userRegions) - if err != nil { - http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError) - return - } -} - -func httpUserRegion(w http.ResponseWriter, r *http.Request) { - filter, err := newRegionFilter(r) - if err != nil { - http.Error(w, err.Error(), http.StatusBadRequest) - return - } - res, err := analyzeAnnotations() - if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } - allRegions := res.regions - - var data []regionDesc - - var maxTotal int64 - for id, regions := range allRegions { - for _, s := range regions { - if !filter.match(id, s) { - continue - } - data = append(data, s) - if maxTotal < s.TotalTime { - maxTotal = s.TotalTime - } - } - } - - sortby := r.FormValue("sortby") - _, ok := reflect.TypeOf(regionDesc{}).FieldByNameFunc(func(s string) bool { - return s == sortby - }) - if !ok { - sortby = "TotalTime" - } - sort.Slice(data, func(i, j int) bool { - ival := reflect.ValueOf(data[i]).FieldByName(sortby).Int() - jval := reflect.ValueOf(data[j]).FieldByName(sortby).Int() - return ival > jval - }) - - err = templUserRegionType.Execute(w, struct { - MaxTotal int64 - Data []regionDesc - Name string - Filter *regionFilter - }{ - MaxTotal: maxTotal, - Data: data, - Name: filter.name, - Filter: filter, - }) - if err != nil { - http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError) - return - } -} - -// httpUserTask presents the details of the selected tasks. -func httpUserTask(w http.ResponseWriter, r *http.Request) { - filter, err := newTaskFilter(r) - if err != nil { - http.Error(w, err.Error(), http.StatusBadRequest) - return - } - - res, err := analyzeAnnotations() - if err != nil { - http.Error(w, err.Error(), http.StatusInternalServerError) - return - } - tasks := res.tasks - - type event struct { - WhenString string - Elapsed time.Duration - Go uint64 - What string - // TODO: include stack trace of creation time - } - type entry struct { - WhenString string - ID uint64 - Duration time.Duration - Complete bool - Events []event - Start, End time.Duration // Time since the beginning of the trace - GCTime time.Duration - } - - base := time.Duration(firstTimestamp()) * time.Nanosecond // trace start - - var data []entry - - for _, task := range tasks { - if !filter.match(task) { - continue - } - // merge events in the task.events and task.regions.Start - rawEvents := append([]*trace.Event{}, task.events...) - for _, s := range task.regions { - if s.Start != nil { - rawEvents = append(rawEvents, s.Start) - } - } - sort.SliceStable(rawEvents, func(i, j int) bool { return rawEvents[i].Ts < rawEvents[j].Ts }) - - var events []event - var last time.Duration - for i, ev := range rawEvents { - when := time.Duration(ev.Ts)*time.Nanosecond - base - elapsed := time.Duration(ev.Ts)*time.Nanosecond - last - if i == 0 { - elapsed = 0 - } - - what := describeEvent(ev) - if what != "" { - events = append(events, event{ - WhenString: fmt.Sprintf("%2.9f", when.Seconds()), - Elapsed: elapsed, - What: what, - Go: ev.G, - }) - last = time.Duration(ev.Ts) * time.Nanosecond - } - } - - data = append(data, entry{ - WhenString: fmt.Sprintf("%2.9fs", (time.Duration(task.firstTimestamp())*time.Nanosecond - base).Seconds()), - Duration: task.duration(), - ID: task.id, - Complete: task.complete(), - Events: events, - Start: time.Duration(task.firstTimestamp()) * time.Nanosecond, - End: time.Duration(task.endTimestamp()) * time.Nanosecond, - GCTime: task.overlappingGCDuration(res.gcEvents), - }) - } - sort.Slice(data, func(i, j int) bool { - return data[i].Duration < data[j].Duration - }) - - // Emit table. - err = templUserTaskType.Execute(w, struct { - Name string - Entry []entry - }{ - Name: filter.name, - Entry: data, - }) - if err != nil { - log.Printf("failed to execute template: %v", err) - http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError) - return - } -} - -type annotationAnalysisResult struct { - tasks map[uint64]*taskDesc // tasks - regions map[regionTypeID][]regionDesc // regions - gcEvents []*trace.Event // GCStartevents, sorted -} - -type regionTypeID struct { - Frame trace.Frame // top frame - Type string -} - -// analyzeAnnotations analyzes user annotation events and -// returns the task descriptors keyed by internal task id. -func analyzeAnnotations() (annotationAnalysisResult, error) { - res, err := parseTrace() - if err != nil { - return annotationAnalysisResult{}, fmt.Errorf("failed to parse trace: %v", err) - } - - events := res.Events - if len(events) == 0 { - return annotationAnalysisResult{}, fmt.Errorf("empty trace") - } - - tasks := allTasks{} - regions := map[regionTypeID][]regionDesc{} - var gcEvents []*trace.Event - - for _, ev := range events { - switch typ := ev.Type; typ { - case trace.EvUserTaskCreate, trace.EvUserTaskEnd, trace.EvUserLog: - taskid := ev.Args[0] - task := tasks.task(taskid) - task.addEvent(ev) - - // retrieve parent task information - if typ == trace.EvUserTaskCreate { - if parentID := ev.Args[1]; parentID != 0 { - parentTask := tasks.task(parentID) - task.parent = parentTask - if parentTask != nil { - parentTask.children = append(parentTask.children, task) - } - } - } - - case trace.EvGCStart: - gcEvents = append(gcEvents, ev) - } - } - // combine region info. - analyzeGoroutines(events) - for goid, stats := range gs { - // gs is a global var defined in goroutines.go as a result - // of analyzeGoroutines. TODO(hyangah): fix this not to depend - // on a 'global' var. - for _, s := range stats.Regions { - if s.TaskID != 0 { - task := tasks.task(s.TaskID) - task.goroutines[goid] = struct{}{} - task.regions = append(task.regions, regionDesc{UserRegionDesc: s, G: goid}) - } - var frame trace.Frame - if s.Start != nil { - frame = *s.Start.Stk[0] - } - id := regionTypeID{Frame: frame, Type: s.Name} - regions[id] = append(regions[id], regionDesc{UserRegionDesc: s, G: goid}) - } - } - - // sort regions in tasks based on the timestamps. - for _, task := range tasks { - sort.SliceStable(task.regions, func(i, j int) bool { - si, sj := task.regions[i].firstTimestamp(), task.regions[j].firstTimestamp() - if si != sj { - return si < sj - } - return task.regions[i].lastTimestamp() < task.regions[j].lastTimestamp() - }) - } - return annotationAnalysisResult{tasks: tasks, regions: regions, gcEvents: gcEvents}, nil -} - -// taskDesc represents a task. -type taskDesc struct { - name string // user-provided task name - id uint64 // internal task id - events []*trace.Event // sorted based on timestamp. - regions []regionDesc // associated regions, sorted based on the start timestamp and then the last timestamp. - goroutines map[uint64]struct{} // involved goroutines - - create *trace.Event // Task create event - end *trace.Event // Task end event - - parent *taskDesc - children []*taskDesc -} - -func newTaskDesc(id uint64) *taskDesc { - return &taskDesc{ - id: id, - goroutines: make(map[uint64]struct{}), - } -} - -func (task *taskDesc) String() string { - if task == nil { - return "task <nil>" - } - wb := new(strings.Builder) - fmt.Fprintf(wb, "task %d:\t%s\n", task.id, task.name) - fmt.Fprintf(wb, "\tstart: %v end: %v complete: %t\n", task.firstTimestamp(), task.endTimestamp(), task.complete()) - fmt.Fprintf(wb, "\t%d goroutines\n", len(task.goroutines)) - fmt.Fprintf(wb, "\t%d regions:\n", len(task.regions)) - for _, s := range task.regions { - fmt.Fprintf(wb, "\t\t%s(goid=%d)\n", s.Name, s.G) - } - if task.parent != nil { - fmt.Fprintf(wb, "\tparent: %s\n", task.parent.name) - } - fmt.Fprintf(wb, "\t%d children:\n", len(task.children)) - for _, c := range task.children { - fmt.Fprintf(wb, "\t\t%s\n", c.name) - } - - return wb.String() -} - -// regionDesc represents a region. -type regionDesc struct { - *trace.UserRegionDesc - G uint64 // id of goroutine where the region was defined -} - -type allTasks map[uint64]*taskDesc - -func (tasks allTasks) task(taskID uint64) *taskDesc { - if taskID == 0 { - return nil // notask - } - - t, ok := tasks[taskID] - if ok { - return t - } - - t = newTaskDesc(taskID) - tasks[taskID] = t - return t -} - -func (task *taskDesc) addEvent(ev *trace.Event) { - if task == nil { - return - } - - task.events = append(task.events, ev) - task.goroutines[ev.G] = struct{}{} - - switch typ := ev.Type; typ { - case trace.EvUserTaskCreate: - task.name = ev.SArgs[0] - task.create = ev - case trace.EvUserTaskEnd: - task.end = ev - } -} - -// complete is true only if both start and end events of this task -// are present in the trace. -func (task *taskDesc) complete() bool { - if task == nil { - return false - } - return task.create != nil && task.end != nil -} - -// descendants returns all the task nodes in the subtree rooted from this task. -func (task *taskDesc) descendants() []*taskDesc { - if task == nil { - return nil - } - res := []*taskDesc{task} - for i := 0; len(res[i:]) > 0; i++ { - t := res[i] - res = append(res, t.children...) - } - return res -} - -// firstTimestamp returns the first timestamp of this task found in -// this trace. If the trace does not contain the task creation event, -// the first timestamp of the trace will be returned. -func (task *taskDesc) firstTimestamp() int64 { - if task != nil && task.create != nil { - return task.create.Ts - } - return firstTimestamp() -} - -// lastTimestamp returns the last timestamp of this task in this -// trace. If the trace does not contain the task end event, the last -// timestamp of the trace will be returned. -func (task *taskDesc) lastTimestamp() int64 { - endTs := task.endTimestamp() - if last := task.lastEvent(); last != nil && last.Ts > endTs { - return last.Ts - } - return endTs -} - -// endTimestamp returns the timestamp of this task's end event. -// If the trace does not contain the task end event, the last -// timestamp of the trace will be returned. -func (task *taskDesc) endTimestamp() int64 { - if task != nil && task.end != nil { - return task.end.Ts - } - return lastTimestamp() -} - -func (task *taskDesc) duration() time.Duration { - return time.Duration(task.endTimestamp()-task.firstTimestamp()) * time.Nanosecond -} - -func (region *regionDesc) duration() time.Duration { - return time.Duration(region.lastTimestamp()-region.firstTimestamp()) * time.Nanosecond -} - -// overlappingGCDuration returns the sum of GC period overlapping with the task's lifetime. -func (task *taskDesc) overlappingGCDuration(evs []*trace.Event) (overlapping time.Duration) { - for _, ev := range evs { - // make sure we only consider the global GC events. - if typ := ev.Type; typ != trace.EvGCStart { - continue - } - - if o, overlapped := task.overlappingDuration(ev); overlapped { - overlapping += o - } - } - return overlapping -} - -// overlappingInstant reports whether the instantaneous event, ev, occurred during -// any of the task's region if ev is a goroutine-local event, or overlaps with the -// task's lifetime if ev is a global event. -func (task *taskDesc) overlappingInstant(ev *trace.Event) bool { - if _, ok := isUserAnnotationEvent(ev); ok && task.id != ev.Args[0] { - return false // not this task's user event. - } - - ts := ev.Ts - taskStart := task.firstTimestamp() - taskEnd := task.endTimestamp() - if ts < taskStart || taskEnd < ts { - return false - } - if ev.P == trace.GCP { - return true - } - - // Goroutine local event. Check whether there are regions overlapping with the event. - goid := ev.G - for _, region := range task.regions { - if region.G != goid { - continue - } - if region.firstTimestamp() <= ts && ts <= region.lastTimestamp() { - return true - } - } - return false -} - -// overlappingDuration reports whether the durational event, ev, overlaps with -// any of the task's region if ev is a goroutine-local event, or overlaps with -// the task's lifetime if ev is a global event. It returns the overlapping time -// as well. -func (task *taskDesc) overlappingDuration(ev *trace.Event) (time.Duration, bool) { - start := ev.Ts - end := lastTimestamp() - if ev.Link != nil { - end = ev.Link.Ts - } - - if start > end { - return 0, false - } - - goid := ev.G - goid2 := ev.G - if ev.Link != nil { - goid2 = ev.Link.G - } - - // This event is a global GC event - if ev.P == trace.GCP { - taskStart := task.firstTimestamp() - taskEnd := task.endTimestamp() - o := overlappingDuration(taskStart, taskEnd, start, end) - return o, o > 0 - } - - // Goroutine local event. Check whether there are regions overlapping with the event. - var overlapping time.Duration - var lastRegionEnd int64 // the end of previous overlapping region - for _, region := range task.regions { - if region.G != goid && region.G != goid2 { - continue - } - regionStart, regionEnd := region.firstTimestamp(), region.lastTimestamp() - if regionStart < lastRegionEnd { // skip nested regions - continue - } - - if o := overlappingDuration(regionStart, regionEnd, start, end); o > 0 { - // overlapping. - lastRegionEnd = regionEnd - overlapping += o - } - } - return overlapping, overlapping > 0 -} - -// overlappingDuration returns the overlapping time duration between -// two time intervals [start1, end1] and [start2, end2] where -// start, end parameters are all int64 representing nanoseconds. -func overlappingDuration(start1, end1, start2, end2 int64) time.Duration { - // assume start1 <= end1 and start2 <= end2 - if end1 < start2 || end2 < start1 { - return 0 - } - - if start1 < start2 { // choose the later one - start1 = start2 - } - if end1 > end2 { // choose the earlier one - end1 = end2 - } - return time.Duration(end1 - start1) -} - -func (task *taskDesc) lastEvent() *trace.Event { - if task == nil { - return nil - } - - if n := len(task.events); n > 0 { - return task.events[n-1] - } - return nil -} - -// firstTimestamp returns the timestamp of region start event. -// If the region's start event is not present in the trace, -// the first timestamp of the trace will be returned. -func (region *regionDesc) firstTimestamp() int64 { - if region.Start != nil { - return region.Start.Ts - } - return firstTimestamp() -} - -// lastTimestamp returns the timestamp of region end event. -// If the region's end event is not present in the trace, -// the last timestamp of the trace will be returned. -func (region *regionDesc) lastTimestamp() int64 { - if region.End != nil { - return region.End.Ts - } - return lastTimestamp() -} - -// RelatedGoroutines returns IDs of goroutines related to the task. A goroutine -// is related to the task if user annotation activities for the task occurred. -// If non-zero depth is provided, this searches all events with BFS and includes -// goroutines unblocked any of related goroutines to the result. -func (task *taskDesc) RelatedGoroutines(events []*trace.Event, depth int) map[uint64]bool { - start, end := task.firstTimestamp(), task.endTimestamp() - - gmap := map[uint64]bool{} - for k := range task.goroutines { - gmap[k] = true - } - - for i := 0; i < depth; i++ { - gmap1 := make(map[uint64]bool) - for g := range gmap { - gmap1[g] = true - } - for _, ev := range events { - if ev.Ts < start || ev.Ts > end { - continue - } - if ev.Type == trace.EvGoUnblock && gmap[ev.Args[0]] { - gmap1[ev.G] = true - } - gmap = gmap1 - } - } - gmap[0] = true // for GC events (goroutine id = 0) - return gmap -} - -type taskFilter struct { - name string - cond []func(*taskDesc) bool -} - -func (f *taskFilter) match(t *taskDesc) bool { - if t == nil { - return false - } - for _, c := range f.cond { - if !c(t) { - return false - } - } - return true -} - -func newTaskFilter(r *http.Request) (*taskFilter, error) { - if err := r.ParseForm(); err != nil { - return nil, err - } - - var name []string - var conditions []func(*taskDesc) bool - - param := r.Form - if typ, ok := param["type"]; ok && len(typ) > 0 { - name = append(name, "type="+typ[0]) - conditions = append(conditions, func(t *taskDesc) bool { - return t.name == typ[0] - }) - } - if complete := r.FormValue("complete"); complete == "1" { - name = append(name, "complete") - conditions = append(conditions, func(t *taskDesc) bool { - return t.complete() - }) - } else if complete == "0" { - name = append(name, "incomplete") - conditions = append(conditions, func(t *taskDesc) bool { - return !t.complete() - }) - } - if lat, err := time.ParseDuration(r.FormValue("latmin")); err == nil { - name = append(name, fmt.Sprintf("latency >= %s", lat)) - conditions = append(conditions, func(t *taskDesc) bool { - return t.complete() && t.duration() >= lat - }) - } - if lat, err := time.ParseDuration(r.FormValue("latmax")); err == nil { - name = append(name, fmt.Sprintf("latency <= %s", lat)) - conditions = append(conditions, func(t *taskDesc) bool { - return t.complete() && t.duration() <= lat - }) - } - if text := r.FormValue("logtext"); text != "" { - name = append(name, fmt.Sprintf("log contains %q", text)) - conditions = append(conditions, func(t *taskDesc) bool { - return taskMatches(t, text) - }) - } - - return &taskFilter{name: strings.Join(name, ","), cond: conditions}, nil -} - -func taskMatches(t *taskDesc, text string) bool { - for _, ev := range t.events { - switch ev.Type { - case trace.EvUserTaskCreate, trace.EvUserRegion, trace.EvUserLog: - for _, s := range ev.SArgs { - if strings.Contains(s, text) { - return true - } - } - } - } - return false -} - -type regionFilter struct { - name string - params url.Values - cond []func(regionTypeID, regionDesc) bool -} - -func (f *regionFilter) match(id regionTypeID, s regionDesc) bool { - for _, c := range f.cond { - if !c(id, s) { - return false - } - } - return true -} - -func newRegionFilter(r *http.Request) (*regionFilter, error) { - if err := r.ParseForm(); err != nil { - return nil, err - } - - var name []string - var conditions []func(regionTypeID, regionDesc) bool - filterParams := make(url.Values) - - param := r.Form - if typ, ok := param["type"]; ok && len(typ) > 0 { - name = append(name, "type="+typ[0]) - conditions = append(conditions, func(id regionTypeID, s regionDesc) bool { - return id.Type == typ[0] - }) - filterParams.Add("type", typ[0]) - } - if pc, err := strconv.ParseUint(r.FormValue("pc"), 16, 64); err == nil { - encPC := fmt.Sprintf("%x", pc) - name = append(name, "pc="+encPC) - conditions = append(conditions, func(id regionTypeID, s regionDesc) bool { - return id.Frame.PC == pc - }) - filterParams.Add("pc", encPC) - } - - if lat, err := time.ParseDuration(r.FormValue("latmin")); err == nil { - name = append(name, fmt.Sprintf("latency >= %s", lat)) - conditions = append(conditions, func(_ regionTypeID, s regionDesc) bool { - return s.duration() >= lat - }) - filterParams.Add("latmin", lat.String()) - } - if lat, err := time.ParseDuration(r.FormValue("latmax")); err == nil { - name = append(name, fmt.Sprintf("latency <= %s", lat)) - conditions = append(conditions, func(_ regionTypeID, s regionDesc) bool { - return s.duration() <= lat - }) - filterParams.Add("latmax", lat.String()) - } - - return ®ionFilter{ - name: strings.Join(name, ","), - cond: conditions, - params: filterParams, - }, nil -} - -type regionStats struct { - regionTypeID - Histogram traceviewer.TimeHistogram -} - -func (s *regionStats) UserRegionURL() func(min, max time.Duration) string { - return func(min, max time.Duration) string { - return fmt.Sprintf("/userregion?type=%s&pc=%x&latmin=%v&latmax=%v", template.URLQueryEscaper(s.Type), s.Frame.PC, template.URLQueryEscaper(min), template.URLQueryEscaper(max)) - } -} - -func (s *regionStats) add(region regionDesc) { - s.Histogram.Add(region.duration()) -} - -var templUserRegionTypes = template.Must(template.New("").Parse(` -<html> -<style type="text/css"> -.histoTime { - width: 20%; - white-space:nowrap; -} - -</style> -<body> -<table border="1" sortable="1"> -<tr> -<th>Region type</th> -<th>Count</th> -<th>Duration distribution (complete tasks)</th> -</tr> -{{range $}} - <tr> - <td>{{.Type}}<br>{{.Frame.Fn}}<br>{{.Frame.File}}:{{.Frame.Line}}</td> - <td><a href="/userregion?type={{.Type}}&pc={{.Frame.PC | printf "%x"}}">{{.Histogram.Count}}</a></td> - <td>{{.Histogram.ToHTML (.UserRegionURL)}}</td> - </tr> -{{end}} -</table> -</body> -</html> -`)) - -type taskStats struct { - Type string - Count int // Complete + incomplete tasks - Histogram traceviewer.TimeHistogram // Complete tasks only -} - -func (s *taskStats) UserTaskURL(complete bool) func(min, max time.Duration) string { - return func(min, max time.Duration) string { - return fmt.Sprintf("/usertask?type=%s&complete=%v&latmin=%v&latmax=%v", template.URLQueryEscaper(s.Type), template.URLQueryEscaper(complete), template.URLQueryEscaper(min), template.URLQueryEscaper(max)) - } -} - -func (s *taskStats) add(task *taskDesc) { - s.Count++ - if task.complete() { - s.Histogram.Add(task.duration()) - } -} - -var templUserTaskTypes = template.Must(template.New("").Parse(` -<html> -<style type="text/css"> -.histoTime { - width: 20%; - white-space:nowrap; -} - -</style> -<body> -Search log text: <form action="/usertask"><input name="logtext" type="text"><input type="submit"></form><br> -<table border="1" sortable="1"> -<tr> -<th>Task type</th> -<th>Count</th> -<th>Duration distribution (complete tasks)</th> -</tr> -{{range $}} - <tr> - <td>{{.Type}}</td> - <td><a href="/usertask?type={{.Type}}">{{.Count}}</a></td> - <td>{{.Histogram.ToHTML (.UserTaskURL true)}}</td> - </tr> -{{end}} -</table> -</body> -</html> -`)) - -var templUserTaskType = template.Must(template.New("userTask").Funcs(template.FuncMap{ - "elapsed": elapsed, - "asMillisecond": asMillisecond, - "trimSpace": strings.TrimSpace, -}).Parse(` -<html> -<head> <title>User Task: {{.Name}} </title> </head> - <style type="text/css"> - body { - font-family: sans-serif; - } - table#req-status td.family { - padding-right: 2em; - } - table#req-status td.active { - padding-right: 1em; - } - table#req-status td.empty { - color: #aaa; - } - table#reqs { - margin-top: 1em; - } - table#reqs tr.first { - font-weight: bold; - } - table#reqs td { - font-family: monospace; - } - table#reqs td.when { - text-align: right; - white-space: nowrap; - } - table#reqs td.elapsed { - padding: 0 0.5em; - text-align: right; - white-space: pre; - width: 10em; - } - address { - font-size: smaller; - margin-top: 5em; - } - </style> -<body> - -<h2>User Task: {{.Name}}</h2> - -Search log text: <form onsubmit="window.location.search+='&logtext='+window.logtextinput.value; return false"> -<input name="logtext" id="logtextinput" type="text"><input type="submit"> -</form><br> - -<table id="reqs"> -<tr><th>When</th><th>Elapsed</th><th>Goroutine ID</th><th>Events</th></tr> - {{range $el := $.Entry}} - <tr class="first"> - <td class="when">{{$el.WhenString}}</td> - <td class="elapsed">{{$el.Duration}}</td> - <td></td> - <td> -<a href="/trace?focustask={{$el.ID}}#{{asMillisecond $el.Start}}:{{asMillisecond $el.End}}">Task {{$el.ID}}</a> -<a href="/trace?taskid={{$el.ID}}#{{asMillisecond $el.Start}}:{{asMillisecond $el.End}}">(goroutine view)</a> -({{if .Complete}}complete{{else}}incomplete{{end}})</td> - </tr> - {{range $el.Events}} - <tr> - <td class="when">{{.WhenString}}</td> - <td class="elapsed">{{elapsed .Elapsed}}</td> - <td class="goid">{{.Go}}</td> - <td>{{.What}}</td> - </tr> - {{end}} - <tr> - <td></td> - <td></td> - <td></td> - <td>GC:{{$el.GCTime}}</td> - {{end}} -</body> -</html> -`)) - -func elapsed(d time.Duration) string { - b := fmt.Appendf(nil, "%.9f", d.Seconds()) - - // For subsecond durations, blank all zeros before decimal point, - // and all zeros between the decimal point and the first non-zero digit. - if d < time.Second { - dot := bytes.IndexByte(b, '.') - for i := 0; i < dot; i++ { - b[i] = ' ' - } - for i := dot + 1; i < len(b); i++ { - if b[i] == '0' { - b[i] = ' ' - } else { - break - } - } - } - - return string(b) -} - -func asMillisecond(d time.Duration) float64 { - return float64(d.Nanoseconds()) / 1e6 -} - -func formatUserLog(ev *trace.Event) string { - k, v := ev.SArgs[0], ev.SArgs[1] - if k == "" { - return v - } - if v == "" { - return k - } - return fmt.Sprintf("%v=%v", k, v) -} - -func describeEvent(ev *trace.Event) string { - switch ev.Type { - case trace.EvGoCreate: - goid := ev.Args[0] - return fmt.Sprintf("new goroutine %d: %s", goid, gs[goid].Name) - case trace.EvGoEnd, trace.EvGoStop: - return "goroutine stopped" - case trace.EvUserLog: - return formatUserLog(ev) - case trace.EvUserRegion: - if ev.Args[1] == 0 { - duration := "unknown" - if ev.Link != nil { - duration = (time.Duration(ev.Link.Ts-ev.Ts) * time.Nanosecond).String() - } - return fmt.Sprintf("region %s started (duration: %v)", ev.SArgs[0], duration) - } - return fmt.Sprintf("region %s ended", ev.SArgs[0]) - case trace.EvUserTaskCreate: - return fmt.Sprintf("task %v (id %d, parent %d) created", ev.SArgs[0], ev.Args[0], ev.Args[1]) - // TODO: add child task creation events into the parent task events - case trace.EvUserTaskEnd: - return "task end" - } - return "" -} - -func isUserAnnotationEvent(ev *trace.Event) (taskID uint64, ok bool) { - switch ev.Type { - case trace.EvUserLog, trace.EvUserRegion, trace.EvUserTaskCreate, trace.EvUserTaskEnd: - return ev.Args[0], true - } - return 0, false -} - -var templUserRegionType = template.Must(template.New("").Funcs(template.FuncMap{ - "prettyDuration": func(nsec int64) template.HTML { - d := time.Duration(nsec) * time.Nanosecond - return template.HTML(d.String()) - }, - "percent": func(dividend, divisor int64) template.HTML { - if divisor == 0 { - return "" - } - return template.HTML(fmt.Sprintf("(%.1f%%)", float64(dividend)/float64(divisor)*100)) - }, - "barLen": func(dividend, divisor int64) template.HTML { - if divisor == 0 { - return "0" - } - return template.HTML(fmt.Sprintf("%.2f%%", float64(dividend)/float64(divisor)*100)) - }, - "unknownTime": func(desc regionDesc) int64 { - sum := desc.ExecTime + desc.IOTime + desc.BlockTime + desc.SyscallTime + desc.SchedWaitTime - if sum < desc.TotalTime { - return desc.TotalTime - sum - } - return 0 - }, - "filterParams": func(f *regionFilter) template.URL { - return template.URL(f.params.Encode()) - }, -}).Parse(` -<!DOCTYPE html> -<title>User Region {{.Name}}</title> -<style> -th { - background-color: #050505; - color: #fff; -} -th.total-time, -th.exec-time, -th.io-time, -th.block-time, -th.syscall-time, -th.sched-time, -th.sweep-time, -th.pause-time { - cursor: pointer; -} -table { - border-collapse: collapse; -} -.details tr:hover { - background-color: #f2f2f2; -} -.details td { - text-align: right; - border: 1px solid #000; -} -.details td.id { - text-align: left; -} -.stacked-bar-graph { - width: 300px; - height: 10px; - color: #414042; - white-space: nowrap; - font-size: 5px; -} -.stacked-bar-graph span { - display: inline-block; - width: 100%; - height: 100%; - box-sizing: border-box; - float: left; - padding: 0; -} -.unknown-time { background-color: #636363; } -.exec-time { background-color: #d7191c; } -.io-time { background-color: #fdae61; } -.block-time { background-color: #d01c8b; } -.syscall-time { background-color: #7b3294; } -.sched-time { background-color: #2c7bb6; } -</style> - -<script> -function reloadTable(key, value) { - let params = new URLSearchParams(window.location.search); - params.set(key, value); - window.location.search = params.toString(); -} -</script> - -<h2>{{.Name}}</h2> - -{{ with $p := filterParams .Filter}} -<table class="summary"> - <tr><td>Network Wait Time:</td><td> <a href="/regionio?{{$p}}">graph</a><a href="/regionio?{{$p}}&raw=1" download="io.profile">(download)</a></td></tr> - <tr><td>Sync Block Time:</td><td> <a href="/regionblock?{{$p}}">graph</a><a href="/regionblock?{{$p}}&raw=1" download="block.profile">(download)</a></td></tr> - <tr><td>Blocking Syscall Time:</td><td> <a href="/regionsyscall?{{$p}}">graph</a><a href="/regionsyscall?{{$p}}&raw=1" download="syscall.profile">(download)</a></td></tr> - <tr><td>Scheduler Wait Time:</td><td> <a href="/regionsched?{{$p}}">graph</a><a href="/regionsched?{{$p}}&raw=1" download="sched.profile">(download)</a></td></tr> -</table> -{{ end }} -<p> -<table class="details"> -<tr> -<th> Goroutine </th> -<th> Task </th> -<th onclick="reloadTable('sortby', 'TotalTime')" class="total-time"> Total</th> -<th></th> -<th onclick="reloadTable('sortby', 'ExecTime')" class="exec-time"> Execution</th> -<th onclick="reloadTable('sortby', 'IOTime')" class="io-time"> Network wait</th> -<th onclick="reloadTable('sortby', 'BlockTime')" class="block-time"> Sync block </th> -<th onclick="reloadTable('sortby', 'SyscallTime')" class="syscall-time"> Blocking syscall</th> -<th onclick="reloadTable('sortby', 'SchedWaitTime')" class="sched-time"> Scheduler wait</th> -<th onclick="reloadTable('sortby', 'SweepTime')" class="sweep-time"> GC sweeping</th> -<th onclick="reloadTable('sortby', 'GCTime')" class="pause-time"> GC pause</th> -</tr> -{{range .Data}} - <tr> - <td> <a href="/trace?goid={{.G}}">{{.G}}</a> </td> - <td> {{if .TaskID}}<a href="/trace?focustask={{.TaskID}}">{{.TaskID}}</a>{{end}} </td> - <td> {{prettyDuration .TotalTime}} </td> - <td> - <div class="stacked-bar-graph"> - {{if unknownTime .}}<span style="width:{{barLen (unknownTime .) $.MaxTotal}}" class="unknown-time"> </span>{{end}} - {{if .ExecTime}}<span style="width:{{barLen .ExecTime $.MaxTotal}}" class="exec-time"> </span>{{end}} - {{if .IOTime}}<span style="width:{{barLen .IOTime $.MaxTotal}}" class="io-time"> </span>{{end}} - {{if .BlockTime}}<span style="width:{{barLen .BlockTime $.MaxTotal}}" class="block-time"> </span>{{end}} - {{if .SyscallTime}}<span style="width:{{barLen .SyscallTime $.MaxTotal}}" class="syscall-time"> </span>{{end}} - {{if .SchedWaitTime}}<span style="width:{{barLen .SchedWaitTime $.MaxTotal}}" class="sched-time"> </span>{{end}} - </div> - </td> - <td> {{prettyDuration .ExecTime}}</td> - <td> {{prettyDuration .IOTime}}</td> - <td> {{prettyDuration .BlockTime}}</td> - <td> {{prettyDuration .SyscallTime}}</td> - <td> {{prettyDuration .SchedWaitTime}}</td> - <td> {{prettyDuration .SweepTime}} {{percent .SweepTime .TotalTime}}</td> - <td> {{prettyDuration .GCTime}} {{percent .GCTime .TotalTime}}</td> - </tr> -{{end}} -</table> -</p> -`)) |
