github.com/hxx258456/ccgo@v0.0.5-0.20230213014102-48b35f46f66f/net/trace/events.go (about)

     1  // Copyright 2015 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  package trace
     6  
     7  import (
     8  	"bytes"
     9  	"fmt"
    10  	"html/template"
    11  	"io"
    12  	"log"
    13  	"runtime"
    14  	"sort"
    15  	"strconv"
    16  	"strings"
    17  	"sync"
    18  	"sync/atomic"
    19  	"text/tabwriter"
    20  	"time"
    21  
    22  	http "github.com/hxx258456/ccgo/gmhttp"
    23  )
    24  
    25  const maxEventsPerLog = 100
    26  
    27  type bucket struct {
    28  	MaxErrAge time.Duration
    29  	String    string
    30  }
    31  
    32  var buckets = []bucket{
    33  	{0, "total"},
    34  	{10 * time.Second, "errs<10s"},
    35  	{1 * time.Minute, "errs<1m"},
    36  	{10 * time.Minute, "errs<10m"},
    37  	{1 * time.Hour, "errs<1h"},
    38  	{10 * time.Hour, "errs<10h"},
    39  	{24000 * time.Hour, "errors"},
    40  }
    41  
    42  // RenderEvents renders the HTML page typically served at /debug/events.
    43  // It does not do any auth checking. The request may be nil.
    44  //
    45  // Most users will use the Events handler.
    46  func RenderEvents(w http.ResponseWriter, req *http.Request, sensitive bool) {
    47  	now := time.Now()
    48  	data := &struct {
    49  		Families []string // family names
    50  		Buckets  []bucket
    51  		Counts   [][]int // eventLog count per family/bucket
    52  
    53  		// Set when a bucket has been selected.
    54  		Family    string
    55  		Bucket    int
    56  		EventLogs eventLogs
    57  		Expanded  bool
    58  	}{
    59  		Buckets: buckets,
    60  	}
    61  
    62  	data.Families = make([]string, 0, len(families))
    63  	famMu.RLock()
    64  	for name := range families {
    65  		data.Families = append(data.Families, name)
    66  	}
    67  	famMu.RUnlock()
    68  	sort.Strings(data.Families)
    69  
    70  	// Count the number of eventLogs in each family for each error age.
    71  	data.Counts = make([][]int, len(data.Families))
    72  	for i, name := range data.Families {
    73  		// TODO(sameer): move this loop under the family lock.
    74  		f := getEventFamily(name)
    75  		data.Counts[i] = make([]int, len(data.Buckets))
    76  		for j, b := range data.Buckets {
    77  			data.Counts[i][j] = f.Count(now, b.MaxErrAge)
    78  		}
    79  	}
    80  
    81  	if req != nil {
    82  		var ok bool
    83  		data.Family, data.Bucket, ok = parseEventsArgs(req)
    84  		if !ok {
    85  			// No-op
    86  		} else {
    87  			data.EventLogs = getEventFamily(data.Family).Copy(now, buckets[data.Bucket].MaxErrAge)
    88  		}
    89  		if data.EventLogs != nil {
    90  			defer data.EventLogs.Free()
    91  			sort.Sort(data.EventLogs)
    92  		}
    93  		if exp, err := strconv.ParseBool(req.FormValue("exp")); err == nil {
    94  			data.Expanded = exp
    95  		}
    96  	}
    97  
    98  	famMu.RLock()
    99  	defer famMu.RUnlock()
   100  	if err := eventsTmpl().Execute(w, data); err != nil {
   101  		log.Printf("net/trace: Failed executing template: %v", err)
   102  	}
   103  }
   104  
   105  func parseEventsArgs(req *http.Request) (fam string, b int, ok bool) {
   106  	fam, bStr := req.FormValue("fam"), req.FormValue("b")
   107  	if fam == "" || bStr == "" {
   108  		return "", 0, false
   109  	}
   110  	b, err := strconv.Atoi(bStr)
   111  	if err != nil || b < 0 || b >= len(buckets) {
   112  		return "", 0, false
   113  	}
   114  	return fam, b, true
   115  }
   116  
   117  // An EventLog provides a log of events associated with a specific object.
   118  type EventLog interface {
   119  	// Printf formats its arguments with fmt.Sprintf and adds the
   120  	// result to the event log.
   121  	Printf(format string, a ...interface{})
   122  
   123  	// Errorf is like Printf, but it marks this event as an error.
   124  	Errorf(format string, a ...interface{})
   125  
   126  	// Finish declares that this event log is complete.
   127  	// The event log should not be used after calling this method.
   128  	Finish()
   129  }
   130  
   131  // NewEventLog returns a new EventLog with the specified family name
   132  // and title.
   133  func NewEventLog(family, title string) EventLog {
   134  	el := newEventLog()
   135  	el.ref()
   136  	el.Family, el.Title = family, title
   137  	el.Start = time.Now()
   138  	el.events = make([]logEntry, 0, maxEventsPerLog)
   139  	el.stack = make([]uintptr, 32)
   140  	n := runtime.Callers(2, el.stack)
   141  	el.stack = el.stack[:n]
   142  
   143  	getEventFamily(family).add(el)
   144  	return el
   145  }
   146  
   147  func (el *eventLog) Finish() {
   148  	getEventFamily(el.Family).remove(el)
   149  	el.unref() // matches ref in New
   150  }
   151  
   152  var (
   153  	famMu    sync.RWMutex
   154  	families = make(map[string]*eventFamily) // family name => family
   155  )
   156  
   157  func getEventFamily(fam string) *eventFamily {
   158  	famMu.Lock()
   159  	defer famMu.Unlock()
   160  	f := families[fam]
   161  	if f == nil {
   162  		f = &eventFamily{}
   163  		families[fam] = f
   164  	}
   165  	return f
   166  }
   167  
   168  type eventFamily struct {
   169  	mu        sync.RWMutex
   170  	eventLogs eventLogs
   171  }
   172  
   173  func (f *eventFamily) add(el *eventLog) {
   174  	f.mu.Lock()
   175  	f.eventLogs = append(f.eventLogs, el)
   176  	f.mu.Unlock()
   177  }
   178  
   179  func (f *eventFamily) remove(el *eventLog) {
   180  	f.mu.Lock()
   181  	defer f.mu.Unlock()
   182  	for i, el0 := range f.eventLogs {
   183  		if el == el0 {
   184  			copy(f.eventLogs[i:], f.eventLogs[i+1:])
   185  			f.eventLogs = f.eventLogs[:len(f.eventLogs)-1]
   186  			return
   187  		}
   188  	}
   189  }
   190  
   191  func (f *eventFamily) Count(now time.Time, maxErrAge time.Duration) (n int) {
   192  	f.mu.RLock()
   193  	defer f.mu.RUnlock()
   194  	for _, el := range f.eventLogs {
   195  		if el.hasRecentError(now, maxErrAge) {
   196  			n++
   197  		}
   198  	}
   199  	return
   200  }
   201  
   202  func (f *eventFamily) Copy(now time.Time, maxErrAge time.Duration) (els eventLogs) {
   203  	f.mu.RLock()
   204  	defer f.mu.RUnlock()
   205  	els = make(eventLogs, 0, len(f.eventLogs))
   206  	for _, el := range f.eventLogs {
   207  		if el.hasRecentError(now, maxErrAge) {
   208  			el.ref()
   209  			els = append(els, el)
   210  		}
   211  	}
   212  	return
   213  }
   214  
   215  type eventLogs []*eventLog
   216  
   217  // Free calls unref on each element of the list.
   218  func (els eventLogs) Free() {
   219  	for _, el := range els {
   220  		el.unref()
   221  	}
   222  }
   223  
   224  // eventLogs may be sorted in reverse chronological order.
   225  func (els eventLogs) Len() int           { return len(els) }
   226  func (els eventLogs) Less(i, j int) bool { return els[i].Start.After(els[j].Start) }
   227  func (els eventLogs) Swap(i, j int)      { els[i], els[j] = els[j], els[i] }
   228  
   229  // A logEntry is a timestamped log entry in an event log.
   230  type logEntry struct {
   231  	When    time.Time
   232  	Elapsed time.Duration // since previous event in log
   233  	NewDay  bool          // whether this event is on a different day to the previous event
   234  	What    string
   235  	IsErr   bool
   236  }
   237  
   238  // WhenString returns a string representation of the elapsed time of the event.
   239  // It will include the date if midnight was crossed.
   240  func (e logEntry) WhenString() string {
   241  	if e.NewDay {
   242  		return e.When.Format("2006/01/02 15:04:05.000000")
   243  	}
   244  	return e.When.Format("15:04:05.000000")
   245  }
   246  
   247  // An eventLog represents an active event log.
   248  type eventLog struct {
   249  	// Family is the top-level grouping of event logs to which this belongs.
   250  	Family string
   251  
   252  	// Title is the title of this event log.
   253  	Title string
   254  
   255  	// Timing information.
   256  	Start time.Time
   257  
   258  	// Call stack where this event log was created.
   259  	stack []uintptr
   260  
   261  	// Append-only sequence of events.
   262  	//
   263  	// TODO(sameer): change this to a ring buffer to avoid the array copy
   264  	// when we hit maxEventsPerLog.
   265  	mu            sync.RWMutex
   266  	events        []logEntry
   267  	LastErrorTime time.Time
   268  	discarded     int
   269  
   270  	refs int32 // how many buckets this is in
   271  }
   272  
   273  func (el *eventLog) reset() {
   274  	// Clear all but the mutex. Mutexes may not be copied, even when unlocked.
   275  	el.Family = ""
   276  	el.Title = ""
   277  	el.Start = time.Time{}
   278  	el.stack = nil
   279  	el.events = nil
   280  	el.LastErrorTime = time.Time{}
   281  	el.discarded = 0
   282  	el.refs = 0
   283  }
   284  
   285  func (el *eventLog) hasRecentError(now time.Time, maxErrAge time.Duration) bool {
   286  	if maxErrAge == 0 {
   287  		return true
   288  	}
   289  	el.mu.RLock()
   290  	defer el.mu.RUnlock()
   291  	return now.Sub(el.LastErrorTime) < maxErrAge
   292  }
   293  
   294  // delta returns the elapsed time since the last event or the log start,
   295  // and whether it spans midnight.
   296  // L >= el.mu
   297  func (el *eventLog) delta(t time.Time) (time.Duration, bool) {
   298  	if len(el.events) == 0 {
   299  		return t.Sub(el.Start), false
   300  	}
   301  	prev := el.events[len(el.events)-1].When
   302  	return t.Sub(prev), prev.Day() != t.Day()
   303  
   304  }
   305  
   306  func (el *eventLog) Printf(format string, a ...interface{}) {
   307  	el.printf(false, format, a...)
   308  }
   309  
   310  func (el *eventLog) Errorf(format string, a ...interface{}) {
   311  	el.printf(true, format, a...)
   312  }
   313  
   314  func (el *eventLog) printf(isErr bool, format string, a ...interface{}) {
   315  	e := logEntry{When: time.Now(), IsErr: isErr, What: fmt.Sprintf(format, a...)}
   316  	el.mu.Lock()
   317  	e.Elapsed, e.NewDay = el.delta(e.When)
   318  	if len(el.events) < maxEventsPerLog {
   319  		el.events = append(el.events, e)
   320  	} else {
   321  		// Discard the oldest event.
   322  		if el.discarded == 0 {
   323  			// el.discarded starts at two to count for the event it
   324  			// is replacing, plus the next one that we are about to
   325  			// drop.
   326  			el.discarded = 2
   327  		} else {
   328  			el.discarded++
   329  		}
   330  		// TODO(sameer): if this causes allocations on a critical path,
   331  		// change eventLog.What to be a fmt.Stringer, as in trace.go.
   332  		el.events[0].What = fmt.Sprintf("(%d events discarded)", el.discarded)
   333  		// The timestamp of the discarded meta-event should be
   334  		// the time of the last event it is representing.
   335  		el.events[0].When = el.events[1].When
   336  		copy(el.events[1:], el.events[2:])
   337  		el.events[maxEventsPerLog-1] = e
   338  	}
   339  	if e.IsErr {
   340  		el.LastErrorTime = e.When
   341  	}
   342  	el.mu.Unlock()
   343  }
   344  
   345  func (el *eventLog) ref() {
   346  	atomic.AddInt32(&el.refs, 1)
   347  }
   348  
   349  func (el *eventLog) unref() {
   350  	if atomic.AddInt32(&el.refs, -1) == 0 {
   351  		freeEventLog(el)
   352  	}
   353  }
   354  
   355  func (el *eventLog) When() string {
   356  	return el.Start.Format("2006/01/02 15:04:05.000000")
   357  }
   358  
   359  func (el *eventLog) ElapsedTime() string {
   360  	elapsed := time.Since(el.Start)
   361  	return fmt.Sprintf("%.6f", elapsed.Seconds())
   362  }
   363  
   364  func (el *eventLog) Stack() string {
   365  	buf := new(bytes.Buffer)
   366  	tw := tabwriter.NewWriter(buf, 1, 8, 1, '\t', 0)
   367  	printStackRecord(tw, el.stack)
   368  	tw.Flush()
   369  	return buf.String()
   370  }
   371  
   372  // printStackRecord prints the function + source line information
   373  // for a single stack trace.
   374  // Adapted from runtime/pprof/pprof.go.
   375  func printStackRecord(w io.Writer, stk []uintptr) {
   376  	for _, pc := range stk {
   377  		f := runtime.FuncForPC(pc)
   378  		if f == nil {
   379  			continue
   380  		}
   381  		file, line := f.FileLine(pc)
   382  		name := f.Name()
   383  		// Hide runtime.goexit and any runtime functions at the beginning.
   384  		if strings.HasPrefix(name, "runtime.") {
   385  			continue
   386  		}
   387  		fmt.Fprintf(w, "#   %s\t%s:%d\n", name, file, line)
   388  	}
   389  }
   390  
   391  func (el *eventLog) Events() []logEntry {
   392  	el.mu.RLock()
   393  	defer el.mu.RUnlock()
   394  	return el.events
   395  }
   396  
   397  // freeEventLogs is a freelist of *eventLog
   398  var freeEventLogs = make(chan *eventLog, 1000)
   399  
   400  // newEventLog returns a event log ready to use.
   401  func newEventLog() *eventLog {
   402  	select {
   403  	case el := <-freeEventLogs:
   404  		return el
   405  	default:
   406  		return new(eventLog)
   407  	}
   408  }
   409  
   410  // freeEventLog adds el to freeEventLogs if there's room.
   411  // This is non-blocking.
   412  func freeEventLog(el *eventLog) {
   413  	el.reset()
   414  	select {
   415  	case freeEventLogs <- el:
   416  	default:
   417  	}
   418  }
   419  
   420  var eventsTmplCache *template.Template
   421  var eventsTmplOnce sync.Once
   422  
   423  func eventsTmpl() *template.Template {
   424  	eventsTmplOnce.Do(func() {
   425  		eventsTmplCache = template.Must(template.New("events").Funcs(template.FuncMap{
   426  			"elapsed":   elapsed,
   427  			"trimSpace": strings.TrimSpace,
   428  		}).Parse(eventsHTML))
   429  	})
   430  	return eventsTmplCache
   431  }
   432  
   433  const eventsHTML = `
   434  <html>
   435  	<head>
   436  		<title>events</title>
   437  	</head>
   438  	<style type="text/css">
   439  		body {
   440  			font-family: sans-serif;
   441  		}
   442  		table#req-status td.family {
   443  			padding-right: 2em;
   444  		}
   445  		table#req-status td.active {
   446  			padding-right: 1em;
   447  		}
   448  		table#req-status td.empty {
   449  			color: #aaa;
   450  		}
   451  		table#reqs {
   452  			margin-top: 1em;
   453  		}
   454  		table#reqs tr.first {
   455  			{{if $.Expanded}}font-weight: bold;{{end}}
   456  		}
   457  		table#reqs td {
   458  			font-family: monospace;
   459  		}
   460  		table#reqs td.when {
   461  			text-align: right;
   462  			white-space: nowrap;
   463  		}
   464  		table#reqs td.elapsed {
   465  			padding: 0 0.5em;
   466  			text-align: right;
   467  			white-space: pre;
   468  			width: 10em;
   469  		}
   470  		address {
   471  			font-size: smaller;
   472  			margin-top: 5em;
   473  		}
   474  	</style>
   475  	<body>
   476  
   477  <h1>/debug/events</h1>
   478  
   479  <table id="req-status">
   480  	{{range $i, $fam := .Families}}
   481  	<tr>
   482  		<td class="family">{{$fam}}</td>
   483  
   484  	        {{range $j, $bucket := $.Buckets}}
   485  	        {{$n := index $.Counts $i $j}}
   486  		<td class="{{if not $bucket.MaxErrAge}}active{{end}}{{if not $n}}empty{{end}}">
   487  	                {{if $n}}<a href="?fam={{$fam}}&b={{$j}}{{if $.Expanded}}&exp=1{{end}}">{{end}}
   488  		        [{{$n}} {{$bucket.String}}]
   489  			{{if $n}}</a>{{end}}
   490  		</td>
   491                  {{end}}
   492  
   493  	</tr>{{end}}
   494  </table>
   495  
   496  {{if $.EventLogs}}
   497  <hr />
   498  <h3>Family: {{$.Family}}</h3>
   499  
   500  {{if $.Expanded}}<a href="?fam={{$.Family}}&b={{$.Bucket}}">{{end}}
   501  [Summary]{{if $.Expanded}}</a>{{end}}
   502  
   503  {{if not $.Expanded}}<a href="?fam={{$.Family}}&b={{$.Bucket}}&exp=1">{{end}}
   504  [Expanded]{{if not $.Expanded}}</a>{{end}}
   505  
   506  <table id="reqs">
   507  	<tr><th>When</th><th>Elapsed</th></tr>
   508  	{{range $el := $.EventLogs}}
   509  	<tr class="first">
   510  		<td class="when">{{$el.When}}</td>
   511  		<td class="elapsed">{{$el.ElapsedTime}}</td>
   512  		<td>{{$el.Title}}
   513  	</tr>
   514  	{{if $.Expanded}}
   515  	<tr>
   516  		<td class="when"></td>
   517  		<td class="elapsed"></td>
   518  		<td><pre>{{$el.Stack|trimSpace}}</pre></td>
   519  	</tr>
   520  	{{range $el.Events}}
   521  	<tr>
   522  		<td class="when">{{.WhenString}}</td>
   523  		<td class="elapsed">{{elapsed .Elapsed}}</td>
   524  		<td>.{{if .IsErr}}E{{else}}.{{end}}. {{.What}}</td>
   525  	</tr>
   526  	{{end}}
   527  	{{end}}
   528  	{{end}}
   529  </table>
   530  {{end}}
   531  	</body>
   532  </html>
   533  `