gopls/internal/test/integration/bench: add an IWL test that opens files

The existing BenchmarkInitialWorkspaceLoad does not open files, which
means it measures only the speed of loading and verifying the workspace
state, with hot caches. It does not measure the memory or time consumed
when starting to actually work on a file.

Fix this by opening a file.

Also, add -profile.block to gopls and -gopls_blockprofile to gopls
benchmarks, for better diagnosis of contention.

Change-Id: I63ef7c9a26ca71ddd9b6895369921655eaa4f090
Reviewed-on: https://go-review.googlesource.com/c/tools/+/614163
LUCI-TryBot-Result: Go LUCI <[email protected]>
Reviewed-by: Alan Donovan <[email protected]>

gopls/internal/cmd/usage/usage-v.hlp

@@ -67,6 +67,8 @@ flags:
     	port on which to run gopls for debugging purposes
   -profile.alloc=string
     	write alloc profile to this file
+  -profile.block=string
+    	write block profile to this file
   -profile.cpu=string
     	write CPU profile to this file
   -profile.mem=string

gopls/internal/cmd/usage/usage.hlp

@@ -64,6 +64,8 @@ flags:
     	port on which to run gopls for debugging purposes
   -profile.alloc=string
     	write alloc profile to this file
+  -profile.block=string
+    	write block profile to this file
   -profile.cpu=string
     	write CPU profile to this file
   -profile.mem=string

gopls/internal/test/integration/bench/bench_test.go

@@ -42,6 +42,7 @@ var (
 	cpuProfile   = flag.String("gopls_cpuprofile", "", "if set, the cpu profile file suffix; see \"Profiling\" in the package doc")
 	memProfile   = flag.String("gopls_memprofile", "", "if set, the mem profile file suffix; see \"Profiling\" in the package doc")
 	allocProfile = flag.String("gopls_allocprofile", "", "if set, the alloc profile file suffix; see \"Profiling\" in the package doc")
+	blockProfile = flag.String("gopls_blockprofile", "", "if set, the block profile file suffix; see \"Profiling\" in the package doc")
 	trace        = flag.String("gopls_trace", "", "if set, the trace file suffix; see \"Profiling\" in the package doc")
 
 	// If non-empty, tempDir is a temporary working dir that was created by this
@@ -177,6 +178,9 @@ func profileArgs(name string, wantCPU bool) []string {
 	if *allocProfile != "" {
 		args = append(args, fmt.Sprintf("-profile.alloc=%s", qualifiedName(name, *allocProfile)))
 	}
+	if *blockProfile != "" {
+		args = append(args, fmt.Sprintf("-profile.block=%s", qualifiedName(name, *blockProfile)))
+	}
 	if *trace != "" {
 		args = append(args, fmt.Sprintf("-profile.trace=%s", qualifiedName(name, *trace)))
 	}

gopls/internal/test/integration/bench/doc.go

@@ -16,8 +16,9 @@
 //
 // Benchmark functions run gopls in a separate process, which means the normal
 // test flags for profiling aren't useful. Instead the -gopls_cpuprofile,
-// -gopls_memprofile, -gopls_allocprofile, and -gopls_trace flags may be used
-// to pass through profiling to the gopls subproces.
+// -gopls_memprofile, -gopls_allocprofile, -gopls_blockprofile, and
+// -gopls_trace flags may be used to pass through profiling to the gopls
+// subproces.
 //
 // Each of these flags sets a suffix for the respective gopls profile, which is
 // named according to the schema <repo>.<operation>.<suffix>. For example,

gopls/internal/test/integration/bench/iwl_test.go

@@ -15,6 +15,11 @@ import (
 
 // BenchmarkInitialWorkspaceLoad benchmarks the initial workspace load time for
 // a new editing session.
+//
+// The OpenFiles variant of this test is more realistic: who cares if gopls is
+// initialized if you can't use it? However, this test is left as is to
+// preserve the validity of historical data, and to represent the baseline
+// performance of validating the workspace state.
 func BenchmarkInitialWorkspaceLoad(b *testing.B) {
 	repoNames := []string{
 		"google-cloud-go",
@@ -37,13 +42,33 @@ func BenchmarkInitialWorkspaceLoad(b *testing.B) {
 			b.ResetTimer()
 
 			for i := 0; i < b.N; i++ {
-				doIWL(b, sharedEnv.Sandbox.GOPATH(), repo)
+				doIWL(b, sharedEnv.Sandbox.GOPATH(), repo, nil)
 			}
 		})
 	}
 }
 
-func doIWL(b *testing.B, gopath string, repo *repo) {
+// BenchmarkInitialWorkspaceLoadOpenFiles benchmarks the initial workspace load
+// after opening one or more files.
+//
+// It may differ significantly from [BenchmarkInitialWorkspaceLoad], since
+// there is various active state that is proportional to the number of open
+// files.
+func BenchmarkInitialWorkspaceLoadOpenFiles(b *testing.B) {
+	for _, t := range didChangeTests {
+		b.Run(t.repo, func(b *testing.B) {
+			repo := getRepo(b, t.repo)
+			sharedEnv := repo.sharedEnv(b)
+			b.ResetTimer()
+
+			for range b.N {
+				doIWL(b, sharedEnv.Sandbox.GOPATH(), repo, []string{t.file})
+			}
+		})
+	}
+}
+
+func doIWL(b *testing.B, gopath string, repo *repo, openfiles []string) {
 	// Exclude the time to set up the env from the benchmark time, as this may
 	// involve installing gopls and/or checking out the repo dir.
 	b.StopTimer()
@@ -52,11 +77,16 @@ func doIWL(b *testing.B, gopath string, repo *repo) {
 	defer env.Close()
 	b.StartTimer()
 
-	// Note: in the future, we may need to open a file in order to cause gopls to
-	// start loading the workspace.
-
+	// TODO(rfindley): not awaiting the IWL here leads to much more volatile
+	// results. Investigate.
 	env.Await(InitialWorkspaceLoad)
 
+	for _, f := range openfiles {
+		env.OpenFile(f)
+	}
+
+	env.AfterChange()
+
 	if env.Editor.HasCommand(command.MemStats) {
 		b.StopTimer()
 		params := &protocol.ExecuteCommandParams{

internal/tool/tool.go

@@ -45,6 +45,7 @@ type Profile struct {
 	Memory string `flag:"profile.mem" help:"write memory profile to this file"`
 	Alloc  string `flag:"profile.alloc" help:"write alloc profile to this file"`
 	Trace  string `flag:"profile.trace" help:"write trace log to this file"`
+	Block  string `flag:"profile.block" help:"write block profile to this file"`
 }
 
 // Application is the interface that must be satisfied by an object passed to Main.
@@ -172,7 +173,9 @@ func Run(ctx context.Context, s *flag.FlagSet, app Application, args []string) (
 			if err := pprof.WriteHeapProfile(f); err != nil {
 				log.Printf("Writing memory profile: %v", err)
 			}
-			f.Close()
+			if err := f.Close(); err != nil {
+				log.Printf("Closing memory profile: %v", err)
+			}
 		}()
 	}
 
@@ -185,7 +188,25 @@ func Run(ctx context.Context, s *flag.FlagSet, app Application, args []string) (
 			if err := pprof.Lookup("allocs").WriteTo(f, 0); err != nil {
 				log.Printf("Writing alloc profile: %v", err)
 			}
-			f.Close()
+			if err := f.Close(); err != nil {
+				log.Printf("Closing alloc profile: %v", err)
+			}
+		}()
+	}
+
+	if p != nil && p.Block != "" {
+		f, err := os.Create(p.Block)
+		if err != nil {
+			return err
+		}
+		runtime.SetBlockProfileRate(1) // record all blocking events
+		defer func() {
+			if err := pprof.Lookup("block").WriteTo(f, 0); err != nil {
+				log.Printf("Writing block profile: %v", err)
+			}
+			if err := f.Close(); err != nil {
+				log.Printf("Closing block profile: %v", err)
+			}
 		}()
 	}