gopls/internal/bug: record bug reports in file cache

This change causes bug.Report to save a copy of the bug report
in the file cache, and the 'gopls stats' command to report
all such bug reports associated with the same executable.

The bug.Notify mechanism was made synchronous (and renamed
bug.Handle) so that the handler has time to record the
report before the process terminates. The handler is
registered early during filecache initialization.

The test uses an undocumented environment variable,
TEST_GOPLS_BUG, which causes the stats command (!)
to simply report a bug and return.

Change-Id: I8b84ad3b8f05386844f00faf5728106495b56294
Reviewed-on: https://go-review.googlesource.com/c/tools/+/488795
Run-TryBot: Alan Donovan <[email protected]>
gopls-CI: kokoro <[email protected]>
Reviewed-by: Robert Findley <[email protected]>
Auto-Submit: Alan Donovan <[email protected]>
TryBot-Result: Gopher Robot <[email protected]>

Author: adonovan

gopls/internal/bug/bug.go

@@ -27,7 +27,7 @@ var PanicOnBugs = false
 var (
 	mu        sync.Mutex
 	exemplars map[string]Bug
-	waiters   []chan<- Bug
+	handlers  []func(Bug)
 )
 
 // A Bug represents an unexpected event or broken invariant. They are used for
@@ -80,31 +80,31 @@ func report(description string) {
 	}
 
 	mu.Lock()
-	defer mu.Unlock()
-
-	if exemplars == nil {
-		exemplars = make(map[string]Bug)
-	}
-
 	if _, ok := exemplars[key]; !ok {
+		if exemplars == nil {
+			exemplars = make(map[string]Bug)
+		}
 		exemplars[key] = bug // capture one exemplar per key
 	}
-
-	for _, waiter := range waiters {
-		waiter <- bug
+	hh := handlers
+	handlers = nil
+	mu.Unlock()
+
+	// Call the handlers outside the critical section since a
+	// handler may itself fail and call bug.Report. Since handlers
+	// are one-shot, the inner call should be trivial.
+	for _, handle := range hh {
+		handle(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 {
+// Handle adds a handler function that will be called with the next
+// bug to occur on the server. The handler only ever receives one bug.
+// It is called synchronously, and should return in a timely manner.
+func Handle(h func(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
+	handlers = append(handlers, h)
 }
 
 // List returns a slice of bug exemplars -- the first bugs to occur at each

gopls/internal/bug/bug_test.go

@@ -11,7 +11,7 @@ import (
 
 func resetForTesting() {
 	exemplars = nil
-	waiters = nil
+	handlers = nil
 }
 
 func TestListBugs(t *testing.T) {
@@ -44,19 +44,21 @@ func wantBugs(t *testing.T, want ...string) {
 	}
 }
 
-func TestBugNotification(t *testing.T) {
+func TestBugHandler(t *testing.T) {
 	defer resetForTesting()
 
 	Report("unseen")
 
-	notify1 := Notify()
-	notify2 := Notify()
+	// Both handlers are called, in order of registration, only once.
+	var got string
+	Handle(func(b Bug) { got += "1:" + b.Description })
+	Handle(func(b Bug) { got += "2:" + b.Description })
 
 	Report("seen")
 
-	for _, got := range []Bug{<-notify1, <-notify2} {
-		if got, want := got.Description, "seen"; got != want {
-			t.Errorf("Saw bug %q, want %q", got, want)
-		}
+	Report("again")
+
+	if want := "1:seen2:seen"; got != want {
+		t.Errorf("got %q, want %q", got, want)
 	}
 }

gopls/internal/lsp/cmd/stats.go

@@ -21,6 +21,7 @@ import (
 	"golang.org/x/tools/gopls/internal/lsp"
 	"golang.org/x/tools/gopls/internal/lsp/command"
 	"golang.org/x/tools/gopls/internal/lsp/debug"
+	"golang.org/x/tools/gopls/internal/lsp/filecache"
 	"golang.org/x/tools/gopls/internal/lsp/protocol"
 	"golang.org/x/tools/gopls/internal/lsp/source"
 )
@@ -47,6 +48,15 @@ Example:
 }
 
 func (s *stats) Run(ctx context.Context, args ...string) error {
+
+	// This undocumented environment variable allows
+	// the cmd integration test to trigger a call to bug.Report.
+	if msg := os.Getenv("TEST_GOPLS_BUG"); msg != "" {
+		filecache.Start() // effect: register bug handler
+		goplsbug.Report(msg)
+		return nil
+	}
+
 	if s.app.Remote != "" {
 		// stats does not work with -remote.
 		// Other sessions on the daemon may interfere with results.
@@ -126,12 +136,15 @@ func (s *stats) Run(ctx context.Context, args ...string) error {
 	}
 	defer conn.terminate(ctx)
 
-	// bug.List only reports bugs that have been encountered in the current
-	// process, so only list bugs after the initial workspace load has completed.
-	//
-	// TODO(rfindley): persist bugs to the gopls cache, so that they can be
-	// interrogated.
-	stats.Bugs = goplsbug.List()
+	// Gather bug reports produced by any process using
+	// this executable and persisted in the cache.
+	stats.BugReports = []string{} // non-nil for JSON
+	do("Gathering bug reports", func() error {
+		for _, report := range filecache.BugReports() {
+			stats.BugReports = append(stats.BugReports, string(report))
+		}
+		return nil
+	})
 
 	if _, err := do("Querying memstats", func() error {
 		memStats, err := conn.ExecuteCommand(ctx, &protocol.ExecuteCommandParams{
@@ -184,7 +197,7 @@ type GoplsStats struct {
 	GoVersion                    string
 	GoplsVersion                 string
 	InitialWorkspaceLoadDuration string // in time.Duration string form
-	Bugs                         []goplsbug.Bug
+	BugReports                   []string
 	MemStats                     command.MemStatsResult
 	WorkspaceStats               command.WorkspaceStatsResult
 	DirStats                     dirStats

gopls/internal/lsp/cmd/test/cmdtest.go

@@ -1,6 +1,8 @@
 // Copyright 2023 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 cmdtest contains the test suite for the command line behavior of gopls.
 package cmdtest
 
 // This file defines integration tests of each gopls subcommand that
@@ -28,6 +30,7 @@ import (
 	"context"
 	"encoding/json"
 	"fmt"
+	"math/rand"
 	"os"
 	"path/filepath"
 	"regexp"
@@ -694,6 +697,15 @@ package b
 package foo
 `)
 
+	// Trigger a bug report with a distinctive string
+	// and check that it was durably recorded.
+	oops := fmt.Sprintf("oops-%d", rand.Int())
+	{
+		env := []string{"TEST_GOPLS_BUG=" + oops}
+		res := goplsWithEnv(t, tree, env, "stats")
+		res.checkExit(true)
+	}
+
 	res := gopls(t, tree, "stats")
 	res.checkExit(true)
 
@@ -728,6 +740,22 @@ package foo
 			t.Errorf("stats.%s = %d, want %d", check.field, check.got, check.want)
 		}
 	}
+
+	// Check that we got a BugReport with the expected message.
+	{
+		got := fmt.Sprint(stats.BugReports)
+		wants := []string{
+			"cmd/stats.go", // File containing call to bug.Report
+			oops,           // Description
+		}
+		for _, want := range wants {
+			if !strings.Contains(got, want) {
+				t.Errorf("BugReports does not contain %q. Got:<<%s>>", want, got)
+				break
+			}
+		}
+	}
+
 }
 
 // TestFix tests the 'fix' subcommand (../suggested_fix.go).
@@ -814,7 +842,12 @@ func TestMain(m *testing.M) {
 
 // This function is a stand-in for gopls.main in ../../../../main.go.
 func goplsMain() {
-	bug.PanicOnBugs = true // (not in the production command)
+	// Panic on bugs (unlike the production gopls command),
+	// except in tests that inject calls to bug.Report.
+	if os.Getenv("TEST_GOPLS_BUG") == "" {
+		bug.PanicOnBugs = true
+	}
+
 	tool.Main(context.Background(), cmd.New("gopls", "", nil, hooks.Options), os.Args[1:])
 }
 
@@ -844,6 +877,10 @@ func writeTree(t *testing.T, archive string) string {
 
 // gopls executes gopls in a child process.
 func gopls(t *testing.T, dir string, args ...string) *result {
+	return goplsWithEnv(t, dir, nil, args...)
+}
+
+func goplsWithEnv(t *testing.T, dir string, env []string, args ...string) *result {
 	testenv.NeedsTool(t, "go")
 
 	// Catch inadvertent use of dir=".", which would make
@@ -857,6 +894,7 @@ func gopls(t *testing.T, dir string, args ...string) *result {
 		"ENTRYPOINT=goplsMain",
 		fmt.Sprintf("%s=true", cmd.DebugSuggestedFixEnvVar),
 	)
+	goplsCmd.Env = append(goplsCmd.Env, env...)
 	goplsCmd.Dir = dir
 	goplsCmd.Stdout = new(bytes.Buffer)
 	goplsCmd.Stderr = new(bytes.Buffer)

gopls/internal/lsp/cmd/test/integration_test.go

@@ -24,10 +24,12 @@ import (
 	"bytes"
 	"crypto/sha256"
 	"encoding/binary"
+	"encoding/hex"
 	"errors"
 	"fmt"
 	"hash/crc32"
 	"io"
+	"io/fs"
 	"log"
 	"os"
 	"path/filepath"
@@ -420,3 +422,48 @@ func gc(goplsDir string) {
 		}
 	}
 }
+
+const bugKind = "bug" // reserved kind for gopls bug reports
+
+func init() {
+	// Register a handler to durably record this process's first
+	// assertion failure in the cache so that we can ask users to
+	// share this information via the stats command.
+	bug.Handle(func(bug bug.Bug) {
+		// Wait for cache init (bugs in tests happen early).
+		_, _ = getCacheDir()
+
+		value := []byte(fmt.Sprintf("%s: %+v", time.Now().Format(time.RFC3339), bug))
+		key := sha256.Sum256(value)
+		_ = Set(bugKind, key, value)
+	})
+}
+
+// BugReports returns a new unordered array of the contents
+// of all cached bug reports produced by this executable.
+func BugReports() [][]byte {
+	dir, err := getCacheDir()
+	if err != nil {
+		return nil // ignore initialization errors
+	}
+	var result [][]byte
+	_ = filepath.Walk(filepath.Join(dir, bugKind),
+		func(path string, info fs.FileInfo, err error) error {
+			if err != nil {
+				return nil // ignore readdir/stat errors
+			}
+			if !info.IsDir() {
+				var key [32]byte
+				n, err := hex.Decode(key[:], []byte(filepath.Base(path)))
+				if err != nil || n != len(key) {
+					return nil // ignore malformed file names
+				}
+				content, err := Get(bugKind, key)
+				if err == nil { // ignore read errors
+					result = append(result, content)
+				}
+			}
+			return nil
+		})
+	return result
+}

gopls/internal/lsp/filecache/filecache.go

@@ -63,17 +63,17 @@ func (s *Server) initialize(ctx context.Context, params *protocol.ParamInitializ
 
 	if options.ShowBugReports {
 		// Report the next bug that occurs on the server.
-		bugCh := bug.Notify()
-		go func() {
-			b := <-bugCh
+		bug.Handle(func(b bug.Bug) {
 			msg := &protocol.ShowMessageParams{
 				Type:    protocol.Error,
 				Message: fmt.Sprintf("A bug occurred on the server: %s\nLocation:%s", b.Description, b.Key),
 			}
-			if err := s.eventuallyShowMessage(context.Background(), msg); err != nil {
-				log.Printf("error showing bug: %v", err)
-			}
-		}()
+			go func() {
+				if err := s.eventuallyShowMessage(context.Background(), msg); err != nil {
+					log.Printf("error showing bug: %v", err)
+				}
+			}()
+		})
 	}
 
 	folders := params.WorkspaceFolders