forked from github/multus-cni
ac21a96804
gomodule is still in progress to migrate for now, hence multus team decide to keep vendor directory to support build without gomodule.
533 lines
12 KiB
Go
533 lines
12 KiB
Go
// Copyright 2015 The Go Authors. All rights reserved.
|
|
// Use of this source code is governed by a BSD-style
|
|
// license that can be found in the LICENSE file.
|
|
|
|
package trace
|
|
|
|
import (
|
|
"bytes"
|
|
"fmt"
|
|
"html/template"
|
|
"io"
|
|
"log"
|
|
"net/http"
|
|
"runtime"
|
|
"sort"
|
|
"strconv"
|
|
"strings"
|
|
"sync"
|
|
"sync/atomic"
|
|
"text/tabwriter"
|
|
"time"
|
|
)
|
|
|
|
const maxEventsPerLog = 100
|
|
|
|
type bucket struct {
|
|
MaxErrAge time.Duration
|
|
String string
|
|
}
|
|
|
|
var buckets = []bucket{
|
|
{0, "total"},
|
|
{10 * time.Second, "errs<10s"},
|
|
{1 * time.Minute, "errs<1m"},
|
|
{10 * time.Minute, "errs<10m"},
|
|
{1 * time.Hour, "errs<1h"},
|
|
{10 * time.Hour, "errs<10h"},
|
|
{24000 * time.Hour, "errors"},
|
|
}
|
|
|
|
// RenderEvents renders the HTML page typically served at /debug/events.
|
|
// It does not do any auth checking. The request may be nil.
|
|
//
|
|
// Most users will use the Events handler.
|
|
func RenderEvents(w http.ResponseWriter, req *http.Request, sensitive bool) {
|
|
now := time.Now()
|
|
data := &struct {
|
|
Families []string // family names
|
|
Buckets []bucket
|
|
Counts [][]int // eventLog count per family/bucket
|
|
|
|
// Set when a bucket has been selected.
|
|
Family string
|
|
Bucket int
|
|
EventLogs eventLogs
|
|
Expanded bool
|
|
}{
|
|
Buckets: buckets,
|
|
}
|
|
|
|
data.Families = make([]string, 0, len(families))
|
|
famMu.RLock()
|
|
for name := range families {
|
|
data.Families = append(data.Families, name)
|
|
}
|
|
famMu.RUnlock()
|
|
sort.Strings(data.Families)
|
|
|
|
// Count the number of eventLogs in each family for each error age.
|
|
data.Counts = make([][]int, len(data.Families))
|
|
for i, name := range data.Families {
|
|
// TODO(sameer): move this loop under the family lock.
|
|
f := getEventFamily(name)
|
|
data.Counts[i] = make([]int, len(data.Buckets))
|
|
for j, b := range data.Buckets {
|
|
data.Counts[i][j] = f.Count(now, b.MaxErrAge)
|
|
}
|
|
}
|
|
|
|
if req != nil {
|
|
var ok bool
|
|
data.Family, data.Bucket, ok = parseEventsArgs(req)
|
|
if !ok {
|
|
// No-op
|
|
} else {
|
|
data.EventLogs = getEventFamily(data.Family).Copy(now, buckets[data.Bucket].MaxErrAge)
|
|
}
|
|
if data.EventLogs != nil {
|
|
defer data.EventLogs.Free()
|
|
sort.Sort(data.EventLogs)
|
|
}
|
|
if exp, err := strconv.ParseBool(req.FormValue("exp")); err == nil {
|
|
data.Expanded = exp
|
|
}
|
|
}
|
|
|
|
famMu.RLock()
|
|
defer famMu.RUnlock()
|
|
if err := eventsTmpl().Execute(w, data); err != nil {
|
|
log.Printf("net/trace: Failed executing template: %v", err)
|
|
}
|
|
}
|
|
|
|
func parseEventsArgs(req *http.Request) (fam string, b int, ok bool) {
|
|
fam, bStr := req.FormValue("fam"), req.FormValue("b")
|
|
if fam == "" || bStr == "" {
|
|
return "", 0, false
|
|
}
|
|
b, err := strconv.Atoi(bStr)
|
|
if err != nil || b < 0 || b >= len(buckets) {
|
|
return "", 0, false
|
|
}
|
|
return fam, b, true
|
|
}
|
|
|
|
// An EventLog provides a log of events associated with a specific object.
|
|
type EventLog interface {
|
|
// Printf formats its arguments with fmt.Sprintf and adds the
|
|
// result to the event log.
|
|
Printf(format string, a ...interface{})
|
|
|
|
// Errorf is like Printf, but it marks this event as an error.
|
|
Errorf(format string, a ...interface{})
|
|
|
|
// Finish declares that this event log is complete.
|
|
// The event log should not be used after calling this method.
|
|
Finish()
|
|
}
|
|
|
|
// NewEventLog returns a new EventLog with the specified family name
|
|
// and title.
|
|
func NewEventLog(family, title string) EventLog {
|
|
el := newEventLog()
|
|
el.ref()
|
|
el.Family, el.Title = family, title
|
|
el.Start = time.Now()
|
|
el.events = make([]logEntry, 0, maxEventsPerLog)
|
|
el.stack = make([]uintptr, 32)
|
|
n := runtime.Callers(2, el.stack)
|
|
el.stack = el.stack[:n]
|
|
|
|
getEventFamily(family).add(el)
|
|
return el
|
|
}
|
|
|
|
func (el *eventLog) Finish() {
|
|
getEventFamily(el.Family).remove(el)
|
|
el.unref() // matches ref in New
|
|
}
|
|
|
|
var (
|
|
famMu sync.RWMutex
|
|
families = make(map[string]*eventFamily) // family name => family
|
|
)
|
|
|
|
func getEventFamily(fam string) *eventFamily {
|
|
famMu.Lock()
|
|
defer famMu.Unlock()
|
|
f := families[fam]
|
|
if f == nil {
|
|
f = &eventFamily{}
|
|
families[fam] = f
|
|
}
|
|
return f
|
|
}
|
|
|
|
type eventFamily struct {
|
|
mu sync.RWMutex
|
|
eventLogs eventLogs
|
|
}
|
|
|
|
func (f *eventFamily) add(el *eventLog) {
|
|
f.mu.Lock()
|
|
f.eventLogs = append(f.eventLogs, el)
|
|
f.mu.Unlock()
|
|
}
|
|
|
|
func (f *eventFamily) remove(el *eventLog) {
|
|
f.mu.Lock()
|
|
defer f.mu.Unlock()
|
|
for i, el0 := range f.eventLogs {
|
|
if el == el0 {
|
|
copy(f.eventLogs[i:], f.eventLogs[i+1:])
|
|
f.eventLogs = f.eventLogs[:len(f.eventLogs)-1]
|
|
return
|
|
}
|
|
}
|
|
}
|
|
|
|
func (f *eventFamily) Count(now time.Time, maxErrAge time.Duration) (n int) {
|
|
f.mu.RLock()
|
|
defer f.mu.RUnlock()
|
|
for _, el := range f.eventLogs {
|
|
if el.hasRecentError(now, maxErrAge) {
|
|
n++
|
|
}
|
|
}
|
|
return
|
|
}
|
|
|
|
func (f *eventFamily) Copy(now time.Time, maxErrAge time.Duration) (els eventLogs) {
|
|
f.mu.RLock()
|
|
defer f.mu.RUnlock()
|
|
els = make(eventLogs, 0, len(f.eventLogs))
|
|
for _, el := range f.eventLogs {
|
|
if el.hasRecentError(now, maxErrAge) {
|
|
el.ref()
|
|
els = append(els, el)
|
|
}
|
|
}
|
|
return
|
|
}
|
|
|
|
type eventLogs []*eventLog
|
|
|
|
// Free calls unref on each element of the list.
|
|
func (els eventLogs) Free() {
|
|
for _, el := range els {
|
|
el.unref()
|
|
}
|
|
}
|
|
|
|
// eventLogs may be sorted in reverse chronological order.
|
|
func (els eventLogs) Len() int { return len(els) }
|
|
func (els eventLogs) Less(i, j int) bool { return els[i].Start.After(els[j].Start) }
|
|
func (els eventLogs) Swap(i, j int) { els[i], els[j] = els[j], els[i] }
|
|
|
|
// A logEntry is a timestamped log entry in an event log.
|
|
type logEntry struct {
|
|
When time.Time
|
|
Elapsed time.Duration // since previous event in log
|
|
NewDay bool // whether this event is on a different day to the previous event
|
|
What string
|
|
IsErr bool
|
|
}
|
|
|
|
// WhenString returns a string representation of the elapsed time of the event.
|
|
// It will include the date if midnight was crossed.
|
|
func (e logEntry) WhenString() string {
|
|
if e.NewDay {
|
|
return e.When.Format("2006/01/02 15:04:05.000000")
|
|
}
|
|
return e.When.Format("15:04:05.000000")
|
|
}
|
|
|
|
// An eventLog represents an active event log.
|
|
type eventLog struct {
|
|
// Family is the top-level grouping of event logs to which this belongs.
|
|
Family string
|
|
|
|
// Title is the title of this event log.
|
|
Title string
|
|
|
|
// Timing information.
|
|
Start time.Time
|
|
|
|
// Call stack where this event log was created.
|
|
stack []uintptr
|
|
|
|
// Append-only sequence of events.
|
|
//
|
|
// TODO(sameer): change this to a ring buffer to avoid the array copy
|
|
// when we hit maxEventsPerLog.
|
|
mu sync.RWMutex
|
|
events []logEntry
|
|
LastErrorTime time.Time
|
|
discarded int
|
|
|
|
refs int32 // how many buckets this is in
|
|
}
|
|
|
|
func (el *eventLog) reset() {
|
|
// Clear all but the mutex. Mutexes may not be copied, even when unlocked.
|
|
el.Family = ""
|
|
el.Title = ""
|
|
el.Start = time.Time{}
|
|
el.stack = nil
|
|
el.events = nil
|
|
el.LastErrorTime = time.Time{}
|
|
el.discarded = 0
|
|
el.refs = 0
|
|
}
|
|
|
|
func (el *eventLog) hasRecentError(now time.Time, maxErrAge time.Duration) bool {
|
|
if maxErrAge == 0 {
|
|
return true
|
|
}
|
|
el.mu.RLock()
|
|
defer el.mu.RUnlock()
|
|
return now.Sub(el.LastErrorTime) < maxErrAge
|
|
}
|
|
|
|
// delta returns the elapsed time since the last event or the log start,
|
|
// and whether it spans midnight.
|
|
// L >= el.mu
|
|
func (el *eventLog) delta(t time.Time) (time.Duration, bool) {
|
|
if len(el.events) == 0 {
|
|
return t.Sub(el.Start), false
|
|
}
|
|
prev := el.events[len(el.events)-1].When
|
|
return t.Sub(prev), prev.Day() != t.Day()
|
|
|
|
}
|
|
|
|
func (el *eventLog) Printf(format string, a ...interface{}) {
|
|
el.printf(false, format, a...)
|
|
}
|
|
|
|
func (el *eventLog) Errorf(format string, a ...interface{}) {
|
|
el.printf(true, format, a...)
|
|
}
|
|
|
|
func (el *eventLog) printf(isErr bool, format string, a ...interface{}) {
|
|
e := logEntry{When: time.Now(), IsErr: isErr, What: fmt.Sprintf(format, a...)}
|
|
el.mu.Lock()
|
|
e.Elapsed, e.NewDay = el.delta(e.When)
|
|
if len(el.events) < maxEventsPerLog {
|
|
el.events = append(el.events, e)
|
|
} else {
|
|
// Discard the oldest event.
|
|
if el.discarded == 0 {
|
|
// el.discarded starts at two to count for the event it
|
|
// is replacing, plus the next one that we are about to
|
|
// drop.
|
|
el.discarded = 2
|
|
} else {
|
|
el.discarded++
|
|
}
|
|
// TODO(sameer): if this causes allocations on a critical path,
|
|
// change eventLog.What to be a fmt.Stringer, as in trace.go.
|
|
el.events[0].What = fmt.Sprintf("(%d events discarded)", el.discarded)
|
|
// The timestamp of the discarded meta-event should be
|
|
// the time of the last event it is representing.
|
|
el.events[0].When = el.events[1].When
|
|
copy(el.events[1:], el.events[2:])
|
|
el.events[maxEventsPerLog-1] = e
|
|
}
|
|
if e.IsErr {
|
|
el.LastErrorTime = e.When
|
|
}
|
|
el.mu.Unlock()
|
|
}
|
|
|
|
func (el *eventLog) ref() {
|
|
atomic.AddInt32(&el.refs, 1)
|
|
}
|
|
|
|
func (el *eventLog) unref() {
|
|
if atomic.AddInt32(&el.refs, -1) == 0 {
|
|
freeEventLog(el)
|
|
}
|
|
}
|
|
|
|
func (el *eventLog) When() string {
|
|
return el.Start.Format("2006/01/02 15:04:05.000000")
|
|
}
|
|
|
|
func (el *eventLog) ElapsedTime() string {
|
|
elapsed := time.Since(el.Start)
|
|
return fmt.Sprintf("%.6f", elapsed.Seconds())
|
|
}
|
|
|
|
func (el *eventLog) Stack() string {
|
|
buf := new(bytes.Buffer)
|
|
tw := tabwriter.NewWriter(buf, 1, 8, 1, '\t', 0)
|
|
printStackRecord(tw, el.stack)
|
|
tw.Flush()
|
|
return buf.String()
|
|
}
|
|
|
|
// printStackRecord prints the function + source line information
|
|
// for a single stack trace.
|
|
// Adapted from runtime/pprof/pprof.go.
|
|
func printStackRecord(w io.Writer, stk []uintptr) {
|
|
for _, pc := range stk {
|
|
f := runtime.FuncForPC(pc)
|
|
if f == nil {
|
|
continue
|
|
}
|
|
file, line := f.FileLine(pc)
|
|
name := f.Name()
|
|
// Hide runtime.goexit and any runtime functions at the beginning.
|
|
if strings.HasPrefix(name, "runtime.") {
|
|
continue
|
|
}
|
|
fmt.Fprintf(w, "# %s\t%s:%d\n", name, file, line)
|
|
}
|
|
}
|
|
|
|
func (el *eventLog) Events() []logEntry {
|
|
el.mu.RLock()
|
|
defer el.mu.RUnlock()
|
|
return el.events
|
|
}
|
|
|
|
// freeEventLogs is a freelist of *eventLog
|
|
var freeEventLogs = make(chan *eventLog, 1000)
|
|
|
|
// newEventLog returns a event log ready to use.
|
|
func newEventLog() *eventLog {
|
|
select {
|
|
case el := <-freeEventLogs:
|
|
return el
|
|
default:
|
|
return new(eventLog)
|
|
}
|
|
}
|
|
|
|
// freeEventLog adds el to freeEventLogs if there's room.
|
|
// This is non-blocking.
|
|
func freeEventLog(el *eventLog) {
|
|
el.reset()
|
|
select {
|
|
case freeEventLogs <- el:
|
|
default:
|
|
}
|
|
}
|
|
|
|
var eventsTmplCache *template.Template
|
|
var eventsTmplOnce sync.Once
|
|
|
|
func eventsTmpl() *template.Template {
|
|
eventsTmplOnce.Do(func() {
|
|
eventsTmplCache = template.Must(template.New("events").Funcs(template.FuncMap{
|
|
"elapsed": elapsed,
|
|
"trimSpace": strings.TrimSpace,
|
|
}).Parse(eventsHTML))
|
|
})
|
|
return eventsTmplCache
|
|
}
|
|
|
|
const eventsHTML = `
|
|
<html>
|
|
<head>
|
|
<title>events</title>
|
|
</head>
|
|
<style type="text/css">
|
|
body {
|
|
font-family: sans-serif;
|
|
}
|
|
table#req-status td.family {
|
|
padding-right: 2em;
|
|
}
|
|
table#req-status td.active {
|
|
padding-right: 1em;
|
|
}
|
|
table#req-status td.empty {
|
|
color: #aaa;
|
|
}
|
|
table#reqs {
|
|
margin-top: 1em;
|
|
}
|
|
table#reqs tr.first {
|
|
{{if $.Expanded}}font-weight: bold;{{end}}
|
|
}
|
|
table#reqs td {
|
|
font-family: monospace;
|
|
}
|
|
table#reqs td.when {
|
|
text-align: right;
|
|
white-space: nowrap;
|
|
}
|
|
table#reqs td.elapsed {
|
|
padding: 0 0.5em;
|
|
text-align: right;
|
|
white-space: pre;
|
|
width: 10em;
|
|
}
|
|
address {
|
|
font-size: smaller;
|
|
margin-top: 5em;
|
|
}
|
|
</style>
|
|
<body>
|
|
|
|
<h1>/debug/events</h1>
|
|
|
|
<table id="req-status">
|
|
{{range $i, $fam := .Families}}
|
|
<tr>
|
|
<td class="family">{{$fam}}</td>
|
|
|
|
{{range $j, $bucket := $.Buckets}}
|
|
{{$n := index $.Counts $i $j}}
|
|
<td class="{{if not $bucket.MaxErrAge}}active{{end}}{{if not $n}}empty{{end}}">
|
|
{{if $n}}<a href="?fam={{$fam}}&b={{$j}}{{if $.Expanded}}&exp=1{{end}}">{{end}}
|
|
[{{$n}} {{$bucket.String}}]
|
|
{{if $n}}</a>{{end}}
|
|
</td>
|
|
{{end}}
|
|
|
|
</tr>{{end}}
|
|
</table>
|
|
|
|
{{if $.EventLogs}}
|
|
<hr />
|
|
<h3>Family: {{$.Family}}</h3>
|
|
|
|
{{if $.Expanded}}<a href="?fam={{$.Family}}&b={{$.Bucket}}">{{end}}
|
|
[Summary]{{if $.Expanded}}</a>{{end}}
|
|
|
|
{{if not $.Expanded}}<a href="?fam={{$.Family}}&b={{$.Bucket}}&exp=1">{{end}}
|
|
[Expanded]{{if not $.Expanded}}</a>{{end}}
|
|
|
|
<table id="reqs">
|
|
<tr><th>When</th><th>Elapsed</th></tr>
|
|
{{range $el := $.EventLogs}}
|
|
<tr class="first">
|
|
<td class="when">{{$el.When}}</td>
|
|
<td class="elapsed">{{$el.ElapsedTime}}</td>
|
|
<td>{{$el.Title}}
|
|
</tr>
|
|
{{if $.Expanded}}
|
|
<tr>
|
|
<td class="when"></td>
|
|
<td class="elapsed"></td>
|
|
<td><pre>{{$el.Stack|trimSpace}}</pre></td>
|
|
</tr>
|
|
{{range $el.Events}}
|
|
<tr>
|
|
<td class="when">{{.WhenString}}</td>
|
|
<td class="elapsed">{{elapsed .Elapsed}}</td>
|
|
<td>.{{if .IsErr}}E{{else}}.{{end}}. {{.What}}</td>
|
|
</tr>
|
|
{{end}}
|
|
{{end}}
|
|
{{end}}
|
|
</table>
|
|
{{end}}
|
|
</body>
|
|
</html>
|
|
`
|