diff options
Diffstat (limited to 'gopls/internal/lsp/debug')
-rw-r--r-- | gopls/internal/lsp/debug/buildinfo_go1.12.go | 29 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/buildinfo_go1.18.go | 19 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/info.go | 254 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/info_test.go | 47 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/log/log.go | 43 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/metrics.go | 58 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/rpc.go | 239 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/serve.go | 909 | ||||
-rw-r--r-- | gopls/internal/lsp/debug/trace.go | 233 |
9 files changed, 1831 insertions, 0 deletions
diff --git a/gopls/internal/lsp/debug/buildinfo_go1.12.go b/gopls/internal/lsp/debug/buildinfo_go1.12.go new file mode 100644 index 000000000..2f360dbfc --- /dev/null +++ b/gopls/internal/lsp/debug/buildinfo_go1.12.go @@ -0,0 +1,29 @@ +// Copyright 2022 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. + +//go:build !go1.18 +// +build !go1.18 + +package debug + +import ( + "runtime" + "runtime/debug" +) + +type BuildInfo struct { + debug.BuildInfo + GoVersion string // Version of Go that produced this binary +} + +func readBuildInfo() (*BuildInfo, bool) { + rinfo, ok := debug.ReadBuildInfo() + if !ok { + return nil, false + } + return &BuildInfo{ + GoVersion: runtime.Version(), + BuildInfo: *rinfo, + }, true +} diff --git a/gopls/internal/lsp/debug/buildinfo_go1.18.go b/gopls/internal/lsp/debug/buildinfo_go1.18.go new file mode 100644 index 000000000..4121c4bc9 --- /dev/null +++ b/gopls/internal/lsp/debug/buildinfo_go1.18.go @@ -0,0 +1,19 @@ +// Copyright 2022 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. + +//go:build go1.18 +// +build go1.18 + +package debug + +import ( + "runtime/debug" +) + +type BuildInfo debug.BuildInfo + +func readBuildInfo() (*BuildInfo, bool) { + info, ok := debug.ReadBuildInfo() + return (*BuildInfo)(info), ok +} diff --git a/gopls/internal/lsp/debug/info.go b/gopls/internal/lsp/debug/info.go new file mode 100644 index 000000000..00752e6f9 --- /dev/null +++ b/gopls/internal/lsp/debug/info.go @@ -0,0 +1,254 @@ +// 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 exports debug information for gopls. +package debug + +import ( + "context" + "encoding/json" + "fmt" + "io" + "reflect" + "runtime" + "runtime/debug" + "sort" + "strings" + + "golang.org/x/tools/gopls/internal/lsp/source" +) + +type PrintMode int + +const ( + PlainText = PrintMode(iota) + Markdown + HTML + JSON +) + +// Version is a manually-updated mechanism for tracking versions. +const Version = "master" + +// ServerVersion is the format used by gopls to report its version to the +// client. This format is structured so that the client can parse it easily. +type ServerVersion struct { + *BuildInfo + Version string +} + +// VersionInfo returns the build info for the gopls process. If it was not +// built in module mode, we return a GOPATH-specific message with the +// hardcoded version. +func VersionInfo() *ServerVersion { + if info, ok := readBuildInfo(); ok { + return getVersion(info) + } + buildInfo := &BuildInfo{} + // go1.17 or earlier, part of s.BuildInfo are embedded fields. + buildInfo.Path = "gopls, built in GOPATH mode" + buildInfo.GoVersion = runtime.Version() + return &ServerVersion{ + Version: Version, + BuildInfo: buildInfo, + } +} + +func getVersion(info *BuildInfo) *ServerVersion { + return &ServerVersion{ + Version: Version, + BuildInfo: info, + } +} + +// PrintServerInfo writes HTML debug info to w for the Instance. +func (i *Instance) PrintServerInfo(ctx context.Context, w io.Writer) { + section(w, HTML, "Server Instance", func() { + fmt.Fprintf(w, "Start time: %v\n", i.StartTime) + fmt.Fprintf(w, "LogFile: %s\n", i.Logfile) + fmt.Fprintf(w, "Working directory: %s\n", i.Workdir) + fmt.Fprintf(w, "Address: %s\n", i.ServerAddress) + fmt.Fprintf(w, "Debug address: %s\n", i.DebugAddress()) + }) + PrintVersionInfo(ctx, w, true, HTML) + section(w, HTML, "Command Line", func() { + fmt.Fprintf(w, "<a href=/debug/pprof/cmdline>cmdline</a>") + }) +} + +// PrintVersionInfo writes version information to w, using the output format +// specified by mode. verbose controls whether additional information is +// written, including section headers. +func PrintVersionInfo(_ context.Context, w io.Writer, verbose bool, mode PrintMode) error { + info := VersionInfo() + if mode == JSON { + return printVersionInfoJSON(w, info) + } + + if !verbose { + printBuildInfo(w, info, false, mode) + return nil + } + section(w, mode, "Build info", func() { + printBuildInfo(w, info, true, mode) + }) + return nil +} + +func printVersionInfoJSON(w io.Writer, info *ServerVersion) error { + js, err := json.MarshalIndent(info, "", "\t") + if err != nil { + return err + } + _, err = fmt.Fprint(w, string(js)) + return err +} + +func section(w io.Writer, mode PrintMode, title string, body func()) { + switch mode { + case PlainText: + fmt.Fprintln(w, title) + fmt.Fprintln(w, strings.Repeat("-", len(title))) + body() + case Markdown: + fmt.Fprintf(w, "#### %s\n\n```\n", title) + body() + fmt.Fprintf(w, "```\n") + case HTML: + fmt.Fprintf(w, "<h3>%s</h3>\n<pre>\n", title) + body() + fmt.Fprint(w, "</pre>\n") + } +} + +func printBuildInfo(w io.Writer, info *ServerVersion, verbose bool, mode PrintMode) { + fmt.Fprintf(w, "%v %v\n", info.Path, Version) + printModuleInfo(w, info.Main, mode) + if !verbose { + return + } + for _, dep := range info.Deps { + printModuleInfo(w, *dep, mode) + } + fmt.Fprintf(w, "go: %v\n", info.GoVersion) +} + +func printModuleInfo(w io.Writer, m debug.Module, _ PrintMode) { + fmt.Fprintf(w, " %s@%s", m.Path, m.Version) + if m.Sum != "" { + fmt.Fprintf(w, " %s", m.Sum) + } + if m.Replace != nil { + fmt.Fprintf(w, " => %v", m.Replace.Path) + } + fmt.Fprintf(w, "\n") +} + +type field struct { + index []int +} + +var fields []field + +// find all the options. The presumption is that the Options are nested structs +// and that pointers don't need to be dereferenced +func swalk(t reflect.Type, ix []int, indent string) { + switch t.Kind() { + case reflect.Struct: + for i := 0; i < t.NumField(); i++ { + fld := t.Field(i) + ixx := append(append([]int{}, ix...), i) + swalk(fld.Type, ixx, indent+". ") + } + default: + // everything is either a struct or a field (that's an assumption about Options) + fields = append(fields, field{ix}) + } +} + +type sessionOption struct { + Name string + Type string + Current string + Default string +} + +func showOptions(o *source.Options) []sessionOption { + var out []sessionOption + t := reflect.TypeOf(*o) + swalk(t, []int{}, "") + v := reflect.ValueOf(*o) + do := reflect.ValueOf(*source.DefaultOptions()) + for _, f := range fields { + val := v.FieldByIndex(f.index) + def := do.FieldByIndex(f.index) + tx := t.FieldByIndex(f.index) + is := strVal(val) + was := strVal(def) + out = append(out, sessionOption{ + Name: tx.Name, + Type: tx.Type.String(), + Current: is, + Default: was, + }) + } + sort.Slice(out, func(i, j int) bool { + rd := out[i].Current == out[i].Default + ld := out[j].Current == out[j].Default + if rd != ld { + return ld + } + return out[i].Name < out[j].Name + }) + return out +} + +func strVal(val reflect.Value) string { + switch val.Kind() { + case reflect.Bool: + return fmt.Sprintf("%v", val.Interface()) + case reflect.Int, reflect.Int8, reflect.Int16, reflect.Int32, reflect.Int64: + return fmt.Sprintf("%v", val.Interface()) + case reflect.Uint, reflect.Uint8, reflect.Uint16, reflect.Uint32, reflect.Uint64: + return fmt.Sprintf("%v", val.Interface()) + case reflect.Uintptr, reflect.UnsafePointer: + return fmt.Sprintf("0x%x", val.Pointer()) + case reflect.Complex64, reflect.Complex128: + return fmt.Sprintf("%v", val.Complex()) + case reflect.Array, reflect.Slice: + ans := []string{} + for i := 0; i < val.Len(); i++ { + ans = append(ans, strVal(val.Index(i))) + } + sort.Strings(ans) + return fmt.Sprintf("%v", ans) + case reflect.Chan, reflect.Func, reflect.Ptr: + return val.Kind().String() + case reflect.Struct: + var x source.Analyzer + if val.Type() != reflect.TypeOf(x) { + return val.Kind().String() + } + // this is sort of ugly, but usable + str := val.FieldByName("Analyzer").Elem().FieldByName("Doc").String() + ix := strings.Index(str, "\n") + if ix == -1 { + ix = len(str) + } + return str[:ix] + case reflect.String: + return fmt.Sprintf("%q", val.Interface()) + case reflect.Map: + ans := []string{} + iter := val.MapRange() + for iter.Next() { + k := iter.Key() + v := iter.Value() + ans = append(ans, fmt.Sprintf("%s:%s, ", strVal(k), strVal(v))) + } + sort.Strings(ans) + return fmt.Sprintf("%v", ans) + } + return fmt.Sprintf("??%s??", val.Type()) +} diff --git a/gopls/internal/lsp/debug/info_test.go b/gopls/internal/lsp/debug/info_test.go new file mode 100644 index 000000000..5a5362841 --- /dev/null +++ b/gopls/internal/lsp/debug/info_test.go @@ -0,0 +1,47 @@ +// Copyright 2022 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 exports debug information for gopls. +package debug + +import ( + "bytes" + "context" + "encoding/json" + "runtime" + "testing" +) + +func TestPrintVersionInfoJSON(t *testing.T) { + buf := new(bytes.Buffer) + if err := PrintVersionInfo(context.Background(), buf, true, JSON); err != nil { + t.Fatalf("PrintVersionInfo failed: %v", err) + } + res := buf.Bytes() + + var got ServerVersion + if err := json.Unmarshal(res, &got); err != nil { + t.Fatalf("unexpected output: %v\n%s", err, res) + } + if g, w := got.GoVersion, runtime.Version(); g != w { + t.Errorf("go version = %v, want %v", g, w) + } + if g, w := got.Version, Version; g != w { + t.Errorf("gopls version = %v, want %v", g, w) + } + // Other fields of BuildInfo may not be available during test. +} + +func TestPrintVersionInfoPlainText(t *testing.T) { + buf := new(bytes.Buffer) + if err := PrintVersionInfo(context.Background(), buf, true, PlainText); err != nil { + t.Fatalf("PrintVersionInfo failed: %v", err) + } + res := buf.Bytes() + + // Other fields of BuildInfo may not be available during test. + if !bytes.Contains(res, []byte(Version)) || !bytes.Contains(res, []byte(runtime.Version())) { + t.Errorf("plaintext output = %q,\nwant (version: %v, go: %v)", res, Version, runtime.Version()) + } +} diff --git a/gopls/internal/lsp/debug/log/log.go b/gopls/internal/lsp/debug/log/log.go new file mode 100644 index 000000000..e3eaa106f --- /dev/null +++ b/gopls/internal/lsp/debug/log/log.go @@ -0,0 +1,43 @@ +// Copyright 2020 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 log provides helper methods for exporting log events to the +// internal/event package. +package log + +import ( + "context" + "fmt" + + "golang.org/x/tools/internal/event" + "golang.org/x/tools/internal/event/label" + "golang.org/x/tools/internal/event/tag" +) + +// Level parameterizes log severity. +type Level int + +const ( + _ Level = iota + Error + Warning + Info + Debug + Trace +) + +// Log exports a log event labeled with level l. +func (l Level) Log(ctx context.Context, msg string) { + event.Log(ctx, msg, tag.Level.Of(int(l))) +} + +// Logf formats and exports a log event labeled with level l. +func (l Level) Logf(ctx context.Context, format string, args ...interface{}) { + l.Log(ctx, fmt.Sprintf(format, args...)) +} + +// LabeledLevel extracts the labeled log l +func LabeledLevel(lm label.Map) Level { + return Level(tag.Level.Get(lm)) +} diff --git a/gopls/internal/lsp/debug/metrics.go b/gopls/internal/lsp/debug/metrics.go new file mode 100644 index 000000000..c8da803d6 --- /dev/null +++ b/gopls/internal/lsp/debug/metrics.go @@ -0,0 +1,58 @@ +// 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 ( + "golang.org/x/tools/internal/event/export/metric" + "golang.org/x/tools/internal/event/label" + "golang.org/x/tools/internal/event/tag" +) + +var ( + // the distributions we use for histograms + bytesDistribution = []int64{1 << 10, 1 << 11, 1 << 12, 1 << 14, 1 << 16, 1 << 20} + millisecondsDistribution = []float64{0.1, 0.5, 1, 2, 5, 10, 50, 100, 500, 1000, 5000, 10000, 50000, 100000} + + receivedBytes = metric.HistogramInt64{ + Name: "received_bytes", + Description: "Distribution of received bytes, by method.", + Keys: []label.Key{tag.RPCDirection, tag.Method}, + Buckets: bytesDistribution, + } + + sentBytes = metric.HistogramInt64{ + Name: "sent_bytes", + Description: "Distribution of sent bytes, by method.", + Keys: []label.Key{tag.RPCDirection, tag.Method}, + Buckets: bytesDistribution, + } + + latency = metric.HistogramFloat64{ + Name: "latency", + Description: "Distribution of latency in milliseconds, by method.", + Keys: []label.Key{tag.RPCDirection, tag.Method}, + Buckets: millisecondsDistribution, + } + + started = metric.Scalar{ + Name: "started", + Description: "Count of RPCs started by method.", + Keys: []label.Key{tag.RPCDirection, tag.Method}, + } + + completed = metric.Scalar{ + Name: "completed", + Description: "Count of RPCs completed by method and status.", + Keys: []label.Key{tag.RPCDirection, tag.Method, tag.StatusCode}, + } +) + +func registerMetrics(m *metric.Config) { + receivedBytes.Record(m, tag.ReceivedBytes) + sentBytes.Record(m, tag.SentBytes) + latency.Record(m, tag.Latency) + started.Count(m, tag.Started) + completed.Count(m, tag.Latency) +} diff --git a/gopls/internal/lsp/debug/rpc.go b/gopls/internal/lsp/debug/rpc.go new file mode 100644 index 000000000..561002147 --- /dev/null +++ b/gopls/internal/lsp/debug/rpc.go @@ -0,0 +1,239 @@ +// 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 ( + "context" + "fmt" + "html/template" + "net/http" + "sort" + "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" + "golang.org/x/tools/internal/event/tag" +) + +var RPCTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}RPC Information{{end}} +{{define "body"}} + <H2>Inbound</H2> + {{template "rpcSection" .Inbound}} + <H2>Outbound</H2> + {{template "rpcSection" .Outbound}} +{{end}} +{{define "rpcSection"}} + {{range .}}<P> + <b>{{.Method}}</b> {{.Started}} <a href="/trace/{{.Method}}">traces</a> ({{.InProgress}} in progress) + <br> + <i>Latency</i> {{with .Latency}}{{.Mean}} ({{.Min}}<{{.Max}}){{end}} + <i>By bucket</i> 0s {{range .Latency.Values}}{{if gt .Count 0}}<b>{{.Count}}</b> {{.Limit}} {{end}}{{end}} + <br> + <i>Received</i> {{.Received}} (avg. {{.ReceivedMean}}) + <i>Sent</i> {{.Sent}} (avg. {{.SentMean}}) + <br> + <i>Result codes</i> {{range .Codes}}{{.Key}}={{.Count}} {{end}} + </P> + {{end}} +{{end}} +`)) + +type Rpcs struct { // exported for testing + mu sync.Mutex + Inbound []*rpcStats // stats for incoming lsp rpcs sorted by method name + Outbound []*rpcStats // stats for outgoing lsp rpcs sorted by method name +} + +type rpcStats struct { + Method string + Started int64 + Completed int64 + + Latency rpcTimeHistogram + Received byteUnits + Sent byteUnits + Codes []*rpcCodeBucket +} + +type rpcTimeHistogram struct { + Sum timeUnits + Count int64 + Min timeUnits + Max timeUnits + Values []rpcTimeBucket +} + +type rpcTimeBucket struct { + Limit timeUnits + Count int64 +} + +type rpcCodeBucket struct { + Key string + Count int64 +} + +func (r *Rpcs) ProcessEvent(ctx context.Context, ev core.Event, lm label.Map) context.Context { + r.mu.Lock() + defer r.mu.Unlock() + switch { + case event.IsStart(ev): + if _, stats := r.getRPCSpan(ctx, ev); stats != nil { + stats.Started++ + } + case event.IsEnd(ev): + span, stats := r.getRPCSpan(ctx, ev) + if stats != nil { + endRPC(ctx, ev, span, stats) + } + case event.IsMetric(ev): + sent := byteUnits(tag.SentBytes.Get(lm)) + rec := byteUnits(tag.ReceivedBytes.Get(lm)) + if sent != 0 || rec != 0 { + if _, stats := r.getRPCSpan(ctx, ev); stats != nil { + stats.Sent += sent + stats.Received += rec + } + } + } + return ctx +} + +func endRPC(ctx context.Context, ev core.Event, span *export.Span, stats *rpcStats) { + // update the basic counts + stats.Completed++ + + // get and record the status code + if status := getStatusCode(span); status != "" { + var b *rpcCodeBucket + for c, entry := range stats.Codes { + if entry.Key == status { + b = stats.Codes[c] + break + } + } + if b == nil { + b = &rpcCodeBucket{Key: status} + stats.Codes = append(stats.Codes, b) + sort.Slice(stats.Codes, func(i int, j int) bool { + return stats.Codes[i].Key < stats.Codes[j].Key + }) + } + b.Count++ + } + + // calculate latency if this was an rpc span + elapsedTime := span.Finish().At().Sub(span.Start().At()) + latencyMillis := timeUnits(elapsedTime) / timeUnits(time.Millisecond) + if stats.Latency.Count == 0 { + stats.Latency.Min = latencyMillis + stats.Latency.Max = latencyMillis + } else { + if stats.Latency.Min > latencyMillis { + stats.Latency.Min = latencyMillis + } + if stats.Latency.Max < latencyMillis { + stats.Latency.Max = latencyMillis + } + } + stats.Latency.Count++ + stats.Latency.Sum += latencyMillis + for i := range stats.Latency.Values { + if stats.Latency.Values[i].Limit > latencyMillis { + stats.Latency.Values[i].Count++ + break + } + } +} + +func (r *Rpcs) getRPCSpan(ctx context.Context, ev core.Event) (*export.Span, *rpcStats) { + // get the span + span := export.GetSpan(ctx) + if span == nil { + return nil, nil + } + // use the span start event look up the correct stats block + // we do this because it prevents us matching a sub span + return span, r.getRPCStats(span.Start()) +} + +func (r *Rpcs) getRPCStats(lm label.Map) *rpcStats { + method := tag.Method.Get(lm) + if method == "" { + return nil + } + set := &r.Inbound + if tag.RPCDirection.Get(lm) != tag.Inbound { + set = &r.Outbound + } + // get the record for this method + index := sort.Search(len(*set), func(i int) bool { + return (*set)[i].Method >= method + }) + + if index < len(*set) && (*set)[index].Method == method { + return (*set)[index] + } + + old := *set + *set = make([]*rpcStats, len(old)+1) + copy(*set, old[:index]) + copy((*set)[index+1:], old[index:]) + stats := &rpcStats{Method: method} + stats.Latency.Values = make([]rpcTimeBucket, len(millisecondsDistribution)) + for i, m := range millisecondsDistribution { + stats.Latency.Values[i].Limit = timeUnits(m) + } + (*set)[index] = stats + return stats +} + +func (s *rpcStats) InProgress() int64 { return s.Started - s.Completed } +func (s *rpcStats) SentMean() byteUnits { return s.Sent / byteUnits(s.Started) } +func (s *rpcStats) ReceivedMean() byteUnits { return s.Received / byteUnits(s.Started) } + +func (h *rpcTimeHistogram) Mean() timeUnits { return h.Sum / timeUnits(h.Count) } + +func getStatusCode(span *export.Span) string { + for _, ev := range span.Events() { + if status := tag.StatusCode.Get(ev); status != "" { + return status + } + } + return "" +} + +func (r *Rpcs) getData(req *http.Request) interface{} { + return r +} + +func units(v float64, suffixes []string) string { + s := "" + for _, s = range suffixes { + n := v / 1000 + if n < 1 { + break + } + v = n + } + return fmt.Sprintf("%.2f%s", v, s) +} + +type timeUnits float64 + +func (v timeUnits) String() string { + v = v * 1000 * 1000 + return units(float64(v), []string{"ns", "μs", "ms", "s"}) +} + +type byteUnits float64 + +func (v byteUnits) String() string { + return units(float64(v), []string{"B", "KB", "MB", "GB", "TB"}) +} diff --git a/gopls/internal/lsp/debug/serve.go b/gopls/internal/lsp/debug/serve.go new file mode 100644 index 000000000..4bbcbcb30 --- /dev/null +++ b/gopls/internal/lsp/debug/serve.go @@ -0,0 +1,909 @@ +// 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 ( + "archive/zip" + "bytes" + "context" + "errors" + "fmt" + "html/template" + "io" + stdlog "log" + "net" + "net/http" + "net/http/pprof" + "os" + "path" + "path/filepath" + "runtime" + rpprof "runtime/pprof" + "strconv" + "strings" + "sync" + "time" + + "golang.org/x/tools/gopls/internal/lsp/cache" + "golang.org/x/tools/gopls/internal/lsp/debug/log" + "golang.org/x/tools/gopls/internal/lsp/protocol" + "golang.org/x/tools/internal/bug" + "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/export/metric" + "golang.org/x/tools/internal/event/export/ocagent" + "golang.org/x/tools/internal/event/export/prometheus" + "golang.org/x/tools/internal/event/keys" + "golang.org/x/tools/internal/event/label" + "golang.org/x/tools/internal/event/tag" +) + +type contextKeyType int + +const ( + instanceKey contextKeyType = iota + traceKey +) + +// An Instance holds all debug information associated with a gopls instance. +type Instance struct { + Logfile string + StartTime time.Time + ServerAddress string + Workdir string + OCAgentConfig string + + LogWriter io.Writer + + exporter event.Exporter + + ocagent *ocagent.Exporter + prometheus *prometheus.Exporter + rpcs *Rpcs + traces *traces + State *State + + serveMu sync.Mutex + debugAddress string + listenedDebugAddress string +} + +// State holds debugging information related to the server state. +type State struct { + mu sync.Mutex + clients []*Client + servers []*Server +} + +func (st *State) Bugs() []bug.Bug { + return bug.List() +} + +// Caches returns the set of Cache objects currently being served. +func (st *State) Caches() []*cache.Cache { + var caches []*cache.Cache + seen := make(map[string]struct{}) + for _, client := range st.Clients() { + cache := client.Session.Cache() + if _, found := seen[cache.ID()]; found { + continue + } + seen[cache.ID()] = struct{}{} + caches = append(caches, cache) + } + return caches +} + +// Cache returns the Cache that matches the supplied id. +func (st *State) Cache(id string) *cache.Cache { + for _, c := range st.Caches() { + if c.ID() == id { + return c + } + } + return nil +} + +// Sessions returns the set of Session objects currently being served. +func (st *State) Sessions() []*cache.Session { + var sessions []*cache.Session + for _, client := range st.Clients() { + sessions = append(sessions, client.Session) + } + return sessions +} + +// Session returns the Session that matches the supplied id. +func (st *State) Session(id string) *cache.Session { + for _, s := range st.Sessions() { + if s.ID() == id { + return s + } + } + return nil +} + +// Views returns the set of View objects currently being served. +func (st *State) Views() []*cache.View { + var views []*cache.View + for _, s := range st.Sessions() { + views = append(views, s.Views()...) + } + return views +} + +// View returns the View that matches the supplied id. +func (st *State) View(id string) *cache.View { + for _, v := range st.Views() { + if v.ID() == id { + return v + } + } + return nil +} + +// Clients returns the set of Clients currently being served. +func (st *State) Clients() []*Client { + st.mu.Lock() + defer st.mu.Unlock() + clients := make([]*Client, len(st.clients)) + copy(clients, st.clients) + return clients +} + +// Client returns the Client matching the supplied id. +func (st *State) Client(id string) *Client { + for _, c := range st.Clients() { + if c.Session.ID() == id { + return c + } + } + return nil +} + +// Servers returns the set of Servers the instance is currently connected to. +func (st *State) Servers() []*Server { + st.mu.Lock() + defer st.mu.Unlock() + servers := make([]*Server, len(st.servers)) + copy(servers, st.servers) + return servers +} + +// A Client is an incoming connection from a remote client. +type Client struct { + Session *cache.Session + DebugAddress string + Logfile string + GoplsPath string + ServerID string + Service protocol.Server +} + +// A Server is an outgoing connection to a remote LSP server. +type Server struct { + ID string + DebugAddress string + Logfile string + GoplsPath string + ClientID string +} + +// addClient adds a client to the set being served. +func (st *State) addClient(session *cache.Session) { + st.mu.Lock() + defer st.mu.Unlock() + st.clients = append(st.clients, &Client{Session: session}) +} + +// dropClient removes a client from the set being served. +func (st *State) dropClient(session *cache.Session) { + st.mu.Lock() + defer st.mu.Unlock() + for i, c := range st.clients { + if c.Session == session { + copy(st.clients[i:], st.clients[i+1:]) + st.clients[len(st.clients)-1] = nil + st.clients = st.clients[:len(st.clients)-1] + return + } + } +} + +// updateServer updates a server to the set being queried. In practice, there should +// be at most one remote server. +func (st *State) updateServer(server *Server) { + st.mu.Lock() + defer st.mu.Unlock() + for i, existing := range st.servers { + if existing.ID == server.ID { + // Replace, rather than mutate, to avoid a race. + newServers := make([]*Server, len(st.servers)) + copy(newServers, st.servers[:i]) + newServers[i] = server + copy(newServers[i+1:], st.servers[i+1:]) + st.servers = newServers + return + } + } + st.servers = append(st.servers, server) +} + +// dropServer drops a server from the set being queried. +func (st *State) dropServer(id string) { + st.mu.Lock() + defer st.mu.Unlock() + for i, s := range st.servers { + if s.ID == id { + copy(st.servers[i:], st.servers[i+1:]) + st.servers[len(st.servers)-1] = nil + st.servers = st.servers[:len(st.servers)-1] + return + } + } +} + +// an http.ResponseWriter that filters writes +type filterResponse struct { + w http.ResponseWriter + edit func([]byte) []byte +} + +func (c filterResponse) Header() http.Header { + return c.w.Header() +} + +func (c filterResponse) Write(buf []byte) (int, error) { + ans := c.edit(buf) + return c.w.Write(ans) +} + +func (c filterResponse) WriteHeader(n int) { + c.w.WriteHeader(n) +} + +// replace annoying nuls by spaces +func cmdline(w http.ResponseWriter, r *http.Request) { + fake := filterResponse{ + w: w, + edit: func(buf []byte) []byte { + return bytes.ReplaceAll(buf, []byte{0}, []byte{' '}) + }, + } + pprof.Cmdline(fake, r) +} + +func (i *Instance) getCache(r *http.Request) interface{} { + return i.State.Cache(path.Base(r.URL.Path)) +} + +func (i *Instance) getSession(r *http.Request) interface{} { + return i.State.Session(path.Base(r.URL.Path)) +} + +func (i *Instance) getClient(r *http.Request) interface{} { + return i.State.Client(path.Base(r.URL.Path)) +} + +func (i *Instance) getServer(r *http.Request) interface{} { + i.State.mu.Lock() + defer i.State.mu.Unlock() + id := path.Base(r.URL.Path) + for _, s := range i.State.servers { + if s.ID == id { + return s + } + } + return nil +} + +func (i *Instance) getView(r *http.Request) interface{} { + return i.State.View(path.Base(r.URL.Path)) +} + +func (i *Instance) getFile(r *http.Request) interface{} { + identifier := path.Base(r.URL.Path) + sid := path.Base(path.Dir(r.URL.Path)) + s := i.State.Session(sid) + if s == nil { + return nil + } + for _, o := range s.Overlays() { + // TODO(adonovan): understand and document this comparison. + if o.FileIdentity().Hash.String() == identifier { + return o + } + } + return nil +} + +func (i *Instance) getInfo(r *http.Request) interface{} { + buf := &bytes.Buffer{} + i.PrintServerInfo(r.Context(), buf) + return template.HTML(buf.String()) +} + +func (i *Instance) AddService(s protocol.Server, session *cache.Session) { + for _, c := range i.State.clients { + if c.Session == session { + c.Service = s + return + } + } + stdlog.Printf("unable to find a Client to add the protocol.Server to") +} + +func getMemory(_ *http.Request) interface{} { + var m runtime.MemStats + runtime.ReadMemStats(&m) + return m +} + +func init() { + event.SetExporter(makeGlobalExporter(os.Stderr)) +} + +func GetInstance(ctx context.Context) *Instance { + if ctx == nil { + return nil + } + v := ctx.Value(instanceKey) + if v == nil { + return nil + } + return v.(*Instance) +} + +// WithInstance creates debug instance ready for use using the supplied +// configuration and stores it in the returned context. +func WithInstance(ctx context.Context, workdir, agent string) context.Context { + i := &Instance{ + StartTime: time.Now(), + Workdir: workdir, + OCAgentConfig: agent, + } + i.LogWriter = os.Stderr + ocConfig := ocagent.Discover() + //TODO: we should not need to adjust the discovered configuration + ocConfig.Address = i.OCAgentConfig + i.ocagent = ocagent.Connect(ocConfig) + i.prometheus = prometheus.New() + i.rpcs = &Rpcs{} + i.traces = &traces{} + i.State = &State{} + i.exporter = makeInstanceExporter(i) + return context.WithValue(ctx, instanceKey, i) +} + +// SetLogFile sets the logfile for use with this instance. +func (i *Instance) SetLogFile(logfile string, isDaemon bool) (func(), error) { + // TODO: probably a better solution for deferring closure to the caller would + // be for the debug instance to itself be closed, but this fixes the + // immediate bug of logs not being captured. + closeLog := func() {} + if logfile != "" { + if logfile == "auto" { + if isDaemon { + logfile = filepath.Join(os.TempDir(), fmt.Sprintf("gopls-daemon-%d.log", os.Getpid())) + } else { + logfile = filepath.Join(os.TempDir(), fmt.Sprintf("gopls-%d.log", os.Getpid())) + } + } + f, err := os.Create(logfile) + if err != nil { + return nil, fmt.Errorf("unable to create log file: %w", err) + } + closeLog = func() { + defer f.Close() + } + stdlog.SetOutput(io.MultiWriter(os.Stderr, f)) + i.LogWriter = f + } + i.Logfile = logfile + return closeLog, nil +} + +// Serve starts and runs a debug server in the background on the given addr. +// It also logs the port the server starts on, to allow for :0 auto assigned +// ports. +func (i *Instance) Serve(ctx context.Context, addr string) (string, error) { + stdlog.SetFlags(stdlog.Lshortfile) + if addr == "" { + return "", nil + } + i.serveMu.Lock() + defer i.serveMu.Unlock() + + if i.listenedDebugAddress != "" { + // Already serving. Return the bound address. + return i.listenedDebugAddress, nil + } + + i.debugAddress = addr + listener, err := net.Listen("tcp", i.debugAddress) + if err != nil { + return "", err + } + i.listenedDebugAddress = listener.Addr().String() + + port := listener.Addr().(*net.TCPAddr).Port + if strings.HasSuffix(i.debugAddress, ":0") { + stdlog.Printf("debug server listening at http://localhost:%d", port) + } + event.Log(ctx, "Debug serving", tag.Port.Of(port)) + go func() { + mux := http.NewServeMux() + mux.HandleFunc("/", render(MainTmpl, func(*http.Request) interface{} { return i })) + mux.HandleFunc("/debug/", render(DebugTmpl, nil)) + mux.HandleFunc("/debug/pprof/", pprof.Index) + mux.HandleFunc("/debug/pprof/cmdline", cmdline) + mux.HandleFunc("/debug/pprof/profile", pprof.Profile) + mux.HandleFunc("/debug/pprof/symbol", pprof.Symbol) + mux.HandleFunc("/debug/pprof/trace", pprof.Trace) + if i.prometheus != nil { + mux.HandleFunc("/metrics/", i.prometheus.Serve) + } + if i.rpcs != nil { + mux.HandleFunc("/rpc/", render(RPCTmpl, i.rpcs.getData)) + } + if i.traces != nil { + mux.HandleFunc("/trace/", render(TraceTmpl, i.traces.getData)) + } + mux.HandleFunc("/cache/", render(CacheTmpl, i.getCache)) + mux.HandleFunc("/session/", render(SessionTmpl, i.getSession)) + mux.HandleFunc("/view/", render(ViewTmpl, i.getView)) + mux.HandleFunc("/client/", render(ClientTmpl, i.getClient)) + mux.HandleFunc("/server/", render(ServerTmpl, i.getServer)) + mux.HandleFunc("/file/", render(FileTmpl, i.getFile)) + mux.HandleFunc("/info", render(InfoTmpl, i.getInfo)) + mux.HandleFunc("/memory", render(MemoryTmpl, getMemory)) + + // Internal debugging helpers. + mux.HandleFunc("/_dogc", func(w http.ResponseWriter, r *http.Request) { + runtime.GC() + runtime.GC() + runtime.GC() + http.Error(w, "OK", 200) + }) + mux.HandleFunc("/_makeabug", func(w http.ResponseWriter, r *http.Request) { + bug.Report("bug here", nil) + http.Error(w, "made a bug", http.StatusOK) + }) + + if err := http.Serve(listener, mux); err != nil { + event.Error(ctx, "Debug server failed", err) + return + } + event.Log(ctx, "Debug server finished") + }() + return i.listenedDebugAddress, nil +} + +func (i *Instance) DebugAddress() string { + i.serveMu.Lock() + defer i.serveMu.Unlock() + return i.debugAddress +} + +func (i *Instance) ListenedDebugAddress() string { + i.serveMu.Lock() + defer i.serveMu.Unlock() + return i.listenedDebugAddress +} + +// MonitorMemory starts recording memory statistics each second. +func (i *Instance) MonitorMemory(ctx context.Context) { + tick := time.NewTicker(time.Second) + nextThresholdGiB := uint64(1) + go func() { + for { + <-tick.C + var mem runtime.MemStats + runtime.ReadMemStats(&mem) + if mem.HeapAlloc < nextThresholdGiB*1<<30 { + continue + } + if err := i.writeMemoryDebug(nextThresholdGiB, true); err != nil { + event.Error(ctx, "writing memory debug info", err) + } + if err := i.writeMemoryDebug(nextThresholdGiB, false); err != nil { + event.Error(ctx, "writing memory debug info", err) + } + event.Log(ctx, fmt.Sprintf("Wrote memory usage debug info to %v", os.TempDir())) + nextThresholdGiB++ + } + }() +} + +func (i *Instance) writeMemoryDebug(threshold uint64, withNames bool) error { + suffix := "withnames" + if !withNames { + suffix = "nonames" + } + + filename := fmt.Sprintf("gopls.%d-%dGiB-%s.zip", os.Getpid(), threshold, suffix) + zipf, err := os.OpenFile(filepath.Join(os.TempDir(), filename), os.O_CREATE|os.O_RDWR, 0644) + if err != nil { + return err + } + zipw := zip.NewWriter(zipf) + + f, err := zipw.Create("heap.pb.gz") + if err != nil { + return err + } + if err := rpprof.Lookup("heap").WriteTo(f, 0); err != nil { + return err + } + + f, err = zipw.Create("goroutines.txt") + if err != nil { + return err + } + if err := rpprof.Lookup("goroutine").WriteTo(f, 1); err != nil { + return err + } + + if err := zipw.Close(); err != nil { + return err + } + return zipf.Close() +} + +func makeGlobalExporter(stderr io.Writer) event.Exporter { + p := export.Printer{} + var pMu sync.Mutex + return func(ctx context.Context, ev core.Event, lm label.Map) context.Context { + i := GetInstance(ctx) + + if event.IsLog(ev) { + // Don't log context cancellation errors. + if err := keys.Err.Get(ev); errors.Is(err, context.Canceled) { + return ctx + } + // Make sure any log messages without an instance go to stderr. + if i == nil { + pMu.Lock() + p.WriteEvent(stderr, ev, lm) + pMu.Unlock() + } + level := log.LabeledLevel(lm) + // Exclude trace logs from LSP logs. + if level < log.Trace { + ctx = protocol.LogEvent(ctx, ev, lm, messageType(level)) + } + } + if i == nil { + return ctx + } + return i.exporter(ctx, ev, lm) + } +} + +func messageType(l log.Level) protocol.MessageType { + switch l { + case log.Error: + return protocol.Error + case log.Warning: + return protocol.Warning + case log.Debug: + return protocol.Log + } + return protocol.Info +} + +func makeInstanceExporter(i *Instance) event.Exporter { + exporter := func(ctx context.Context, ev core.Event, lm label.Map) context.Context { + if i.ocagent != nil { + ctx = i.ocagent.ProcessEvent(ctx, ev, lm) + } + if i.prometheus != nil { + ctx = i.prometheus.ProcessEvent(ctx, ev, lm) + } + if i.rpcs != nil { + ctx = i.rpcs.ProcessEvent(ctx, ev, lm) + } + if i.traces != nil { + ctx = i.traces.ProcessEvent(ctx, ev, lm) + } + if event.IsLog(ev) { + if s := cache.KeyCreateSession.Get(ev); s != nil { + i.State.addClient(s) + } + if sid := tag.NewServer.Get(ev); sid != "" { + i.State.updateServer(&Server{ + ID: sid, + Logfile: tag.Logfile.Get(ev), + DebugAddress: tag.DebugAddress.Get(ev), + GoplsPath: tag.GoplsPath.Get(ev), + ClientID: tag.ClientID.Get(ev), + }) + } + if s := cache.KeyShutdownSession.Get(ev); s != nil { + i.State.dropClient(s) + } + if sid := tag.EndServer.Get(ev); sid != "" { + i.State.dropServer(sid) + } + if s := cache.KeyUpdateSession.Get(ev); s != nil { + if c := i.State.Client(s.ID()); c != nil { + c.DebugAddress = tag.DebugAddress.Get(ev) + c.Logfile = tag.Logfile.Get(ev) + c.ServerID = tag.ServerID.Get(ev) + c.GoplsPath = tag.GoplsPath.Get(ev) + } + } + } + return ctx + } + // StdTrace must be above export.Spans below (by convention, export + // middleware applies its wrapped exporter last). + exporter = StdTrace(exporter) + metrics := metric.Config{} + registerMetrics(&metrics) + exporter = metrics.Exporter(exporter) + exporter = export.Spans(exporter) + exporter = export.Labels(exporter) + return exporter +} + +type dataFunc func(*http.Request) interface{} + +func render(tmpl *template.Template, fun dataFunc) func(http.ResponseWriter, *http.Request) { + return func(w http.ResponseWriter, r *http.Request) { + var data interface{} + if fun != nil { + data = fun(r) + } + if err := tmpl.Execute(w, data); err != nil { + event.Error(context.Background(), "", err) + http.Error(w, err.Error(), http.StatusInternalServerError) + } + } +} + +func commas(s string) string { + for i := len(s); i > 3; { + i -= 3 + s = s[:i] + "," + s[i:] + } + return s +} + +func fuint64(v uint64) string { + return commas(strconv.FormatUint(v, 10)) +} + +func fuint32(v uint32) string { + return commas(strconv.FormatUint(uint64(v), 10)) +} + +func fcontent(v []byte) string { + return string(v) +} + +var BaseTemplate = template.Must(template.New("").Parse(` +<html> +<head> +<title>{{template "title" .}}</title> +<style> +.profile-name{ + display:inline-block; + width:6rem; +} +td.value { + text-align: right; +} +ul.events { + list-style-type: none; +} + +</style> +{{block "head" .}}{{end}} +</head> +<body> +<a href="/">Main</a> +<a href="/info">Info</a> +<a href="/memory">Memory</a> +<a href="/metrics">Metrics</a> +<a href="/rpc">RPC</a> +<a href="/trace">Trace</a> +<hr> +<h1>{{template "title" .}}</h1> +{{block "body" .}} +Unknown page +{{end}} +</body> +</html> + +{{define "cachelink"}}<a href="/cache/{{.}}">Cache {{.}}</a>{{end}} +{{define "clientlink"}}<a href="/client/{{.}}">Client {{.}}</a>{{end}} +{{define "serverlink"}}<a href="/server/{{.}}">Server {{.}}</a>{{end}} +{{define "sessionlink"}}<a href="/session/{{.}}">Session {{.}}</a>{{end}} +{{define "viewlink"}}<a href="/view/{{.}}">View {{.}}</a>{{end}} +`)).Funcs(template.FuncMap{ + "fuint64": fuint64, + "fuint32": fuint32, + "fcontent": fcontent, + "localAddress": func(s string) string { + // Try to translate loopback addresses to localhost, both for cosmetics and + // because unspecified ipv6 addresses can break links on Windows. + // + // TODO(rfindley): In the future, it would be better not to assume the + // server is running on localhost, and instead construct this address using + // the remote host. + host, port, err := net.SplitHostPort(s) + if err != nil { + return s + } + ip := net.ParseIP(host) + if ip == nil { + return s + } + if ip.IsLoopback() || ip.IsUnspecified() { + return "localhost:" + port + } + return s + }, + "options": func(s *cache.Session) []sessionOption { + return showOptions(s.Options()) + }, +}) + +var MainTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}GoPls server information{{end}} +{{define "body"}} +<h2>Caches</h2> +<ul>{{range .State.Caches}}<li>{{template "cachelink" .ID}}</li>{{end}}</ul> +<h2>Sessions</h2> +<ul>{{range .State.Sessions}}<li>{{template "sessionlink" .ID}} from {{template "cachelink" .Cache.ID}}</li>{{end}}</ul> +<h2>Clients</h2> +<ul>{{range .State.Clients}}<li>{{template "clientlink" .Session.ID}}</li>{{end}}</ul> +<h2>Servers</h2> +<ul>{{range .State.Servers}}<li>{{template "serverlink" .ID}}</li>{{end}}</ul> +<h2>Bug reports</h2> +<dl>{{range .State.Bugs}}<dt>{{.Key}}</dt><dd>{{.Description}}</dd>{{end}}</dl> +{{end}} +`)) + +var InfoTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}GoPls version information{{end}} +{{define "body"}} +{{.}} +{{end}} +`)) + +var MemoryTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}GoPls memory usage{{end}} +{{define "head"}}<meta http-equiv="refresh" content="5">{{end}} +{{define "body"}} +<h2>Stats</h2> +<table> +<tr><td class="label">Allocated bytes</td><td class="value">{{fuint64 .HeapAlloc}}</td></tr> +<tr><td class="label">Total allocated bytes</td><td class="value">{{fuint64 .TotalAlloc}}</td></tr> +<tr><td class="label">System bytes</td><td class="value">{{fuint64 .Sys}}</td></tr> +<tr><td class="label">Heap system bytes</td><td class="value">{{fuint64 .HeapSys}}</td></tr> +<tr><td class="label">Malloc calls</td><td class="value">{{fuint64 .Mallocs}}</td></tr> +<tr><td class="label">Frees</td><td class="value">{{fuint64 .Frees}}</td></tr> +<tr><td class="label">Idle heap bytes</td><td class="value">{{fuint64 .HeapIdle}}</td></tr> +<tr><td class="label">In use bytes</td><td class="value">{{fuint64 .HeapInuse}}</td></tr> +<tr><td class="label">Released to system bytes</td><td class="value">{{fuint64 .HeapReleased}}</td></tr> +<tr><td class="label">Heap object count</td><td class="value">{{fuint64 .HeapObjects}}</td></tr> +<tr><td class="label">Stack in use bytes</td><td class="value">{{fuint64 .StackInuse}}</td></tr> +<tr><td class="label">Stack from system bytes</td><td class="value">{{fuint64 .StackSys}}</td></tr> +<tr><td class="label">Bucket hash bytes</td><td class="value">{{fuint64 .BuckHashSys}}</td></tr> +<tr><td class="label">GC metadata bytes</td><td class="value">{{fuint64 .GCSys}}</td></tr> +<tr><td class="label">Off heap bytes</td><td class="value">{{fuint64 .OtherSys}}</td></tr> +</table> +<h2>By size</h2> +<table> +<tr><th>Size</th><th>Mallocs</th><th>Frees</th></tr> +{{range .BySize}}<tr><td class="value">{{fuint32 .Size}}</td><td class="value">{{fuint64 .Mallocs}}</td><td class="value">{{fuint64 .Frees}}</td></tr>{{end}} +</table> +{{end}} +`)) + +var DebugTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}GoPls Debug pages{{end}} +{{define "body"}} +<a href="/debug/pprof">Profiling</a> +{{end}} +`)) + +var CacheTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}Cache {{.ID}}{{end}} +{{define "body"}} +<h2>memoize.Store entries</h2> +<ul>{{range $k,$v := .MemStats}}<li>{{$k}} - {{$v}}</li>{{end}}</ul> +{{end}} +`)) + +var ClientTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}Client {{.Session.ID}}{{end}} +{{define "body"}} +Using session: <b>{{template "sessionlink" .Session.ID}}</b><br> +{{if .DebugAddress}}Debug this client at: <a href="http://{{localAddress .DebugAddress}}">{{localAddress .DebugAddress}}</a><br>{{end}} +Logfile: {{.Logfile}}<br> +Gopls Path: {{.GoplsPath}}<br> +<h2>Diagnostics</h2> +{{/*Service: []protocol.Server; each server has map[uri]fileReports; + each fileReport: map[diagnosticSoure]diagnosticReport + diagnosticSource is one of 5 source + diagnosticReport: snapshotID and map[hash]*source.Diagnostic + sourceDiagnostic: struct { + Range protocol.Range + Message string + Source string + Code string + CodeHref string + Severity protocol.DiagnosticSeverity + Tags []protocol.DiagnosticTag + + Related []RelatedInformation + } + RelatedInformation: struct { + URI span.URI + Range protocol.Range + Message string + } + */}} +<ul>{{range $k, $v := .Service.Diagnostics}}<li>{{$k}}:<ol>{{range $v}}<li>{{.}}</li>{{end}}</ol></li>{{end}}</ul> +{{end}} +`)) + +var ServerTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}Server {{.ID}}{{end}} +{{define "body"}} +{{if .DebugAddress}}Debug this server at: <a href="http://{{localAddress .DebugAddress}}">{{localAddress .DebugAddress}}</a><br>{{end}} +Logfile: {{.Logfile}}<br> +Gopls Path: {{.GoplsPath}}<br> +{{end}} +`)) + +var SessionTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}Session {{.ID}}{{end}} +{{define "body"}} +From: <b>{{template "cachelink" .Cache.ID}}</b><br> +<h2>Views</h2> +<ul>{{range .Views}}<li>{{.Name}} is {{template "viewlink" .ID}} in {{.Folder}}</li>{{end}}</ul> +<h2>Overlays</h2> +{{$session := .}} +<ul>{{range .Overlays}} +<li> +<a href="/file/{{$session.ID}}/{{.FileIdentity.Hash}}">{{.FileIdentity.URI}}</a> +</li>{{end}}</ul> +<h2>Options</h2> +{{range options .}} +<p><b>{{.Name}}</b> {{.Type}}</p> +<p><i>default:</i> {{.Default}}</p> +{{if ne .Default .Current}}<p><i>current:</i> {{.Current}}</p>{{end}} +{{end}} +{{end}} +`)) + +var ViewTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}View {{.ID}}{{end}} +{{define "body"}} +Name: <b>{{.Name}}</b><br> +Folder: <b>{{.Folder}}</b><br> +<h2>Environment</h2> +<ul>{{range .Options.Env}}<li>{{.}}</li>{{end}}</ul> +{{end}} +`)) + +var FileTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(` +{{define "title"}}Overlay {{.FileIdentity.Hash}}{{end}} +{{define "body"}} +{{with .}} + URI: <b>{{.URI}}</b><br> + Identifier: <b>{{.FileIdentity.Hash}}</b><br> + Version: <b>{{.Version}}</b><br> + Kind: <b>{{.Kind}}</b><br> +{{end}} +<h3>Contents</h3> +<pre>{{fcontent .Read}}</pre> +{{end}} +`)) diff --git a/gopls/internal/lsp/debug/trace.go b/gopls/internal/lsp/debug/trace.go new file mode 100644 index 000000000..bb402cfaa --- /dev/null +++ b/gopls/internal/lsp/debug/trace.go @@ -0,0 +1,233 @@ +// 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() +} |