1// Copyright 2019 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
5package debug
6
7import (
8	"bytes"
9	"context"
10	"fmt"
11	"html/template"
12	"net/http"
13	"runtime/trace"
14	"sort"
15	"strings"
16	"sync"
17	"time"
18
19	"golang.org/x/tools/internal/event"
20	"golang.org/x/tools/internal/event/core"
21	"golang.org/x/tools/internal/event/export"
22	"golang.org/x/tools/internal/event/label"
23)
24
25var TraceTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(`
26{{define "title"}}Trace Information{{end}}
27{{define "body"}}
28	{{range .Traces}}<a href="/trace/{{.Name}}">{{.Name}}</a> last: {{.Last.Duration}}, longest: {{.Longest.Duration}}<br>{{end}}
29	{{if .Selected}}
30		<H2>{{.Selected.Name}}</H2>
31		{{if .Selected.Last}}<H3>Last</H3><ul>{{template "details" .Selected.Last}}</ul>{{end}}
32		{{if .Selected.Longest}}<H3>Longest</H3><ul>{{template "details" .Selected.Longest}}</ul>{{end}}
33	{{end}}
34{{end}}
35{{define "details"}}
36	<li>{{.Offset}} {{.Name}} {{.Duration}} {{.Tags}}</li>
37	{{if .Events}}<ul class=events>{{range .Events}}<li>{{.Offset}} {{.Tags}}</li>{{end}}</ul>{{end}}
38	{{if .Children}}<ul>{{range .Children}}{{template "details" .}}{{end}}</ul>{{end}}
39{{end}}
40`))
41
42type traces struct {
43	mu         sync.Mutex
44	sets       map[string]*traceSet
45	unfinished map[export.SpanContext]*traceData
46}
47
48type TraceResults struct { // exported for testing
49	Traces   []*traceSet
50	Selected *traceSet
51}
52
53type traceSet struct {
54	Name    string
55	Last    *traceData
56	Longest *traceData
57}
58
59type traceData struct {
60	TraceID  export.TraceID
61	SpanID   export.SpanID
62	ParentID export.SpanID
63	Name     string
64	Start    time.Time
65	Finish   time.Time
66	Offset   time.Duration
67	Duration time.Duration
68	Tags     string
69	Events   []traceEvent
70	Children []*traceData
71}
72
73type traceEvent struct {
74	Time   time.Time
75	Offset time.Duration
76	Tags   string
77}
78
79func StdTrace(exporter event.Exporter) event.Exporter {
80	return func(ctx context.Context, ev core.Event, lm label.Map) context.Context {
81		span := export.GetSpan(ctx)
82		if span == nil {
83			return exporter(ctx, ev, lm)
84		}
85		switch {
86		case event.IsStart(ev):
87			if span.ParentID.IsValid() {
88				region := trace.StartRegion(ctx, span.Name)
89				ctx = context.WithValue(ctx, traceKey, region)
90			} else {
91				var task *trace.Task
92				ctx, task = trace.NewTask(ctx, span.Name)
93				ctx = context.WithValue(ctx, traceKey, task)
94			}
95			// Log the start event as it may contain useful labels.
96			msg := formatEvent(ctx, ev, lm)
97			trace.Log(ctx, "start", msg)
98		case event.IsLog(ev):
99			category := ""
100			if event.IsError(ev) {
101				category = "error"
102			}
103			msg := formatEvent(ctx, ev, lm)
104			trace.Log(ctx, category, msg)
105		case event.IsEnd(ev):
106			if v := ctx.Value(traceKey); v != nil {
107				v.(interface{ End() }).End()
108			}
109		}
110		return exporter(ctx, ev, lm)
111	}
112}
113
114func formatEvent(ctx context.Context, ev core.Event, lm label.Map) string {
115	buf := &bytes.Buffer{}
116	p := export.Printer{}
117	p.WriteEvent(buf, ev, lm)
118	return buf.String()
119}
120
121func (t *traces) ProcessEvent(ctx context.Context, ev core.Event, lm label.Map) context.Context {
122	t.mu.Lock()
123	defer t.mu.Unlock()
124	span := export.GetSpan(ctx)
125	if span == nil {
126		return ctx
127	}
128
129	switch {
130	case event.IsStart(ev):
131		if t.sets == nil {
132			t.sets = make(map[string]*traceSet)
133			t.unfinished = make(map[export.SpanContext]*traceData)
134		}
135		// just starting, add it to the unfinished map
136		td := &traceData{
137			TraceID:  span.ID.TraceID,
138			SpanID:   span.ID.SpanID,
139			ParentID: span.ParentID,
140			Name:     span.Name,
141			Start:    span.Start().At(),
142			Tags:     renderLabels(span.Start()),
143		}
144		t.unfinished[span.ID] = td
145		// and wire up parents if we have them
146		if !span.ParentID.IsValid() {
147			return ctx
148		}
149		parentID := export.SpanContext{TraceID: span.ID.TraceID, SpanID: span.ParentID}
150		parent, found := t.unfinished[parentID]
151		if !found {
152			// trace had an invalid parent, so it cannot itself be valid
153			return ctx
154		}
155		parent.Children = append(parent.Children, td)
156
157	case event.IsEnd(ev):
158		// finishing, must be already in the map
159		td, found := t.unfinished[span.ID]
160		if !found {
161			return ctx // if this happens we are in a bad place
162		}
163		delete(t.unfinished, span.ID)
164
165		td.Finish = span.Finish().At()
166		td.Duration = span.Finish().At().Sub(span.Start().At())
167		events := span.Events()
168		td.Events = make([]traceEvent, len(events))
169		for i, event := range events {
170			td.Events[i] = traceEvent{
171				Time: event.At(),
172				Tags: renderLabels(event),
173			}
174		}
175
176		set, ok := t.sets[span.Name]
177		if !ok {
178			set = &traceSet{Name: span.Name}
179			t.sets[span.Name] = set
180		}
181		set.Last = td
182		if set.Longest == nil || set.Last.Duration > set.Longest.Duration {
183			set.Longest = set.Last
184		}
185		if !td.ParentID.IsValid() {
186			fillOffsets(td, td.Start)
187		}
188	}
189	return ctx
190}
191
192func (t *traces) getData(req *http.Request) interface{} {
193	if len(t.sets) == 0 {
194		return nil
195	}
196	data := TraceResults{}
197	data.Traces = make([]*traceSet, 0, len(t.sets))
198	for _, set := range t.sets {
199		data.Traces = append(data.Traces, set)
200	}
201	sort.Slice(data.Traces, func(i, j int) bool { return data.Traces[i].Name < data.Traces[j].Name })
202	if bits := strings.SplitN(req.URL.Path, "/trace/", 2); len(bits) > 1 {
203		data.Selected = t.sets[bits[1]]
204	}
205	return data
206}
207
208func fillOffsets(td *traceData, start time.Time) {
209	td.Offset = td.Start.Sub(start)
210	for i := range td.Events {
211		td.Events[i].Offset = td.Events[i].Time.Sub(start)
212	}
213	for _, child := range td.Children {
214		fillOffsets(child, start)
215	}
216}
217
218func renderLabels(labels label.List) string {
219	buf := &bytes.Buffer{}
220	for index := 0; labels.Valid(index); index++ {
221		if l := labels.Label(index); l.Valid() {
222			fmt.Fprintf(buf, "%v ", l)
223		}
224	}
225	return buf.String()
226}
227