goroutines.go

Documentation: cmd/trace/v2

     1  // Copyright 2023 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  // Goroutine-related profiles.
     6  
     7  package trace
     8  
     9  import (
    10  	"cmp"
    11  	"fmt"
    12  	"html/template"
    13  	"internal/trace"
    14  	"internal/trace/traceviewer"
    15  	tracev2 "internal/trace/v2"
    16  	"log"
    17  	"net/http"
    18  	"slices"
    19  	"sort"
    20  	"strings"
    21  	"time"
    22  )
    23  
    24  // GoroutinesHandlerFunc returns a HandlerFunc that serves list of goroutine groups.
    25  func GoroutinesHandlerFunc(summaries map[tracev2.GoID]*trace.GoroutineSummary) http.HandlerFunc {
    26  	return func(w http.ResponseWriter, r *http.Request) {
    27  		// goroutineGroup describes a group of goroutines grouped by name.
    28  		type goroutineGroup struct {
    29  			Name     string        // Start function.
    30  			N        int           // Total number of goroutines in this group.
    31  			ExecTime time.Duration // Total execution time of all goroutines in this group.
    32  		}
    33  		// Accumulate groups by Name.
    34  		groupsByName := make(map[string]goroutineGroup)
    35  		for _, summary := range summaries {
    36  			group := groupsByName[summary.Name]
    37  			group.Name = summary.Name
    38  			group.N++
    39  			group.ExecTime += summary.ExecTime
    40  			groupsByName[summary.Name] = group
    41  		}
    42  		var groups []goroutineGroup
    43  		for _, group := range groupsByName {
    44  			groups = append(groups, group)
    45  		}
    46  		slices.SortFunc(groups, func(a, b goroutineGroup) int {
    47  			return cmp.Compare(b.ExecTime, a.ExecTime)
    48  		})
    49  		w.Header().Set("Content-Type", "text/html;charset=utf-8")
    50  		if err := templGoroutines.Execute(w, groups); err != nil {
    51  			log.Printf("failed to execute template: %v", err)
    52  			return
    53  		}
    54  	}
    55  }
    56  
    57  var templGoroutines = template.Must(template.New("").Parse(`
    58  <html>
    59  <style>` + traceviewer.CommonStyle + `
    60  table {
    61    border-collapse: collapse;
    62  }
    63  td,
    64  th {
    65    border: 1px solid black;
    66    padding-left: 8px;
    67    padding-right: 8px;
    68    padding-top: 4px;
    69    padding-bottom: 4px;
    70  }
    71  </style>
    72  <body>
    73  <h1>Goroutines</h1>
    74  Below is a table of all goroutines in the trace grouped by start location and sorted by the total execution time of the group.<br>
    75  <br>
    76  Click a start location to view more details about that group.<br>
    77  <br>
    78  <table>
    79    <tr>
    80      <th>Start location</th>
    81  	<th>Count</th>
    82  	<th>Total execution time</th>
    83    </tr>
    84  {{range $}}
    85    <tr>
    86      <td><code><a href="/goroutine?name={{.Name}}">{{or .Name "(Inactive, no stack trace sampled)"}}</a></code></td>
    87  	<td>{{.N}}</td>
    88  	<td>{{.ExecTime}}</td>
    89    </tr>
    90  {{end}}
    91  </table>
    92  </body>
    93  </html>
    94  `))
    95  
    96  // GoroutineHandler creates a handler that serves information about
    97  // goroutines in a particular group.
    98  func GoroutineHandler(summaries map[tracev2.GoID]*trace.GoroutineSummary) http.HandlerFunc {
    99  	return func(w http.ResponseWriter, r *http.Request) {
   100  		goroutineName := r.FormValue("name")
   101  
   102  		type goroutine struct {
   103  			*trace.GoroutineSummary
   104  			NonOverlappingStats map[string]time.Duration
   105  			HasRangeTime        bool
   106  		}
   107  
   108  		// Collect all the goroutines in the group.
   109  		var (
   110  			goroutines              []goroutine
   111  			name                    string
   112  			totalExecTime, execTime time.Duration
   113  			maxTotalTime            time.Duration
   114  		)
   115  		validNonOverlappingStats := make(map[string]struct{})
   116  		validRangeStats := make(map[string]struct{})
   117  		for _, summary := range summaries {
   118  			totalExecTime += summary.ExecTime
   119  
   120  			if summary.Name != goroutineName {
   121  				continue
   122  			}
   123  			nonOverlappingStats := summary.NonOverlappingStats()
   124  			for name := range nonOverlappingStats {
   125  				validNonOverlappingStats[name] = struct{}{}
   126  			}
   127  			var totalRangeTime time.Duration
   128  			for name, dt := range summary.RangeTime {
   129  				validRangeStats[name] = struct{}{}
   130  				totalRangeTime += dt
   131  			}
   132  			goroutines = append(goroutines, goroutine{
   133  				GoroutineSummary:    summary,
   134  				NonOverlappingStats: nonOverlappingStats,
   135  				HasRangeTime:        totalRangeTime != 0,
   136  			})
   137  			name = summary.Name
   138  			execTime += summary.ExecTime
   139  			if maxTotalTime < summary.TotalTime {
   140  				maxTotalTime = summary.TotalTime
   141  			}
   142  		}
   143  
   144  		// Compute the percent of total execution time these goroutines represent.
   145  		execTimePercent := ""
   146  		if totalExecTime > 0 {
   147  			execTimePercent = fmt.Sprintf("%.2f%%", float64(execTime)/float64(totalExecTime)*100)
   148  		}
   149  
   150  		// Sort.
   151  		sortBy := r.FormValue("sortby")
   152  		if _, ok := validNonOverlappingStats[sortBy]; ok {
   153  			slices.SortFunc(goroutines, func(a, b goroutine) int {
   154  				return cmp.Compare(b.NonOverlappingStats[sortBy], a.NonOverlappingStats[sortBy])
   155  			})
   156  		} else {
   157  			// Sort by total time by default.
   158  			slices.SortFunc(goroutines, func(a, b goroutine) int {
   159  				return cmp.Compare(b.TotalTime, a.TotalTime)
   160  			})
   161  		}
   162  
   163  		// Write down all the non-overlapping stats and sort them.
   164  		allNonOverlappingStats := make([]string, 0, len(validNonOverlappingStats))
   165  		for name := range validNonOverlappingStats {
   166  			allNonOverlappingStats = append(allNonOverlappingStats, name)
   167  		}
   168  		slices.SortFunc(allNonOverlappingStats, func(a, b string) int {
   169  			if a == b {
   170  				return 0
   171  			}
   172  			if a == "Execution time" {
   173  				return -1
   174  			}
   175  			if b == "Execution time" {
   176  				return 1
   177  			}
   178  			return cmp.Compare(a, b)
   179  		})
   180  
   181  		// Write down all the range stats and sort them.
   182  		allRangeStats := make([]string, 0, len(validRangeStats))
   183  		for name := range validRangeStats {
   184  			allRangeStats = append(allRangeStats, name)
   185  		}
   186  		sort.Strings(allRangeStats)
   187  
   188  		err := templGoroutine.Execute(w, struct {
   189  			Name                string
   190  			N                   int
   191  			ExecTimePercent     string
   192  			MaxTotal            time.Duration
   193  			Goroutines          []goroutine
   194  			NonOverlappingStats []string
   195  			RangeStats          []string
   196  		}{
   197  			Name:                name,
   198  			N:                   len(goroutines),
   199  			ExecTimePercent:     execTimePercent,
   200  			MaxTotal:            maxTotalTime,
   201  			Goroutines:          goroutines,
   202  			NonOverlappingStats: allNonOverlappingStats,
   203  			RangeStats:          allRangeStats,
   204  		})
   205  		if err != nil {
   206  			http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError)
   207  			return
   208  		}
   209  	}
   210  }
   211  
   212  func stat2Color(statName string) string {
   213  	color := "#636363"
   214  	if strings.HasPrefix(statName, "Block time") {
   215  		color = "#d01c8b"
   216  	}
   217  	switch statName {
   218  	case "Sched wait time":
   219  		color = "#2c7bb6"
   220  	case "Syscall execution time":
   221  		color = "#7b3294"
   222  	case "Execution time":
   223  		color = "#d7191c"
   224  	}
   225  	return color
   226  }
   227  
   228  var templGoroutine = template.Must(template.New("").Funcs(template.FuncMap{
   229  	"percent": func(dividend, divisor time.Duration) template.HTML {
   230  		if divisor == 0 {
   231  			return ""
   232  		}
   233  		return template.HTML(fmt.Sprintf("(%.1f%%)", float64(dividend)/float64(divisor)*100))
   234  	},
   235  	"headerStyle": func(statName string) template.HTMLAttr {
   236  		return template.HTMLAttr(fmt.Sprintf("style=\"background-color: %s;\"", stat2Color(statName)))
   237  	},
   238  	"barStyle": func(statName string, dividend, divisor time.Duration) template.HTMLAttr {
   239  		width := "0"
   240  		if divisor != 0 {
   241  			width = fmt.Sprintf("%.2f%%", float64(dividend)/float64(divisor)*100)
   242  		}
   243  		return template.HTMLAttr(fmt.Sprintf("style=\"width: %s; background-color: %s;\"", width, stat2Color(statName)))
   244  	},
   245  }).Parse(`
   246  <!DOCTYPE html>
   247  <title>Goroutines: {{.Name}}</title>
   248  <style>` + traceviewer.CommonStyle + `
   249  th {
   250    background-color: #050505;
   251    color: #fff;
   252  }
   253  th.link {
   254    cursor: pointer;
   255  }
   256  table {
   257    border-collapse: collapse;
   258  }
   259  td,
   260  th {
   261    padding-left: 8px;
   262    padding-right: 8px;
   263    padding-top: 4px;
   264    padding-bottom: 4px;
   265  }
   266  .details tr:hover {
   267    background-color: #f2f2f2;
   268  }
   269  .details td {
   270    text-align: right;
   271    border: 1px solid black;
   272  }
   273  .details td.id {
   274    text-align: left;
   275  }
   276  .stacked-bar-graph {
   277    width: 300px;
   278    height: 10px;
   279    color: #414042;
   280    white-space: nowrap;
   281    font-size: 5px;
   282  }
   283  .stacked-bar-graph span {
   284    display: inline-block;
   285    width: 100%;
   286    height: 100%;
   287    box-sizing: border-box;
   288    float: left;
   289    padding: 0;
   290  }
   291  </style>
   292  
   293  <script>
   294  function reloadTable(key, value) {
   295    let params = new URLSearchParams(window.location.search);
   296    params.set(key, value);
   297    window.location.search = params.toString();
   298  }
   299  </script>
   300  
   301  <h1>Goroutines</h1>
   302  
   303  Table of contents
   304  <ul>
   305  	<li><a href="#summary">Summary</a></li>
   306  	<li><a href="#breakdown">Breakdown</a></li>
   307  	<li><a href="#ranges">Special ranges</a></li>
   308  </ul>
   309  
   310  <h3 id="summary">Summary</h3>
   311  
   312  <table class="summary">
   313  	<tr>
   314  		<td>Goroutine start location:</td>
   315  		<td><code>{{.Name}}</code></td>
   316  	</tr>
   317  	<tr>
   318  		<td>Count:</td>
   319  		<td>{{.N}}</td>
   320  	</tr>
   321  	<tr>
   322  		<td>Execution Time:</td>
   323  		<td>{{.ExecTimePercent}} of total program execution time </td>
   324  	</tr>
   325  	<tr>
   326  		<td>Network wait profile:</td>
   327  		<td> <a href="/io?name={{.Name}}">graph</a> <a href="/io?name={{.Name}}&raw=1" download="io.profile">(download)</a></td>
   328  	</tr>
   329  	<tr>
   330  		<td>Sync block profile:</td>
   331  		<td> <a href="/block?name={{.Name}}">graph</a> <a href="/block?name={{.Name}}&raw=1" download="block.profile">(download)</a></td>
   332  	</tr>
   333  	<tr>
   334  		<td>Syscall profile:</td>
   335  		<td> <a href="/syscall?name={{.Name}}">graph</a> <a href="/syscall?name={{.Name}}&raw=1" download="syscall.profile">(download)</a></td>
   336  		</tr>
   337  	<tr>
   338  		<td>Scheduler wait profile:</td>
   339  		<td> <a href="/sched?name={{.Name}}">graph</a> <a href="/sched?name={{.Name}}&raw=1" download="sched.profile">(download)</a></td>
   340  	</tr>
   341  </table>
   342  
   343  <h3 id="breakdown">Breakdown</h3>
   344  
   345  The table below breaks down where each goroutine is spent its time during the
   346  traced period.
   347  All of the columns except total time are non-overlapping.
   348  <br>
   349  <br>
   350  
   351  <table class="details">
   352  <tr>
   353  <th> Goroutine</th>
   354  <th class="link" onclick="reloadTable('sortby', 'Total time')"> Total</th>
   355  <th></th>
   356  {{range $.NonOverlappingStats}}
   357  <th class="link" onclick="reloadTable('sortby', '{{.}}')" {{headerStyle .}}> {{.}}</th>
   358  {{end}}
   359  </tr>
   360  {{range .Goroutines}}
   361  	<tr>
   362  		<td> <a href="/trace?goid={{.ID}}">{{.ID}}</a> </td>
   363  		<td> {{ .TotalTime.String }} </td>
   364  		<td>
   365  			<div class="stacked-bar-graph">
   366  			{{$Goroutine := .}}
   367  			{{range $.NonOverlappingStats}}
   368  				{{$Time := index $Goroutine.NonOverlappingStats .}}
   369  				{{if $Time}}
   370  					<span {{barStyle . $Time $.MaxTotal}}>&nbsp;</span>
   371  				{{end}}
   372  			{{end}}
   373  			</div>
   374  		</td>
   375  		{{$Goroutine := .}}
   376  		{{range $.NonOverlappingStats}}
   377  			{{$Time := index $Goroutine.NonOverlappingStats .}}
   378  			<td> {{$Time.String}}</td>
   379  		{{end}}
   380  	</tr>
   381  {{end}}
   382  </table>
   383  
   384  <h3 id="ranges">Special ranges</h3>
   385  
   386  The table below describes how much of the traced period each goroutine spent in
   387  certain special time ranges.
   388  If a goroutine has spent no time in any special time ranges, it is excluded from
   389  the table.
   390  For example, how much time it spent helping the GC. Note that these times do
   391  overlap with the times from the first table.
   392  In general the goroutine may not be executing in these special time ranges.
   393  For example, it may have blocked while trying to help the GC.
   394  This must be taken into account when interpreting the data.
   395  <br>
   396  <br>
   397  
   398  <table class="details">
   399  <tr>
   400  <th> Goroutine</th>
   401  <th> Total</th>
   402  {{range $.RangeStats}}
   403  <th {{headerStyle .}}> {{.}}</th>
   404  {{end}}
   405  </tr>
   406  {{range .Goroutines}}
   407  	{{if .HasRangeTime}}
   408  		<tr>
   409  			<td> <a href="/trace?goid={{.ID}}">{{.ID}}</a> </td>
   410  			<td> {{ .TotalTime.String }} </td>
   411  			{{$Goroutine := .}}
   412  			{{range $.RangeStats}}
   413  				{{$Time := index $Goroutine.RangeTime .}}
   414  				<td> {{$Time.String}}</td>
   415  			{{end}}
   416  		</tr>
   417  	{{end}}
   418  {{end}}
   419  </table>
   420  `))
   421
View as plain text