1
0
mirror of https://github.com/golang/go synced 2024-11-18 18:44:42 -07:00
go/internal/lsp/debug/trace.go
Ian Cottrell c4206d458c internal/telemetry: change tracing to be event based
We no longer use the span as the core type of tracing, instead that is an
artifact of the exporter, and start and end tracing is just event based.
This both makes the interface normalized, and also means the null exporter case
is considerably cheaper in memory and cpu.
See below for benchstat changes

name                 old time/op    new time/op    delta
TracingNoExporter-8    4.19µs ±12%    2.71µs ±11%  -35.33%  (p=0.000 n=20+20)
Tracing-8              24.1µs ± 3%     5.1µs ±17%  -78.66%  (p=0.000 n=16+20)

name                 old alloc/op   new alloc/op   delta
TracingNoExporter-8    2.32kB ± 0%    0.40kB ± 0%  -82.76%  (p=0.000 n=20+20)
Tracing-8              6.32kB ± 0%    2.32kB ± 0%  -63.30%  (p=0.000 n=20+20)

name                 old allocs/op  new allocs/op  delta
TracingNoExporter-8      35.0 ± 0%      15.0 ± 0%  -57.14%  (p=0.000 n=20+20)
Tracing-8                 215 ± 0%        35 ± 0%  -83.72%  (p=0.000 n=20+20)

Change-Id: I3cf25871fa49584819504b5c19aa580e5dd03395
Reviewed-on: https://go-review.googlesource.com/c/tools/+/221740
Run-TryBot: Ian Cottrell <iancottrell@google.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: Emmanuel Odeke <emm.odeke@gmail.com>
2020-03-04 02:41:40 +00:00

178 lines
4.3 KiB
Go

// 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"
"sort"
"strings"
"sync"
"time"
"golang.org/x/tools/internal/telemetry"
"golang.org/x/tools/internal/telemetry/export"
)
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 {
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 (t *traces) ProcessEvent(ctx context.Context, event telemetry.Event) context.Context {
t.mu.Lock()
defer t.mu.Unlock()
span := export.GetSpan(ctx)
if span == nil {
return ctx
}
switch event.Type {
case telemetry.EventStartSpan:
if t.sets == nil {
t.sets = make(map[string]*traceSet)
t.unfinished = make(map[export.SpanContext]*traceData)
}
// just starting, add it to the unfinished map
td := &traceData{
TraceID: span.ID.TraceID,
SpanID: span.ID.SpanID,
ParentID: span.ParentID,
Name: span.Name,
Start: span.Start,
Tags: renderTags(span.Tags),
}
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 telemetry.EventEndSpan:
// finishing, must be already in the map
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
td.Duration = span.Finish.Sub(span.Start)
td.Events = make([]traceEvent, len(span.Events))
for i, event := range span.Events {
td.Events[i] = traceEvent{
Time: event.At,
Tags: renderTags(event.Tags),
}
}
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 renderTags(tags telemetry.TagList) string {
buf := &bytes.Buffer{}
for _, tag := range tags {
fmt.Fprintf(buf, "%v=%q ", tag.Key, tag.Value)
}
return buf.String()
}