goroutines.go

Documentation: cmd/trace

     1  // Copyright 2014 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 main
     8  
     9  import (
    10  	"fmt"
    11  	"html/template"
    12  	"internal/trace"
    13  	"log"
    14  	"net/http"
    15  	"reflect"
    16  	"sort"
    17  	"strconv"
    18  	"sync"
    19  	"time"
    20  )
    21  
    22  func init() {
    23  	http.HandleFunc("/goroutines", httpGoroutines)
    24  	http.HandleFunc("/goroutine", httpGoroutine)
    25  }
    26  
    27  // gtype describes a group of goroutines grouped by start PC.
    28  type gtype struct {
    29  	ID       uint64 // Unique identifier (PC).
    30  	Name     string // Start function.
    31  	N        int    // Total number of goroutines in this group.
    32  	ExecTime int64  // Total execution time of all goroutines in this group.
    33  }
    34  
    35  var (
    36  	gsInit sync.Once
    37  	gs     map[uint64]*trace.GDesc
    38  )
    39  
    40  // analyzeGoroutines generates statistics about execution of all goroutines and stores them in gs.
    41  func analyzeGoroutines(events []*trace.Event) {
    42  	gsInit.Do(func() {
    43  		gs = trace.GoroutineStats(events)
    44  	})
    45  }
    46  
    47  // httpGoroutines serves list of goroutine groups.
    48  func httpGoroutines(w http.ResponseWriter, r *http.Request) {
    49  	events, err := parseEvents()
    50  	if err != nil {
    51  		http.Error(w, err.Error(), http.StatusInternalServerError)
    52  		return
    53  	}
    54  	analyzeGoroutines(events)
    55  	gss := make(map[uint64]gtype)
    56  	for _, g := range gs {
    57  		gs1 := gss[g.PC]
    58  		gs1.ID = g.PC
    59  		gs1.Name = g.Name
    60  		gs1.N++
    61  		gs1.ExecTime += g.ExecTime
    62  		gss[g.PC] = gs1
    63  	}
    64  	var glist []gtype
    65  	for k, v := range gss {
    66  		v.ID = k
    67  		// If goroutine didn't run during the trace (no sampled PC),
    68  		// the v.ID and v.Name will be zero value.
    69  		if v.ID == 0 && v.Name == "" {
    70  			v.Name = "(Inactive, no stack trace sampled)"
    71  		}
    72  		glist = append(glist, v)
    73  	}
    74  	sort.Slice(glist, func(i, j int) bool { return glist[i].ExecTime > glist[j].ExecTime })
    75  	w.Header().Set("Content-Type", "text/html;charset=utf-8")
    76  	if err := templGoroutines.Execute(w, glist); err != nil {
    77  		log.Printf("failed to execute template: %v", err)
    78  		return
    79  	}
    80  }
    81  
    82  var templGoroutines = template.Must(template.New("").Parse(`
    83  <html>
    84  <body>
    85  Goroutines: <br>
    86  {{range $}}
    87    <a href="/goroutine?id={{.ID}}">{{.Name}}</a> N={{.N}} <br>
    88  {{end}}
    89  </body>
    90  </html>
    91  `))
    92  
    93  // httpGoroutine serves list of goroutines in a particular group.
    94  func httpGoroutine(w http.ResponseWriter, r *http.Request) {
    95  	// TODO(hyangah): support format=csv (raw data)
    96  
    97  	events, err := parseEvents()
    98  	if err != nil {
    99  		http.Error(w, err.Error(), http.StatusInternalServerError)
   100  		return
   101  	}
   102  
   103  	pc, err := strconv.ParseUint(r.FormValue("id"), 10, 64)
   104  	if err != nil {
   105  		http.Error(w, fmt.Sprintf("failed to parse id parameter '%v': %v", r.FormValue("id"), err), http.StatusInternalServerError)
   106  		return
   107  	}
   108  	analyzeGoroutines(events)
   109  	var (
   110  		glist                   []*trace.GDesc
   111  		name                    string
   112  		totalExecTime, execTime int64
   113  		maxTotalTime            int64
   114  	)
   115  
   116  	for _, g := range gs {
   117  		totalExecTime += g.ExecTime
   118  
   119  		if g.PC != pc {
   120  			continue
   121  		}
   122  		glist = append(glist, g)
   123  		name = g.Name
   124  		execTime += g.ExecTime
   125  		if maxTotalTime < g.TotalTime {
   126  			maxTotalTime = g.TotalTime
   127  		}
   128  	}
   129  
   130  	execTimePercent := ""
   131  	if totalExecTime > 0 {
   132  		execTimePercent = fmt.Sprintf("%.2f%%", float64(execTime)/float64(totalExecTime)*100)
   133  	}
   134  
   135  	sortby := r.FormValue("sortby")
   136  	_, ok := reflect.TypeOf(trace.GDesc{}).FieldByNameFunc(func(s string) bool {
   137  		return s == sortby
   138  	})
   139  	if !ok {
   140  		sortby = "TotalTime"
   141  	}
   142  
   143  	sort.Slice(glist, func(i, j int) bool {
   144  		ival := reflect.ValueOf(glist[i]).Elem().FieldByName(sortby).Int()
   145  		jval := reflect.ValueOf(glist[j]).Elem().FieldByName(sortby).Int()
   146  		return ival > jval
   147  	})
   148  
   149  	err = templGoroutine.Execute(w, struct {
   150  		Name            string
   151  		PC              uint64
   152  		N               int
   153  		ExecTimePercent string
   154  		MaxTotal        int64
   155  		GList           []*trace.GDesc
   156  	}{
   157  		Name:            name,
   158  		PC:              pc,
   159  		N:               len(glist),
   160  		ExecTimePercent: execTimePercent,
   161  		MaxTotal:        maxTotalTime,
   162  		GList:           glist})
   163  	if err != nil {
   164  		http.Error(w, fmt.Sprintf("failed to execute template: %v", err), http.StatusInternalServerError)
   165  		return
   166  	}
   167  }
   168  
   169  var templGoroutine = template.Must(template.New("").Funcs(template.FuncMap{
   170  	"prettyDuration": func(nsec int64) template.HTML {
   171  		d := time.Duration(nsec) * time.Nanosecond
   172  		return template.HTML(d.String())
   173  	},
   174  	"percent": func(dividend, divisor int64) template.HTML {
   175  		if divisor == 0 {
   176  			return ""
   177  		}
   178  		return template.HTML(fmt.Sprintf("(%.1f%%)", float64(dividend)/float64(divisor)*100))
   179  	},
   180  	"barLen": func(dividend, divisor int64) template.HTML {
   181  		if divisor == 0 {
   182  			return "0"
   183  		}
   184  		return template.HTML(fmt.Sprintf("%.2f%%", float64(dividend)/float64(divisor)*100))
   185  	},
   186  	"unknownTime": func(desc *trace.GDesc) int64 {
   187  		sum := desc.ExecTime + desc.IOTime + desc.BlockTime + desc.SyscallTime + desc.SchedWaitTime
   188  		if sum < desc.TotalTime {
   189  			return desc.TotalTime - sum
   190  		}
   191  		return 0
   192  	},
   193  }).Parse(`
   194  <!DOCTYPE html>
   195  <title>Goroutine {{.Name}}</title>
   196  <style>
   197  th {
   198    background-color: #050505;
   199    color: #fff;
   200  }
   201  th.total-time,
   202  th.exec-time,
   203  th.io-time,
   204  th.block-time,
   205  th.syscall-time,
   206  th.sched-time,
   207  th.sweep-time,
   208  th.pause-time {
   209    cursor: pointer;
   210  }
   211  table {
   212    border-collapse: collapse;
   213  }
   214  .details tr:hover {
   215    background-color: #f2f2f2;
   216  }
   217  .details td {
   218    text-align: right;
   219    border: 1px solid black;
   220  }
   221  .details td.id {
   222    text-align: left;
   223  }
   224  .stacked-bar-graph {
   225    width: 300px;
   226    height: 10px;
   227    color: #414042;
   228    white-space: nowrap;
   229    font-size: 5px;
   230  }
   231  .stacked-bar-graph span {
   232    display: inline-block;
   233    width: 100%;
   234    height: 100%;
   235    box-sizing: border-box;
   236    float: left;
   237    padding: 0;
   238  }
   239  .unknown-time { background-color: #636363; }
   240  .exec-time { background-color: #d7191c; }
   241  .io-time { background-color: #fdae61; }
   242  .block-time { background-color: #d01c8b; }
   243  .syscall-time { background-color: #7b3294; }
   244  .sched-time { background-color: #2c7bb6; }
   245  </style>
   246  
   247  <script>
   248  function reloadTable(key, value) {
   249    let params = new URLSearchParams(window.location.search);
   250    params.set(key, value);
   251    window.location.search = params.toString();
   252  }
   253  </script>
   254  
   255  <table class="summary">
   256  	<tr><td>Goroutine Name:</td><td>{{.Name}}</td></tr>
   257  	<tr><td>Number of Goroutines:</td><td>{{.N}}</td></tr>
   258  	<tr><td>Execution Time:</td><td>{{.ExecTimePercent}} of total program execution time </td> </tr>
   259  	<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>
   260  	<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>
   261  	<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>
   262  	<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>
   263  </table>
   264  <p>
   265  <table class="details">
   266  <tr>
   267  <th> Goroutine</th>
   268  <th onclick="reloadTable('sortby', 'TotalTime')" class="total-time"> Total</th>
   269  <th></th>
   270  <th onclick="reloadTable('sortby', 'ExecTime')" class="exec-time"> Execution</th>
   271  <th onclick="reloadTable('sortby', 'IOTime')" class="io-time"> Network wait</th>
   272  <th onclick="reloadTable('sortby', 'BlockTime')" class="block-time"> Sync block </th>
   273  <th onclick="reloadTable('sortby', 'SyscallTime')" class="syscall-time"> Blocking syscall</th>
   274  <th onclick="reloadTable('sortby', 'SchedWaitTime')" class="sched-time"> Scheduler wait</th>
   275  <th onclick="reloadTable('sortby', 'SweepTime')" class="sweep-time"> GC sweeping</th>
   276  <th onclick="reloadTable('sortby', 'GCTime')" class="pause-time"> GC pause</th>
   277  </tr>
   278  {{range .GList}}
   279    <tr>
   280      <td> <a href="/trace?goid={{.ID}}">{{.ID}}</a> </td>
   281      <td> {{prettyDuration .TotalTime}} </td>
   282      <td>
   283  	<div class="stacked-bar-graph">
   284  	  {{if unknownTime .}}<span style="width:{{barLen (unknownTime .) $.MaxTotal}}" class="unknown-time">&nbsp;</span>{{end}}
   285            {{if .ExecTime}}<span style="width:{{barLen .ExecTime $.MaxTotal}}" class="exec-time">&nbsp;</span>{{end}}
   286            {{if .IOTime}}<span style="width:{{barLen .IOTime $.MaxTotal}}" class="io-time">&nbsp;</span>{{end}}
   287            {{if .BlockTime}}<span style="width:{{barLen .BlockTime $.MaxTotal}}" class="block-time">&nbsp;</span>{{end}}
   288            {{if .SyscallTime}}<span style="width:{{barLen .SyscallTime $.MaxTotal}}" class="syscall-time">&nbsp;</span>{{end}}
   289            {{if .SchedWaitTime}}<span style="width:{{barLen .SchedWaitTime $.MaxTotal}}" class="sched-time">&nbsp;</span>{{end}}
   290          </div>
   291      </td>
   292      <td> {{prettyDuration .ExecTime}}</td>
   293      <td> {{prettyDuration .IOTime}}</td>
   294      <td> {{prettyDuration .BlockTime}}</td>
   295      <td> {{prettyDuration .SyscallTime}}</td>
   296      <td> {{prettyDuration .SchedWaitTime}}</td>
   297      <td> {{prettyDuration .SweepTime}} {{percent .SweepTime .TotalTime}}</td>
   298      <td> {{prettyDuration .GCTime}} {{percent .GCTime .TotalTime}}</td>
   299    </tr>
   300  {{end}}
   301  </table>
   302  `))
   303
View as plain text