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>

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
+}

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)
+		}
+	}
+}

internal/lsp/debug/serve.go

@@ -21,7 +21,6 @@ import (
 	"path/filepath"
 	"runtime"
 	rpprof "runtime/pprof"
-	"sort"
 	"strconv"
 	"strings"
 	"sync"
@@ -35,6 +34,7 @@ import (
 	"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 @@ type State struct {
 	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 @@ func (i *Instance) Serve(ctx context.Context, addr string) (string, error) {
 		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 @@ func makeInstanceExporter(i *Instance) event.Exporter {
 				}
 			}
 		}
-		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 @@ var MainTmpl = template.Must(template.Must(BaseTemplate.Clone()).Parse(`
 <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}}
 `))
 

internal/lsp/debug/tag/tag.go

@@ -43,10 +43,6 @@ var (
 	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 (

internal/lsp/source/completion/package.go

@@ -18,7 +18,7 @@ import (
 	"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 @@ func packageCompletionSurrounding(ctx context.Context, fset *token.FileSet, pgf
 		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)

internal/lsp/source/hover.go

@@ -22,6 +22,7 @@ import (
 
 	"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 @@ func linkData(obj types.Object, enclosing *types.TypeName) (name, importPath, an
 	}
 
 	// 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 @@ func FindHoverContext(ctx context.Context, s Snapshot, pkg Package, obj types.Ob
 				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:

internal/lsp/source/identifier.go

@@ -17,6 +17,7 @@ import (
 
 	"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 @@ func Identifier(ctx context.Context, snapshot Snapshot, fh FileHandle, pos proto
 	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)