internal/lsp/regtest: add a benchmark for didChange

Add a benchmark for the processing of workspace/didChange notifications,
attempting to isolate the synchronous change processing from
asynchronous diagnostics. To enable this, add a new type of expectation
that asserts on work that has been _started_, but not necessarily
completed. Of course, what we really want to know is whether the current
notification has been processed, but that's ~equivalent to knowing
whether the next one has been started. Really, it's off-by-one, but
amortized over e.g. the 100 iterations of a benchmark we get
approximately the right results.

Also change some functions to accept testing.TB, because in a first pass
at this I modified the regtest framework to operate on testing.B in
addition to testing.T... but that didn't work out as IWL is just too
slow to execute the benchmarks outside of the environment -- even though
we can ResetTimer, the benchmark execution is just too slow to be
usable. It seems like a fine change to accept testing.TB is some places,
though.

For golang/go#45686

Change-Id: I8894444b01177dc947bbed56ec7df80a15a2eae9
Reviewed-on: https://go-review.googlesource.com/c/tools/+/317292
Trust: Robert Findley <[email protected]>
Run-TryBot: Robert Findley <[email protected]>
gopls-CI: kokoro <[email protected]>
TryBot-Result: Go Bot <[email protected]>
Reviewed-by: Rebecca Stambler <[email protected]>

gopls/internal/regtest/bench/bench_test.go

@@ -8,8 +8,10 @@ import (
 	"flag"
 	"fmt"
 	"testing"
+	"time"
 
 	"golang.org/x/tools/gopls/internal/hooks"
+	"golang.org/x/tools/internal/lsp/fake"
 	. "golang.org/x/tools/internal/lsp/regtest"
 
 	"golang.org/x/tools/internal/lsp/protocol"
@@ -19,6 +21,24 @@ func TestMain(m *testing.M) {
 	Main(m, hooks.Options)
 }
 
+func benchmarkOptions(dir string) []RunOption {
+	return []RunOption{
+		// Run in an existing directory, since we're trying to simulate known cases
+		// that cause gopls memory problems.
+		InExistingDir(dir),
+		// Skip logs as they buffer up memory unnaturally.
+		SkipLogs(),
+		// The Debug server only makes sense if running in singleton mode.
+		Modes(Singleton),
+		// Set a generous timeout. Individual tests should control their own
+		// graceful termination.
+		Timeout(20 * time.Minute),
+
+		// Use the actual proxy, since we want our builds to succeed.
+		GOPROXY("https://proxy.golang.org"),
+	}
+}
+
 func printBenchmarkResults(result testing.BenchmarkResult) {
 	fmt.Println("Benchmark Statistics:")
 	fmt.Println(result.String())
@@ -109,3 +129,51 @@ func TestBenchmarkSymbols(t *testing.T) {
 		printBenchmarkResults(results)
 	})
 }
+
+var (
+	benchDir  = flag.String("didchange_dir", "", "If set, run benchmarks in this dir. Must also set regtest_bench_file.")
+	benchFile = flag.String("didchange_file", "", "The file to modify")
+)
+
+// TestBenchmarkDidChange benchmarks modifications of a single file by making
+// synthetic modifications in a comment. It controls pacing by waiting for the
+// server to actually start processing the didChange notification before
+// proceeding. Notably it does not wait for diagnostics to complete.
+//
+// Run it by passing -didchange_dir and -didchange_file, where -didchange_dir
+// is the path to a workspace root, and -didchange_file is the
+// workspace-relative path to a file to modify. e.g.:
+//
+//  go test -run=TestBenchmarkDidChange \
+//   -didchange_dir=path/to/kubernetes \
+//   -didchange_file=pkg/util/hash/hash.go
+func TestBenchmarkDidChange(t *testing.T) {
+	if *benchDir == "" {
+		t.Skip("-didchange_dir is not set")
+	}
+	if *benchFile == "" {
+		t.Fatal("-didchange_file must be set if -didchange_dir is set")
+	}
+
+	opts := benchmarkOptions(*benchDir)
+	WithOptions(opts...).Run(t, "", func(_ *testing.T, env *Env) {
+		env.OpenFile(*benchFile)
+		env.Await(env.DoneWithOpen())
+		// Insert the text we'll be modifying at the top of the file.
+		env.EditBuffer(*benchFile, fake.Edit{Text: "// __REGTEST_PLACEHOLDER_0__\n"})
+		result := testing.Benchmark(func(b *testing.B) {
+			b.ResetTimer()
+			for i := 0; i < b.N; i++ {
+				env.EditBuffer(*benchFile, fake.Edit{
+					Start: fake.Pos{Line: 0, Column: 0},
+					End:   fake.Pos{Line: 1, Column: 0},
+					// Increment
+					Text: fmt.Sprintf("// __REGTEST_PLACEHOLDER_%d__\n", i+1),
+				})
+				env.Await(StartedChange(uint64(i + 1)))
+			}
+			b.StopTimer()
+		})
+		printBenchmarkResults(result)
+	})
+}

gopls/internal/regtest/bench/stress_test.go

@@ -23,27 +23,9 @@ var pilosaPath = flag.String("pilosa_path", "", "Path to a directory containing
 	"know what you're doing!")
 
 func stressTestOptions(dir string) []RunOption {
-	return []RunOption{
-		// Run in an existing directory, since we're trying to simulate known cases
-		// that cause gopls memory problems.
-		InExistingDir(dir),
-
-		// Enable live debugging.
-		DebugAddress(":8087"),
-
-		// Skip logs as they buffer up memory unnaturally.
-		SkipLogs(),
-		// Similarly to logs: disable hooks so that they don't affect performance.
-		SkipHooks(true),
-		// The Debug server only makes sense if running in singleton mode.
-		Modes(Singleton),
-		// Set a generous timeout. Individual tests should control their own
-		// graceful termination.
-		Timeout(20 * time.Minute),
-
-		// Use the actual proxy, since we want our builds to succeed.
-		GOPROXY("https://proxy.golang.org"),
-	}
+	opts := benchmarkOptions(dir)
+	opts = append(opts, SkipHooks(true), DebugAddress(":8087"))
+	return opts
 }
 
 func TestPilosaStress(t *testing.T) {
@@ -52,7 +34,7 @@ func TestPilosaStress(t *testing.T) {
 	}
 	opts := stressTestOptions(*pilosaPath)
 
-	WithOptions(opts...).Run(t, "", func(t *testing.T, env *Env) {
+	WithOptions(opts...).Run(t, "", func(_ *testing.T, env *Env) {
 		files := []string{
 			"cmd.go",
 			"internal/private.pb.go",

gopls/internal/regtest/diagnostics/diagnostics_test.go

@@ -301,7 +301,7 @@ func Hello() {
 			env.Await(
 				env.DiagnosticAtRegexp("main.go", `"mod.com/bob"`),
 			)
-			if err := env.Sandbox.RunGoCommand(env.Ctx, "", "mod", []string{"init", "mod.com"}); err != nil {
+			if err := env.Sandbox.RunGoCommand(env.Ctx, "", "mod", []string{"init", "mod.com"}, true); err != nil {
 				t.Fatal(err)
 			}
 			env.Await(

gopls/internal/regtest/watch/watch_test.go

@@ -627,7 +627,7 @@ func main() {
 	).Run(t, files, func(t *testing.T, env *Env) {
 		env.OpenFile("foo/main.go")
 		env.Await(env.DiagnosticAtRegexp("foo/main.go", `"blah"`))
-		if err := env.Sandbox.RunGoCommand(env.Ctx, "foo", "mod", []string{"init", "mod.com"}); err != nil {
+		if err := env.Sandbox.RunGoCommand(env.Ctx, "foo", "mod", []string{"init", "mod.com"}, true); err != nil {
 			t.Fatal(err)
 		}
 		env.RegexpReplace("foo/main.go", `"blah"`, `"mod.com/blah"`)

internal/lsp/fake/sandbox.go

@@ -221,8 +221,10 @@ func (sb *Sandbox) GoEnv() map[string]string {
 	return vars
 }
 
-// RunGoCommand executes a go command in the sandbox.
-func (sb *Sandbox) RunGoCommand(ctx context.Context, dir, verb string, args []string) error {
+// RunGoCommand executes a go command in the sandbox. If checkForFileChanges is
+// true, the sandbox scans the working directory and emits file change events
+// for any file changes it finds.
+func (sb *Sandbox) RunGoCommand(ctx context.Context, dir, verb string, args []string, checkForFileChanges bool) error {
 	var vars []string
 	for k, v := range sb.GoEnv() {
 		vars = append(vars, fmt.Sprintf("%s=%s", k, v))
@@ -248,7 +250,10 @@ func (sb *Sandbox) RunGoCommand(ctx context.Context, dir, verb string, args []st
 	}
 	// Since running a go command may result in changes to workspace files,
 	// check if we need to send any any "watched" file events.
-	if sb.Workdir != nil {
+	//
+	// TODO(rFindley): this side-effect can impact the usability of the sandbox
+	//                 for benchmarks. Consider refactoring.
+	if sb.Workdir != nil && checkForFileChanges {
 		if err := sb.Workdir.CheckForFileChanges(ctx); err != nil {
 			return errors.Errorf("checking for file changes: %w", err)
 		}
@@ -260,7 +265,7 @@ func (sb *Sandbox) RunGoCommand(ctx context.Context, dir, verb string, args []st
 func (sb *Sandbox) Close() error {
 	var goCleanErr error
 	if sb.gopath != "" {
-		goCleanErr = sb.RunGoCommand(context.Background(), "", "clean", []string{"-modcache"})
+		goCleanErr = sb.RunGoCommand(context.Background(), "", "clean", []string{"-modcache"}, false)
 	}
 	err := os.RemoveAll(sb.rootdir)
 	if err != nil || goCleanErr != nil {

internal/lsp/regtest/env.go

@@ -21,7 +21,7 @@ import (
 // on any error, so that tests for the happy path may be written without
 // checking errors.
 type Env struct {
-	T   *testing.T
+	T   testing.TB
 	Ctx context.Context
 
 	// Most tests should not need to access the scratch area, editor, server, or
@@ -54,6 +54,7 @@ type State struct {
 	// be string, though the spec allows for numeric tokens as well.  When work
 	// completes, it is deleted from this map.
 	outstandingWork map[protocol.ProgressToken]*workProgress
+	startedWork     map[string]uint64
 	completedWork   map[string]uint64
 }
 
@@ -108,17 +109,18 @@ type condition struct {
 
 // NewEnv creates a new test environment using the given scratch environment
 // and gopls server.
-func NewEnv(ctx context.Context, t *testing.T, sandbox *fake.Sandbox, ts servertest.Connector, editorConfig fake.EditorConfig, withHooks bool) *Env {
-	t.Helper()
+func NewEnv(ctx context.Context, tb testing.TB, sandbox *fake.Sandbox, ts servertest.Connector, editorConfig fake.EditorConfig, withHooks bool) *Env {
+	tb.Helper()
 	conn := ts.Connect(ctx)
 	env := &Env{
-		T:       t,
+		T:       tb,
 		Ctx:     ctx,
 		Sandbox: sandbox,
 		Server:  ts,
 		state: State{
 			diagnostics:     make(map[string]*protocol.PublishDiagnosticsParams),
 			outstandingWork: make(map[protocol.ProgressToken]*workProgress),
+			startedWork:     make(map[string]uint64),
 			completedWork:   make(map[string]uint64),
 		},
 		waiters: make(map[int]*condition),
@@ -138,7 +140,7 @@ func NewEnv(ctx context.Context, t *testing.T, sandbox *fake.Sandbox, ts servert
 	}
 	editor, err := fake.NewEditor(sandbox, editorConfig).Connect(ctx, conn, hooks)
 	if err != nil {
-		t.Fatal(err)
+		tb.Fatal(err)
 	}
 	env.Editor = editor
 	return env
@@ -200,6 +202,7 @@ func (e *Env) onProgress(_ context.Context, m *protocol.ProgressParams) error {
 	switch kind := v["kind"]; kind {
 	case "begin":
 		work.title = v["title"].(string)
+		e.state.startedWork[work.title] = e.state.startedWork[work.title] + 1
 		if msg, ok := v["message"]; ok {
 			work.msg = msg.(string)
 		}

internal/lsp/regtest/env_test.go

@@ -16,6 +16,7 @@ func TestProgressUpdating(t *testing.T) {
 	e := &Env{
 		state: State{
 			outstandingWork: make(map[protocol.ProgressToken]*workProgress),
+			startedWork:     make(map[string]uint64),
 			completedWork:   make(map[string]uint64),
 		},
 	}

internal/lsp/regtest/expectation.go

@@ -193,6 +193,12 @@ func (e *Env) DoneWithOpen() Expectation {
 	return CompletedWork(lsp.DiagnosticWorkTitle(lsp.FromDidOpen), opens)
 }
 
+// StartedChange expects there to have been i work items started for
+// processing didChange notifications.
+func StartedChange(i uint64) Expectation {
+	return StartedWork(lsp.DiagnosticWorkTitle(lsp.FromDidChange), i)
+}
+
 // DoneWithChange expects all didChange notifications currently sent by the
 // editor to be completely processed.
 func (e *Env) DoneWithChange() Expectation {
@@ -221,6 +227,22 @@ func (e *Env) DoneWithClose() Expectation {
 	return CompletedWork(lsp.DiagnosticWorkTitle(lsp.FromDidClose), changes)
 }
 
+// StartedWork expect a work item to have been started >= atLeast times.
+//
+// See CompletedWork.
+func StartedWork(title string, atLeast uint64) SimpleExpectation {
+	check := func(s State) Verdict {
+		if s.startedWork[title] >= atLeast {
+			return Met
+		}
+		return Unmet
+	}
+	return SimpleExpectation{
+		check:       check,
+		description: fmt.Sprintf("started work %q at least %d time(s)", title, atLeast),
+	}
+}
+
 // CompletedWork expects a work item to have been completed >= atLeast times.
 //
 // Since the Progress API doesn't include any hidden metadata, we must use the

internal/lsp/regtest/wrappers.go

@@ -247,7 +247,7 @@ func (e *Env) DocumentHighlight(name string, pos fake.Pos) []protocol.DocumentHi
 	return highlights
 }
 
-func checkIsFatal(t *testing.T, err error) {
+func checkIsFatal(t testing.TB, err error) {
 	t.Helper()
 	if err != nil && !errors.Is(err, io.EOF) && !errors.Is(err, io.ErrClosedPipe) {
 		t.Fatal(err)
@@ -279,7 +279,7 @@ func (e *Env) RunGenerate(dir string) {
 // directory.
 func (e *Env) RunGoCommand(verb string, args ...string) {
 	e.T.Helper()
-	if err := e.Sandbox.RunGoCommand(e.Ctx, "", verb, args); err != nil {
+	if err := e.Sandbox.RunGoCommand(e.Ctx, "", verb, args, true); err != nil {
 		e.T.Fatal(err)
 	}
 }
@@ -288,7 +288,7 @@ func (e *Env) RunGoCommand(verb string, args ...string) {
 // relative directory of the sandbox.
 func (e *Env) RunGoCommandInDir(dir, verb string, args ...string) {
 	e.T.Helper()
-	if err := e.Sandbox.RunGoCommand(e.Ctx, dir, verb, args); err != nil {
+	if err := e.Sandbox.RunGoCommand(e.Ctx, dir, verb, args, true); err != nil {
 		e.T.Fatal(err)
 	}
 }
@@ -298,7 +298,7 @@ func (e *Env) RunGoCommandInDir(dir, verb string, args ...string) {
 func (e *Env) DumpGoSum(dir string) {
 	e.T.Helper()
 
-	if err := e.Sandbox.RunGoCommand(e.Ctx, dir, "list", []string{"-mod=mod", "..."}); err != nil {
+	if err := e.Sandbox.RunGoCommand(e.Ctx, dir, "list", []string{"-mod=mod", "..."}, true); err != nil {
 		e.T.Fatal(err)
 	}
 	sumFile := path.Join(dir, "/go.sum")