internal/lsp/bug: add a package for bug reporting
The existing debug.Bug mechanism for reporting internal bugs is
insufficient for several reasons:
- It requires a context, which is not always available.
- By being defined in the debug package, it is subject to import
cycles.
- It is too complicated. Listening for bugs requires understanding the
event package.
Replace this with a simpler 'bug' package with no dependencies, that
allows reporting, listing, and listening on internal bugs. Hopefully
this will fulfill the goal of debug.Bug, to help us track down rare
bugs.
Change-Id: I30cab58429b29bd2d944d62e94f5657e40a760fc
Reviewed-on: https://go-review.googlesource.com/c/tools/+/399623
Reviewed-by: Hyang-Ah Hana Kim <hyangah@gmail.com>
Reviewed-by: Alan Donovan <adonovan@google.com>
gopls-CI: kokoro <noreply+kokoro@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Run-TryBot: Robert Findley <rfindley@google.com>
diff --git a/internal/lsp/bug/bug.go b/internal/lsp/bug/bug.go
new file mode 100644
index 0000000..147b8e8
--- /dev/null
+++ b/internal/lsp/bug/bug.go
@@ -0,0 +1,106 @@
+// 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 bug provides utilities for reporting internal bugs, and being
+// notified when they occur.
+//
+// Philosophically, because gopls runs as a sidecar process that the user does
+// not directly control, sometimes it keeps going on broken invariants rather
+// than panicking. In those cases, bug reports provide a mechanism to alert
+// developers and capture relevant metadata.
+package bug
+
+import (
+ "fmt"
+ "runtime"
+ "runtime/debug"
+ "sort"
+ "sync"
+)
+
+var (
+ mu sync.Mutex
+ exemplars map[string]Bug
+ waiters []chan<- Bug
+)
+
+// A Bug represents an unexpected event or broken invariant. They are used for
+// capturing metadata that helps us understand the event.
+type Bug struct {
+ File string // file containing the call to bug.Report
+ Line int // line containing the call to bug.Report
+ Description string // description of the bug
+ Data Data // additional metadata
+ Key string // key identifying the bug (file:line if available)
+ Stack string // call stack
+}
+
+// Data is additional metadata to record for a bug.
+type Data map[string]interface{}
+
+// Report records a new bug encountered on the server.
+// It uses reflection to report the position of the immediate caller.
+func Report(description string, data Data) {
+ _, file, line, ok := runtime.Caller(1)
+
+ key := "<missing callsite>"
+ if ok {
+ key = fmt.Sprintf("%s:%d", file, line)
+ }
+
+ bug := Bug{
+ File: file,
+ Line: line,
+ Description: description,
+ Data: data,
+ Key: key,
+ Stack: string(debug.Stack()),
+ }
+
+ mu.Lock()
+ defer mu.Unlock()
+
+ if exemplars == nil {
+ exemplars = make(map[string]Bug)
+ }
+
+ if _, ok := exemplars[key]; !ok {
+ exemplars[key] = bug // capture one exemplar per key
+ }
+
+ for _, waiter := range waiters {
+ waiter <- bug
+ }
+ waiters = nil
+}
+
+// Notify returns a channel that will be sent the next bug to occur on the
+// server. This channel only ever receives one bug.
+func Notify() <-chan Bug {
+ mu.Lock()
+ defer mu.Unlock()
+
+ ch := make(chan Bug, 1) // 1-buffered so that bug reporting is non-blocking
+ waiters = append(waiters, ch)
+ return ch
+}
+
+// List returns a slice of bug exemplars -- the first bugs to occur at each
+// callsite.
+func List() []Bug {
+ mu.Lock()
+ defer mu.Unlock()
+
+ var bugs []Bug
+
+ for _, bug := range exemplars {
+ bugs = append(bugs, bug)
+ }
+
+ sort.Slice(bugs, func(i, j int) bool {
+ return bugs[i].Key < bugs[j].Key
+ })
+
+ return bugs
+}
diff --git a/internal/lsp/bug/bug_test.go b/internal/lsp/bug/bug_test.go
new file mode 100644
index 0000000..edfc103
--- /dev/null
+++ b/internal/lsp/bug/bug_test.go
@@ -0,0 +1,65 @@
+// 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 bug
+
+import (
+ "fmt"
+ "testing"
+)
+
+func resetForTesting() {
+ exemplars = nil
+ waiters = nil
+}
+
+func TestListBugs(t *testing.T) {
+ defer resetForTesting()
+
+ Report("bad", nil)
+
+ wantBugs(t, "bad")
+
+ for i := 0; i < 3; i++ {
+ Report(fmt.Sprintf("index:%d", i), nil)
+ }
+
+ wantBugs(t, "bad", "index:0")
+}
+
+func wantBugs(t *testing.T, want ...string) {
+ t.Helper()
+
+ bugs := List()
+ if got, want := len(bugs), len(want); got != want {
+ t.Errorf("List(): got %d bugs, want %d", got, want)
+ return
+ }
+
+ for i, b := range bugs {
+ if got, want := b.Description, want[i]; got != want {
+ t.Errorf("bug.List()[%d] = %q, want %q", i, got, want)
+ }
+ }
+}
+
+func TestBugNotification(t *testing.T) {
+ defer resetForTesting()
+
+ Report("unseen", nil)
+
+ notify1 := Notify()
+ notify2 := Notify()
+
+ Report("seen", Data{"answer": 42})
+
+ for _, got := range []Bug{<-notify1, <-notify2} {
+ if got, want := got.Description, "seen"; got != want {
+ t.Errorf("Saw bug %q, want %q", got, want)
+ }
+ if got, want := got.Data["answer"], 42; got != want {
+ t.Errorf(`bug.Data["answer"] = %v, want %v`, got, want)
+ }
+ }
+}
diff --git a/internal/lsp/debug/serve.go b/internal/lsp/debug/serve.go
index 97790fc..0bdee92 100644
--- a/internal/lsp/debug/serve.go
+++ b/internal/lsp/debug/serve.go
@@ -21,7 +21,6 @@
"path/filepath"
"runtime"
rpprof "runtime/pprof"
- "sort"
"strconv"
"strings"
"sync"
@@ -35,6 +34,7 @@
"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/lsp/bug"
"golang.org/x/tools/internal/lsp/cache"
"golang.org/x/tools/internal/lsp/debug/log"
"golang.org/x/tools/internal/lsp/debug/tag"
@@ -77,45 +77,10 @@
mu sync.Mutex
clients []*Client
servers []*Server
-
- // bugs maps bug description -> formatted event
- bugs map[string]string
}
-func Bug(ctx context.Context, desc, format string, args ...interface{}) {
- labels := []label.Label{tag.Bug.Of(desc)}
- _, file, line, ok := runtime.Caller(1)
- if ok {
- labels = append(labels, tag.Callsite.Of(fmt.Sprintf("%s:%d", file, line)))
- }
- msg := fmt.Sprintf(format, args...)
- event.Log(ctx, msg, labels...)
-}
-
-type bug struct {
- Description, Event string
-}
-
-func (st *State) Bugs() []bug {
- st.mu.Lock()
- defer st.mu.Unlock()
- var bugs []bug
- for k, v := range st.bugs {
- bugs = append(bugs, bug{k, v})
- }
- sort.Slice(bugs, func(i, j int) bool {
- return bugs[i].Description < bugs[j].Description
- })
- return bugs
-}
-
-func (st *State) recordBug(description, event string) {
- st.mu.Lock()
- defer st.mu.Unlock()
- if st.bugs == nil {
- st.bugs = make(map[string]string)
- }
- st.bugs[description] = event
+func (st *State) Bugs() []bug.Bug {
+ return bug.List()
}
// Caches returns the set of Cache objects currently being served.
@@ -502,6 +467,12 @@
mux.HandleFunc("/file/", render(FileTmpl, i.getFile))
mux.HandleFunc("/info", render(InfoTmpl, i.getInfo))
mux.HandleFunc("/memory", render(MemoryTmpl, getMemory))
+
+ 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
@@ -676,9 +647,6 @@
}
}
}
- if b := tag.Bug.Get(ev); b != "" {
- i.State.recordBug(b, fmt.Sprintf("%v", ev))
- }
return ctx
}
// StdTrace must be above export.Spans below (by convention, export
@@ -809,8 +777,8 @@
<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>Known bugs encountered</h2>
-<dl>{{range .State.Bugs}}<dt>{{.Description}}</dt><dd>{{.Event}}</dd>{{end}}</dl>
+<h2>Bug reports</h2>
+<dl>{{range .State.Bugs}}<dt>{{.Key}}</dt><dd>{{.Description}}</dd>{{end}}</dl>
{{end}}
`))
diff --git a/internal/lsp/debug/tag/tag.go b/internal/lsp/debug/tag/tag.go
index 1d00038..ff2f2ec 100644
--- a/internal/lsp/debug/tag/tag.go
+++ b/internal/lsp/debug/tag/tag.go
@@ -43,10 +43,6 @@
ClientID = keys.NewString("client_id", "")
Level = keys.NewInt("level", "The logging level")
-
- // Bug tracks occurrences of known bugs in the server.
- Bug = keys.NewString("bug", "A bug has occurred")
- Callsite = keys.NewString("callsite", "gopls function call site")
)
var (
diff --git a/internal/lsp/source/completion/package.go b/internal/lsp/source/completion/package.go
index 39495e6..7a05153 100644
--- a/internal/lsp/source/completion/package.go
+++ b/internal/lsp/source/completion/package.go
@@ -18,7 +18,7 @@
"strings"
"unicode"
- "golang.org/x/tools/internal/lsp/debug"
+ "golang.org/x/tools/internal/lsp/bug"
"golang.org/x/tools/internal/lsp/fuzzy"
"golang.org/x/tools/internal/lsp/protocol"
"golang.org/x/tools/internal/lsp/safetoken"
@@ -86,7 +86,13 @@
return nil, err
}
if offset > tok.Size() {
- debug.Bug(ctx, "out of bounds cursor", "cursor offset (%d) out of bounds for %s (size: %d)", offset, pgf.URI, tok.Size())
+ // internal bug: we should never get an offset that exceeds the size of our
+ // file.
+ bug.Report("out of bounds cursor", bug.Data{
+ "offset": offset,
+ "URI": pgf.URI,
+ "size": tok.Size(),
+ })
return nil, fmt.Errorf("cursor out of bounds")
}
cursor := tok.Pos(offset)
diff --git a/internal/lsp/source/hover.go b/internal/lsp/source/hover.go
index 277933c..dff9060 100644
--- a/internal/lsp/source/hover.go
+++ b/internal/lsp/source/hover.go
@@ -22,6 +22,7 @@
"golang.org/x/text/unicode/runenames"
"golang.org/x/tools/internal/event"
+ "golang.org/x/tools/internal/lsp/bug"
"golang.org/x/tools/internal/lsp/protocol"
"golang.org/x/tools/internal/lsp/safetoken"
"golang.org/x/tools/internal/typeparams"
@@ -407,8 +408,11 @@
}
// golang/go#52211: somehow we get here with a nil obj.Pkg
- // TODO: allow using debug.Bug here, to catch this bug.
if obj.Pkg() == nil {
+ bug.Report("object with nil pkg", bug.Data{
+ "name": obj.Name(),
+ "type": fmt.Sprintf("%T", obj),
+ })
return "", "", ""
}
@@ -598,11 +602,9 @@
info.signatureSource = "func " + sig.name + sig.Format()
} else {
// Fall back on the object as a signature source.
-
- // TODO(rfindley): refactor so that we can report bugs from the source
- // package.
-
- // debug.Bug(ctx, "invalid builtin hover", "did not find builtin signature: %v", err)
+ bug.Report("invalid builtin hover", bug.Data{
+ "err": err.Error(),
+ })
info.signatureSource = obj
}
case *types.Var:
diff --git a/internal/lsp/source/identifier.go b/internal/lsp/source/identifier.go
index fd1fd3b..d5aa0a5 100644
--- a/internal/lsp/source/identifier.go
+++ b/internal/lsp/source/identifier.go
@@ -17,6 +17,7 @@
"golang.org/x/tools/go/ast/astutil"
"golang.org/x/tools/internal/event"
+ "golang.org/x/tools/internal/lsp/bug"
"golang.org/x/tools/internal/lsp/protocol"
"golang.org/x/tools/internal/lsp/safetoken"
"golang.org/x/tools/internal/span"
@@ -98,6 +99,9 @@
for _, pkg := range pkgs {
pgf, err := pkg.File(fh.URI())
if err != nil {
+ // We shouldn't get a package from PackagesForFile that doesn't actually
+ // contain the file.
+ bug.Report("missing package file", bug.Data{"pkg": pkg.ID(), "file": fh.URI()})
return nil, err
}
spn, err := pgf.Mapper.PointSpan(pos)
