Source file src/cmd/trace/mmu.go

Documentation: cmd/trace

     1  // Copyright 2017 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  // Minimum mutator utilization (MMU) graphing.
     6  
     7  // TODO:
     8  //
     9  // In worst window list, show break-down of GC utilization sources
    10  // (STW, assist, etc). Probably requires a different MutatorUtil
    11  // representation.
    12  //
    13  // When a window size is selected, show a second plot of the mutator
    14  // utilization distribution for that window size.
    15  //
    16  // Render plot progressively so rough outline is visible quickly even
    17  // for very complex MUTs. Start by computing just a few window sizes
    18  // and then add more window sizes.
    19  //
    20  // Consider using sampling to compute an approximate MUT. This would
    21  // work by sampling the mutator utilization at randomly selected
    22  // points in time in the trace to build an empirical distribution. We
    23  // could potentially put confidence intervals on these estimates and
    24  // render this progressively as we refine the distributions.
    25  
    26  package main
    27  
    28  import (
    29  	"encoding/json"
    30  	"fmt"
    31  	"internal/trace"
    32  	"log"
    33  	"math"
    34  	"net/http"
    35  	"strconv"
    36  	"strings"
    37  	"sync"
    38  	"time"
    39  )
    40  
    41  func init() {
    42  	http.HandleFunc("/mmu", httpMMU)
    43  	http.HandleFunc("/mmuPlot", httpMMUPlot)
    44  	http.HandleFunc("/mmuDetails", httpMMUDetails)
    45  }
    46  
    47  var utilFlagNames = map[string]trace.UtilFlags{
    48  	"perProc":    trace.UtilPerProc,
    49  	"stw":        trace.UtilSTW,
    50  	"background": trace.UtilBackground,
    51  	"assist":     trace.UtilAssist,
    52  	"sweep":      trace.UtilSweep,
    53  }
    54  
    55  type mmuCacheEntry struct {
    56  	init     sync.Once
    57  	util     [][]trace.MutatorUtil
    58  	mmuCurve *trace.MMUCurve
    59  	err      error
    60  }
    61  
    62  var mmuCache struct {
    63  	m    map[trace.UtilFlags]*mmuCacheEntry
    64  	lock sync.Mutex
    65  }
    66  
    67  func init() {
    68  	mmuCache.m = make(map[trace.UtilFlags]*mmuCacheEntry)
    69  }
    70  
    71  func getMMUCurve(r *http.Request) ([][]trace.MutatorUtil, *trace.MMUCurve, error) {
    72  	var flags trace.UtilFlags
    73  	for _, flagStr := range strings.Split(r.FormValue("flags"), "|") {
    74  		flags |= utilFlagNames[flagStr]
    75  	}
    76  
    77  	mmuCache.lock.Lock()
    78  	c := mmuCache.m[flags]
    79  	if c == nil {
    80  		c = new(mmuCacheEntry)
    81  		mmuCache.m[flags] = c
    82  	}
    83  	mmuCache.lock.Unlock()
    84  
    85  	c.init.Do(func() {
    86  		events, err := parseEvents()
    87  		if err != nil {
    88  			c.err = err
    89  		} else {
    90  			c.util = trace.MutatorUtilization(events, flags)
    91  			c.mmuCurve = trace.NewMMUCurve(c.util)
    92  		}
    93  	})
    94  	return c.util, c.mmuCurve, c.err
    95  }
    96  
    97  // httpMMU serves the MMU plot page.
    98  func httpMMU(w http.ResponseWriter, r *http.Request) {
    99  	http.ServeContent(w, r, "", time.Time{}, strings.NewReader(templMMU))
   100  }
   101  
   102  // httpMMUPlot serves the JSON data for the MMU plot.
   103  func httpMMUPlot(w http.ResponseWriter, r *http.Request) {
   104  	mu, mmuCurve, err := getMMUCurve(r)
   105  	if err != nil {
   106  		http.Error(w, fmt.Sprintf("failed to parse events: %v", err), http.StatusInternalServerError)
   107  		return
   108  	}
   109  
   110  	var quantiles []float64
   111  	for _, flagStr := range strings.Split(r.FormValue("flags"), "|") {
   112  		if flagStr == "mut" {
   113  			quantiles = []float64{0, 1 - .999, 1 - .99, 1 - .95}
   114  			break
   115  		}
   116  	}
   117  
   118  	// Find a nice starting point for the plot.
   119  	xMin := time.Second
   120  	for xMin > 1 {
   121  		if mmu := mmuCurve.MMU(xMin); mmu < 0.0001 {
   122  			break
   123  		}
   124  		xMin /= 1000
   125  	}
   126  	// Cover six orders of magnitude.
   127  	xMax := xMin * 1e6
   128  	// But no more than the length of the trace.
   129  	minEvent, maxEvent := mu[0][0].Time, mu[0][len(mu[0])-1].Time
   130  	for _, mu1 := range mu[1:] {
   131  		if mu1[0].Time < minEvent {
   132  			minEvent = mu1[0].Time
   133  		}
   134  		if mu1[len(mu1)-1].Time > maxEvent {
   135  			maxEvent = mu1[len(mu1)-1].Time
   136  		}
   137  	}
   138  	if maxMax := time.Duration(maxEvent - minEvent); xMax > maxMax {
   139  		xMax = maxMax
   140  	}
   141  	// Compute MMU curve.
   142  	logMin, logMax := math.Log(float64(xMin)), math.Log(float64(xMax))
   143  	const samples = 100
   144  	plot := make([][]float64, samples)
   145  	for i := 0; i < samples; i++ {
   146  		window := time.Duration(math.Exp(float64(i)/(samples-1)*(logMax-logMin) + logMin))
   147  		if quantiles == nil {
   148  			plot[i] = make([]float64, 2)
   149  			plot[i][1] = mmuCurve.MMU(window)
   150  		} else {
   151  			plot[i] = make([]float64, 1+len(quantiles))
   152  			copy(plot[i][1:], mmuCurve.MUD(window, quantiles))
   153  		}
   154  		plot[i][0] = float64(window)
   155  	}
   156  
   157  	// Create JSON response.
   158  	err = json.NewEncoder(w).Encode(map[string]interface{}{"xMin": int64(xMin), "xMax": int64(xMax), "quantiles": quantiles, "curve": plot})
   159  	if err != nil {
   160  		log.Printf("failed to serialize response: %v", err)
   161  		return
   162  	}
   163  }
   164  
   165  var templMMU = `<!doctype html>
   166  <html>
   167    <head>
   168      <meta charset="utf-8">
   169      <script type="text/javascript" src="https://www.gstatic.com/charts/loader.js"></script>
   170      <script type="text/javascript" src="https://ajax.googleapis.com/ajax/libs/jquery/3.2.1/jquery.min.js"></script>
   171      <script type="text/javascript">
   172        google.charts.load('current', {'packages':['corechart']});
   173        var chartsReady = false;
   174        google.charts.setOnLoadCallback(function() { chartsReady = true; refreshChart(); });
   175  
   176        var chart;
   177        var curve;
   178  
   179        function niceDuration(ns) {
   180            if (ns < 1e3) { return ns + 'ns'; }
   181            else if (ns < 1e6) { return ns / 1e3 + '┬Ás'; }
   182            else if (ns < 1e9) { return ns / 1e6 + 'ms'; }
   183            else { return ns / 1e9 + 's'; }
   184        }
   185  
   186        function niceQuantile(q) {
   187          return 'p' + q*100;
   188        }
   189  
   190        function mmuFlags() {
   191          var flags = "";
   192          $("#options input").each(function(i, elt) {
   193            if (elt.checked)
   194              flags += "|" + elt.id;
   195          });
   196          return flags.substr(1);
   197        }
   198  
   199        function refreshChart() {
   200          if (!chartsReady) return;
   201          var container = $('#mmu_chart');
   202          container.css('opacity', '.5');
   203          refreshChart.count++;
   204          var seq = refreshChart.count;
   205          $.getJSON('/mmuPlot?flags=' + mmuFlags())
   206           .fail(function(xhr, status, error) {
   207             alert('failed to load plot: ' + status);
   208           })
   209           .done(function(result) {
   210             if (refreshChart.count === seq)
   211               drawChart(result);
   212           });
   213        }
   214        refreshChart.count = 0;
   215  
   216        function drawChart(plotData) {
   217          curve = plotData.curve;
   218          var data = new google.visualization.DataTable();
   219          data.addColumn('number', 'Window duration');
   220          data.addColumn('number', 'Minimum mutator utilization');
   221          if (plotData.quantiles) {
   222            for (var i = 1; i < plotData.quantiles.length; i++) {
   223              data.addColumn('number', niceQuantile(1 - plotData.quantiles[i]) + ' MU');
   224            }
   225          }
   226          data.addRows(curve);
   227          for (var i = 0; i < curve.length; i++) {
   228            data.setFormattedValue(i, 0, niceDuration(curve[i][0]));
   229          }
   230  
   231          var options = {
   232            chart: {
   233              title: 'Minimum mutator utilization',
   234            },
   235            hAxis: {
   236              title: 'Window duration',
   237              scaleType: 'log',
   238              ticks: [],
   239            },
   240            vAxis: {
   241              title: 'Minimum mutator utilization',
   242              minValue: 0.0,
   243              maxValue: 1.0,
   244            },
   245            legend: { position: 'none' },
   246            focusTarget: 'category',
   247            width: 900,
   248            height: 500,
   249            chartArea: { width: '80%', height: '80%' },
   250          };
   251          for (var v = plotData.xMin; v <= plotData.xMax; v *= 10) {
   252            options.hAxis.ticks.push({v:v, f:niceDuration(v)});
   253          }
   254          if (plotData.quantiles) {
   255            options.vAxis.title = 'Mutator utilization';
   256            options.legend.position = 'in';
   257          }
   258  
   259          var container = $('#mmu_chart');
   260          container.empty();
   261          container.css('opacity', '');
   262          chart = new google.visualization.LineChart(container[0]);
   263          chart = new google.visualization.LineChart(document.getElementById('mmu_chart'));
   264          chart.draw(data, options);
   265  
   266          google.visualization.events.addListener(chart, 'select', selectHandler);
   267          $('#details').empty();
   268        }
   269  
   270        function selectHandler() {
   271          var items = chart.getSelection();
   272          if (items.length === 0) {
   273            return;
   274          }
   275          var details = $('#details');
   276          details.empty();
   277          var windowNS = curve[items[0].row][0];
   278          var url = '/mmuDetails?window=' + windowNS + '&flags=' + mmuFlags();
   279          $.getJSON(url)
   280           .fail(function(xhr, status, error) {
   281              details.text(status + ': ' + url + ' could not be loaded');
   282           })
   283           .done(function(worst) {
   284              details.text('Lowest mutator utilization in ' + niceDuration(windowNS) + ' windows:');
   285              for (var i = 0; i < worst.length; i++) {
   286                details.append($('<br/>'));
   287                var text = worst[i].MutatorUtil.toFixed(3) + ' at time ' + niceDuration(worst[i].Time);
   288                details.append($('<a/>').text(text).attr('href', worst[i].URL));
   289              }
   290           });
   291        }
   292  
   293        $.when($.ready).then(function() {
   294          $("#options input").click(refreshChart);
   295        });
   296      </script>
   297      <style>
   298        .help {
   299          display: inline-block;
   300          position: relative;
   301          width: 1em;
   302          height: 1em;
   303          border-radius: 50%;
   304          color: #fff;
   305          background: #555;
   306          text-align: center;
   307          cursor: help;
   308        }
   309        .help > span {
   310          display: none;
   311        }
   312        .help:hover > span {
   313          display: block;
   314          position: absolute;
   315          left: 1.1em;
   316          top: 1.1em;
   317          background: #555;
   318          text-align: left;
   319          width: 20em;
   320          padding: 0.5em;
   321          border-radius: 0.5em;
   322          z-index: 5;
   323        }
   324      </style>
   325    </head>
   326    <body>
   327      <div style="position: relative">
   328        <div id="mmu_chart" style="width: 900px; height: 500px; display: inline-block; vertical-align: top">Loading plot...</div>
   329        <div id="options" style="display: inline-block; vertical-align: top">
   330          <p>
   331            <b>View</b><br/>
   332            <input type="radio" name="view" id="system" checked><label for="system">System</label>
   333            <span class="help">?<span>Consider whole system utilization. For example, if one of four procs is available to the mutator, mutator utilization will be 0.25. This is the standard definition of an MMU.</span></span><br/>
   334            <input type="radio" name="view" id="perProc"><label for="perProc">Per-goroutine</label>
   335            <span class="help">?<span>Consider per-goroutine utilization. When even one goroutine is interrupted by GC, mutator utilization is 0.</span></span><br/>
   336          </p>
   337          <p>
   338            <b>Include</b><br/>
   339            <input type="checkbox" id="stw" checked><label for="stw">STW</label>
   340            <span class="help">?<span>Stop-the-world stops all goroutines simultaneously.</span></span><br/>
   341            <input type="checkbox" id="background" checked><label for="background">Background workers</label>
   342            <span class="help">?<span>Background workers are GC-specific goroutines. 25% of the CPU is dedicated to background workers during GC.</span></span><br/>
   343            <input type="checkbox" id="assist" checked><label for="assist">Mark assist</label>
   344            <span class="help">?<span>Mark assists are performed by allocation to prevent the mutator from outpacing GC.</span></span><br/>
   345            <input type="checkbox" id="sweep"><label for="sweep">Sweep</label>
   346            <span class="help">?<span>Sweep reclaims unused memory between GCs. (Enabling this may be very slow.).</span></span><br/>
   347          </p>
   348          <p>
   349            <b>Display</b><br/>
   350            <input type="checkbox" id="mut"><label for="mut">Show percentiles</label>
   351            <span class="help">?<span>Display percentile mutator utilization in addition to minimum. E.g., p99 MU drops the worst 1% of windows.</span></span><br/>
   352          </p>
   353        </div>
   354      </div>
   355      <div id="details">Select a point for details.</div>
   356    </body>
   357  </html>
   358  `
   359  
   360  // httpMMUDetails serves details of an MMU graph at a particular window.
   361  func httpMMUDetails(w http.ResponseWriter, r *http.Request) {
   362  	_, mmuCurve, err := getMMUCurve(r)
   363  	if err != nil {
   364  		http.Error(w, fmt.Sprintf("failed to parse events: %v", err), http.StatusInternalServerError)
   365  		return
   366  	}
   367  
   368  	windowStr := r.FormValue("window")
   369  	window, err := strconv.ParseUint(windowStr, 10, 64)
   370  	if err != nil {
   371  		http.Error(w, fmt.Sprintf("failed to parse window parameter %q: %v", windowStr, err), http.StatusBadRequest)
   372  		return
   373  	}
   374  	worst := mmuCurve.Examples(time.Duration(window), 10)
   375  
   376  	// Construct a link for each window.
   377  	var links []linkedUtilWindow
   378  	for _, ui := range worst {
   379  		links = append(links, newLinkedUtilWindow(ui, time.Duration(window)))
   380  	}
   381  
   382  	err = json.NewEncoder(w).Encode(links)
   383  	if err != nil {
   384  		log.Printf("failed to serialize trace: %v", err)
   385  		return
   386  	}
   387  }
   388  
   389  type linkedUtilWindow struct {
   390  	trace.UtilWindow
   391  	URL string
   392  }
   393  
   394  func newLinkedUtilWindow(ui trace.UtilWindow, window time.Duration) linkedUtilWindow {
   395  	// Find the range containing this window.
   396  	var r Range
   397  	for _, r = range ranges {
   398  		if r.EndTime > ui.Time {
   399  			break
   400  		}
   401  	}
   402  	return linkedUtilWindow{ui, fmt.Sprintf("%s#%v:%v", r.URL(), float64(ui.Time)/1e6, float64(ui.Time+int64(window))/1e6)}
   403  }
   404  

View as plain text