codekingpro/portable-devtools

1// Copyright 2023 The Go Authors. All rights reserved.2// Use of this source code is governed by a BSD-style3// license that can be found in the LICENSE file.4 5package main6 7import (8	"bytes"9	"cmp"10	"fmt"11	"html/template"12	"internal/trace"13	"internal/trace/traceviewer"14	"log"15	"net/http"16	"slices"17	"strings"18	"time"19)20 21// UserTasksHandlerFunc returns a HandlerFunc that reports all tasks found in the trace.22func UserTasksHandlerFunc(t *parsedTrace) http.HandlerFunc {23	return func(w http.ResponseWriter, r *http.Request) {24		tasks := t.summary.Tasks25 26		// Summarize groups of tasks with the same name.27		summary := make(map[string]taskStats)28		for _, task := range tasks {29			stats, ok := summary[task.Name]30			if !ok {31				stats.Type = task.Name32			}33			stats.add(task)34			summary[task.Name] = stats35		}36 37		// Sort tasks by type.38		userTasks := make([]taskStats, 0, len(summary))39		for _, stats := range summary {40			userTasks = append(userTasks, stats)41		}42		slices.SortFunc(userTasks, func(a, b taskStats) int {43			return cmp.Compare(a.Type, b.Type)44		})45 46		// Emit table.47		err := templUserTaskTypes.Execute(w, userTasks)48		if err != nil {49			http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError)50			return51		}52	}53}54 55type taskStats struct {56	Type      string57	Count     int                       // Complete + incomplete tasks58	Histogram traceviewer.TimeHistogram // Complete tasks only59}60 61func (s *taskStats) UserTaskURL(complete bool) func(min, max time.Duration) string {62	return func(min, max time.Duration) string {63		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))64	}65}66 67func (s *taskStats) add(task *trace.UserTaskSummary) {68	s.Count++69	if task.Complete() {70		s.Histogram.Add(task.End.Time().Sub(task.Start.Time()))71	}72}73 74var templUserTaskTypes = template.Must(template.New("").Parse(`75<!DOCTYPE html>76<title>Tasks</title>77<style>` + traceviewer.CommonStyle + `78.histoTime {79  width: 20%;80  white-space:nowrap;81}82th {83  background-color: #050505;84  color: #fff;85}86table {87  border-collapse: collapse;88}89td,90th {91  padding-left: 8px;92  padding-right: 8px;93  padding-top: 4px;94  padding-bottom: 4px;95}96</style>97<body>98Search log text: <form action="/usertask"><input name="logtext" type="text"><input type="submit"></form><br>99<table border="1" sortable="1">100<tr>101<th>Task type</th>102<th>Count</th>103<th>Duration distribution (complete tasks)</th>104</tr>105{{range $}}106  <tr>107    <td>{{.Type}}</td>108    <td><a href="/usertask?type={{.Type}}">{{.Count}}</a></td>109    <td>{{.Histogram.ToHTML (.UserTaskURL true)}}</td>110  </tr>111{{end}}112</table>113</body>114</html>115`))116 117// UserTaskHandlerFunc returns a HandlerFunc that presents the details of the selected tasks.118func UserTaskHandlerFunc(t *parsedTrace) http.HandlerFunc {119	return func(w http.ResponseWriter, r *http.Request) {120		filter, err := newTaskFilter(r)121		if err != nil {122			http.Error(w, err.Error(), http.StatusBadRequest)123			return124		}125		type event struct {126			WhenString string127			Elapsed    time.Duration128			Goroutine  trace.GoID129			What       string130			// TODO: include stack trace of creation time131		}132		type task struct {133			WhenString string134			ID         trace.TaskID135			Duration   time.Duration136			Complete   bool137			Events     []event138			Start, End time.Duration // Time since the beginning of the trace139			GCTime     time.Duration140		}141		var tasks []task142		for _, summary := range t.summary.Tasks {143			if !filter.match(t, summary) {144				continue145			}146 147			// Collect all the events for the task.148			var rawEvents []*trace.Event149			if summary.Start != nil {150				rawEvents = append(rawEvents, summary.Start)151			}152			if summary.End != nil {153				rawEvents = append(rawEvents, summary.End)154			}155			rawEvents = append(rawEvents, summary.Logs...)156			for _, r := range summary.Regions {157				if r.Start != nil {158					rawEvents = append(rawEvents, r.Start)159				}160				if r.End != nil {161					rawEvents = append(rawEvents, r.End)162				}163			}164 165			// Sort them.166			slices.SortStableFunc(rawEvents, func(a, b *trace.Event) int {167				return cmp.Compare(a.Time(), b.Time())168			})169 170			// Summarize them.171			var events []event172			last := t.startTime()173			for _, ev := range rawEvents {174				what := describeEvent(ev)175				if what == "" {176					continue177				}178				sinceStart := ev.Time().Sub(t.startTime())179				events = append(events, event{180					WhenString: fmt.Sprintf("%2.9f", sinceStart.Seconds()),181					Elapsed:    ev.Time().Sub(last),182					What:       what,183					Goroutine:  primaryGoroutine(ev),184				})185				last = ev.Time()186			}187			taskSpan := taskInterval(t, summary)188			taskStart := taskSpan.start.Sub(t.startTime())189 190			// Produce the task summary.191			tasks = append(tasks, task{192				WhenString: fmt.Sprintf("%2.9fs", taskStart.Seconds()),193				Duration:   taskSpan.duration(),194				ID:         summary.ID,195				Complete:   summary.Complete(),196				Events:     events,197				Start:      taskStart,198				End:        taskStart + taskSpan.duration(),199			})200		}201		// Sort the tasks by duration.202		slices.SortFunc(tasks, func(a, b task) int {203			return cmp.Compare(a.Duration, b.Duration)204		})205 206		// Emit table.207		err = templUserTaskType.Execute(w, struct {208			Name  string209			Tasks []task210		}{211			Name:  filter.name,212			Tasks: tasks,213		})214		if err != nil {215			log.Printf("failed to execute template: %v", err)216			http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError)217			return218		}219	}220}221 222var templUserTaskType = template.Must(template.New("userTask").Funcs(template.FuncMap{223	"elapsed":       elapsed,224	"asMillisecond": asMillisecond,225	"trimSpace":     strings.TrimSpace,226}).Parse(`227<!DOCTYPE html>228<title>Tasks: {{.Name}}</title>229<style>` + traceviewer.CommonStyle + `230body {231  font-family: sans-serif;232}233table#req-status td.family {234  padding-right: 2em;235}236table#req-status td.active {237  padding-right: 1em;238}239table#req-status td.empty {240  color: #aaa;241}242table#reqs {243  margin-top: 1em;244  border-collapse: collapse;245}246table#reqs tr.first {247  font-weight: bold;248}249table#reqs td {250  font-family: monospace;251}252table#reqs td.when {253  text-align: right;254  white-space: nowrap;255}256table#reqs td.elapsed {257  padding: 0 0.5em;258  text-align: right;259  white-space: pre;260  width: 10em;261}262address {263  font-size: smaller;264  margin-top: 5em;265}266</style>267<body>268 269<h2>User Task: {{.Name}}</h2>270 271Search log text: <form onsubmit="window.location.search+='&logtext='+window.logtextinput.value; return false">272<input name="logtext" id="logtextinput" type="text"><input type="submit">273</form><br>274 275<table id="reqs">276	<tr>277		<th>When</th>278		<th>Elapsed</th>279		<th>Goroutine</th>280		<th>Events</th>281	</tr>282	{{range $el := $.Tasks}}283	<tr class="first">284		<td class="when">{{$el.WhenString}}</td>285		<td class="elapsed">{{$el.Duration}}</td>286		<td></td>287		<td>288			<a href="/trace?focustask={{$el.ID}}#{{asMillisecond $el.Start}}:{{asMillisecond $el.End}}">Task {{$el.ID}}</a>289			<a href="/trace?taskid={{$el.ID}}#{{asMillisecond $el.Start}}:{{asMillisecond $el.End}}">(goroutine view)</a>290			({{if .Complete}}complete{{else}}incomplete{{end}})291		</td>292	</tr>293	{{range $el.Events}}294	<tr>295		<td class="when">{{.WhenString}}</td>296		<td class="elapsed">{{elapsed .Elapsed}}</td>297		<td class="goid">{{.Goroutine}}</td>298		<td>{{.What}}</td>299	</tr>300	{{end}}301    {{end}}302</body>303</html>304`))305 306// taskFilter represents a task filter specified by a user of cmd/trace.307type taskFilter struct {308	name string309	cond []func(*parsedTrace, *trace.UserTaskSummary) bool310}311 312// match returns true if a task, described by its ID and summary, matches313// the filter.314func (f *taskFilter) match(t *parsedTrace, task *trace.UserTaskSummary) bool {315	if t == nil {316		return false317	}318	for _, c := range f.cond {319		if !c(t, task) {320			return false321		}322	}323	return true324}325 326// newTaskFilter creates a new task filter from URL query variables.327func newTaskFilter(r *http.Request) (*taskFilter, error) {328	if err := r.ParseForm(); err != nil {329		return nil, err330	}331 332	var name []string333	var conditions []func(*parsedTrace, *trace.UserTaskSummary) bool334 335	param := r.Form336	if typ, ok := param["type"]; ok && len(typ) > 0 {337		name = append(name, fmt.Sprintf("%q", typ[0]))338		conditions = append(conditions, func(_ *parsedTrace, task *trace.UserTaskSummary) bool {339			return task.Name == typ[0]340		})341	}342	if complete := r.FormValue("complete"); complete == "1" {343		name = append(name, "complete")344		conditions = append(conditions, func(_ *parsedTrace, task *trace.UserTaskSummary) bool {345			return task.Complete()346		})347	} else if complete == "0" {348		name = append(name, "incomplete")349		conditions = append(conditions, func(_ *parsedTrace, task *trace.UserTaskSummary) bool {350			return !task.Complete()351		})352	}353	if lat, err := time.ParseDuration(r.FormValue("latmin")); err == nil {354		name = append(name, fmt.Sprintf("latency >= %s", lat))355		conditions = append(conditions, func(t *parsedTrace, task *trace.UserTaskSummary) bool {356			return task.Complete() && taskInterval(t, task).duration() >= lat357		})358	}359	if lat, err := time.ParseDuration(r.FormValue("latmax")); err == nil {360		name = append(name, fmt.Sprintf("latency <= %s", lat))361		conditions = append(conditions, func(t *parsedTrace, task *trace.UserTaskSummary) bool {362			return task.Complete() && taskInterval(t, task).duration() <= lat363		})364	}365	if text := r.FormValue("logtext"); text != "" {366		name = append(name, fmt.Sprintf("log contains %q", text))367		conditions = append(conditions, func(_ *parsedTrace, task *trace.UserTaskSummary) bool {368			return taskMatches(task, text)369		})370	}371 372	return &taskFilter{name: strings.Join(name, ","), cond: conditions}, nil373}374 375func taskInterval(t *parsedTrace, s *trace.UserTaskSummary) interval {376	var i interval377	if s.Start != nil {378		i.start = s.Start.Time()379	} else {380		i.start = t.startTime()381	}382	if s.End != nil {383		i.end = s.End.Time()384	} else {385		i.end = t.endTime()386	}387	return i388}389 390func taskMatches(t *trace.UserTaskSummary, text string) bool {391	matches := func(s string) bool {392		return strings.Contains(s, text)393	}394	if matches(t.Name) {395		return true396	}397	for _, r := range t.Regions {398		if matches(r.Name) {399			return true400		}401	}402	for _, ev := range t.Logs {403		log := ev.Log()404		if matches(log.Category) {405			return true406		}407		if matches(log.Message) {408			return true409		}410	}411	return false412}413 414func describeEvent(ev *trace.Event) string {415	switch ev.Kind() {416	case trace.EventStateTransition:417		st := ev.StateTransition()418		if st.Resource.Kind != trace.ResourceGoroutine {419			return ""420		}421		old, new := st.Goroutine()422		return fmt.Sprintf("%s -> %s", old, new)423	case trace.EventRegionBegin:424		return fmt.Sprintf("region %q begin", ev.Region().Type)425	case trace.EventRegionEnd:426		return fmt.Sprintf("region %q end", ev.Region().Type)427	case trace.EventTaskBegin:428		t := ev.Task()429		return fmt.Sprintf("task %q (D %d, parent %d) begin", t.Type, t.ID, t.Parent)430	case trace.EventTaskEnd:431		return "task end"432	case trace.EventLog:433		log := ev.Log()434		if log.Category != "" {435			return fmt.Sprintf("log %q", log.Message)436		}437		return fmt.Sprintf("log (category: %s): %q", log.Category, log.Message)438	}439	return ""440}441 442func primaryGoroutine(ev *trace.Event) trace.GoID {443	if ev.Kind() != trace.EventStateTransition {444		return ev.Goroutine()445	}446	st := ev.StateTransition()447	if st.Resource.Kind != trace.ResourceGoroutine {448		return trace.NoGoroutine449	}450	return st.Resource.Goroutine()451}452 453func elapsed(d time.Duration) string {454	b := fmt.Appendf(nil, "%.9f", d.Seconds())455 456	// For subsecond durations, blank all zeros before decimal point,457	// and all zeros between the decimal point and the first non-zero digit.458	if d < time.Second {459		dot := bytes.IndexByte(b, '.')460		for i := 0; i < dot; i++ {461			b[i] = ' '462		}463		for i := dot + 1; i < len(b); i++ {464			if b[i] == '0' {465				b[i] = ' '466			} else {467				break468			}469		}470	}471	return string(b)472}473 474func asMillisecond(d time.Duration) float64 {475	return float64(d.Nanoseconds()) / float64(time.Millisecond)476}477