blob: bb402cfaa8f36f2d7ff0d2405f087f779de79d04 [file] [log] [blame]
// Copyright 2019 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 debug
import (
"bytes"
"context"
"fmt"
"html/template"
"net/http"
"runtime/trace"
"sort"
"strings"
"sync"
"time"
"golang.org/x/tools/internal/event"
"golang.org/x/tools/internal/event/core"
"golang.org/x/tools/internal/event/export"
"golang.org/x/tools/internal/event/label"
)
var TraceTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(`
{{define "title"}}Trace Information{{end}}
{{define "body"}}
{{range .Traces}}<a href="/trace/{{.Name}}">{{.Name}}</a> last: {{.Last.Duration}}, longest: {{.Longest.Duration}}<br>{{end}}
{{if .Selected}}
<H2>{{.Selected.Name}}</H2>
{{if .Selected.Last}}<H3>Last</H3><ul>{{template "details" .Selected.Last}}</ul>{{end}}
{{if .Selected.Longest}}<H3>Longest</H3><ul>{{template "details" .Selected.Longest}}</ul>{{end}}
{{end}}
{{end}}
{{define "details"}}
<li>{{.Offset}} {{.Name}} {{.Duration}} {{.Tags}}</li>
{{if .Events}}<ul class=events>{{range .Events}}<li>{{.Offset}} {{.Tags}}</li>{{end}}</ul>{{end}}
{{if .Children}}<ul>{{range .Children}}{{template "details" .}}{{end}}</ul>{{end}}
{{end}}
`))
type traces struct {
mu sync.Mutex
sets map[string]*traceSet
unfinished map[export.SpanContext]*traceData
}
type TraceResults struct { // exported for testing
Traces []*traceSet
Selected *traceSet
}
type traceSet struct {
Name string
Last *traceData
Longest *traceData
}
type traceData struct {
TraceID export.TraceID
SpanID export.SpanID
ParentID export.SpanID
Name string
Start time.Time
Finish time.Time
Offset time.Duration
Duration time.Duration
Tags string
Events []traceEvent
Children []*traceData
}
type traceEvent struct {
Time time.Time
Offset time.Duration
Tags string
}
func StdTrace(exporter event.Exporter) event.Exporter {
return func(ctx context.Context, ev core.Event, lm label.Map) context.Context {
span := export.GetSpan(ctx)
if span == nil {
return exporter(ctx, ev, lm)
}
switch {
case event.IsStart(ev):
if span.ParentID.IsValid() {
region := trace.StartRegion(ctx, span.Name)
ctx = context.WithValue(ctx, traceKey, region)
} else {
var task *trace.Task
ctx, task = trace.NewTask(ctx, span.Name)
ctx = context.WithValue(ctx, traceKey, task)
}
// Log the start event as it may contain useful labels.
msg := formatEvent(ctx, ev, lm)
trace.Log(ctx, "start", msg)
case event.IsLog(ev):
category := ""
if event.IsError(ev) {
category = "error"
}
msg := formatEvent(ctx, ev, lm)
trace.Log(ctx, category, msg)
case event.IsEnd(ev):
if v := ctx.Value(traceKey); v != nil {
v.(interface{ End() }).End()
}
}
return exporter(ctx, ev, lm)
}
}
func formatEvent(ctx context.Context, ev core.Event, lm label.Map) string {
buf := &bytes.Buffer{}
p := export.Printer{}
p.WriteEvent(buf, ev, lm)
return buf.String()
}
func (t *traces) ProcessEvent(ctx context.Context, ev core.Event, lm label.Map) context.Context {
span := export.GetSpan(ctx)
if span == nil {
return ctx
}
switch {
case event.IsStart(ev):
// Just starting: add it to the unfinished map.
// Allocate before the critical section.
td := &traceData{
TraceID: span.ID.TraceID,
SpanID: span.ID.SpanID,
ParentID: span.ParentID,
Name: span.Name,
Start: span.Start().At(),
Tags: renderLabels(span.Start()),
}
t.mu.Lock()
defer t.mu.Unlock()
if t.sets == nil {
t.sets = make(map[string]*traceSet)
t.unfinished = make(map[export.SpanContext]*traceData)
}
t.unfinished[span.ID] = td
// and wire up parents if we have them
if !span.ParentID.IsValid() {
return ctx
}
parentID := export.SpanContext{TraceID: span.ID.TraceID, SpanID: span.ParentID}
parent, found := t.unfinished[parentID]
if !found {
// trace had an invalid parent, so it cannot itself be valid
return ctx
}
parent.Children = append(parent.Children, td)
case event.IsEnd(ev):
// Finishing: must be already in the map.
// Allocate events before the critical section.
events := span.Events()
tdEvents := make([]traceEvent, len(events))
for i, event := range events {
tdEvents[i] = traceEvent{
Time: event.At(),
Tags: renderLabels(event),
}
}
t.mu.Lock()
defer t.mu.Unlock()
td, found := t.unfinished[span.ID]
if !found {
return ctx // if this happens we are in a bad place
}
delete(t.unfinished, span.ID)
td.Finish = span.Finish().At()
td.Duration = span.Finish().At().Sub(span.Start().At())
td.Events = tdEvents
set, ok := t.sets[span.Name]
if !ok {
set = &traceSet{Name: span.Name}
t.sets[span.Name] = set
}
set.Last = td
if set.Longest == nil || set.Last.Duration > set.Longest.Duration {
set.Longest = set.Last
}
if !td.ParentID.IsValid() {
fillOffsets(td, td.Start)
}
}
return ctx
}
func (t *traces) getData(req *http.Request) interface{} {
if len(t.sets) == 0 {
return nil
}
data := TraceResults{}
data.Traces = make([]*traceSet, 0, len(t.sets))
for _, set := range t.sets {
data.Traces = append(data.Traces, set)
}
sort.Slice(data.Traces, func(i, j int) bool { return data.Traces[i].Name < data.Traces[j].Name })
if bits := strings.SplitN(req.URL.Path, "/trace/", 2); len(bits) > 1 {
data.Selected = t.sets[bits[1]]
}
return data
}
func fillOffsets(td *traceData, start time.Time) {
td.Offset = td.Start.Sub(start)
for i := range td.Events {
td.Events[i].Offset = td.Events[i].Time.Sub(start)
}
for _, child := range td.Children {
fillOffsets(child, start)
}
}
func renderLabels(labels label.List) string {
buf := &bytes.Buffer{}
for index := 0; labels.Valid(index); index++ {
if l := labels.Label(index); l.Valid() {
fmt.Fprintf(buf, "%v ", l)
}
}
return buf.String()
}