gopls/internal/test/integration: better expectation failures

A particularly tricky-to-diagnose marker test failure finally led me to
address several long-standing TODOs: integration test expectations
should identify their specific failure reason.

Previously, we had been relying on a combination the State.String
summary and LSP logs to debug failed expectations, but often it was not
obvious from the test failure what condition actually failed. Now,
expectations describe their failure, and composite expectations compose
their component failures.

Change-Id: I2533c8a35b4eb561f505fd3ed95fe55483340773
Reviewed-on: https://go-review.googlesource.com/c/tools/+/651417
Reviewed-by: Alan Donovan <adonovan@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Auto-Submit: Robert Findley <rfindley@google.com>

Author: findleyr

gopls/internal/test/integration/env.go

@@ -114,53 +114,16 @@ type workProgress struct {
 	complete           bool // seen 'end'
 }
 
-// This method, provided for debugging, accesses mutable fields without a lock,
-// so it must not be called concurrent with any State mutation.
-func (s State) String() string {
-	var b strings.Builder
-	b.WriteString("#### log messages (see RPC logs for full text):\n")
-	for _, msg := range s.logs {
-		summary := fmt.Sprintf("%v: %q", msg.Type, msg.Message)
-		if len(summary) > 60 {
-			summary = summary[:57] + "..."
-		}
-		// Some logs are quite long, and since they should be reproduced in the RPC
-		// logs on any failure we include here just a short summary.
-		fmt.Fprint(&b, "\t"+summary+"\n")
-	}
-	b.WriteString("\n")
-	b.WriteString("#### diagnostics:\n")
-	for name, params := range s.diagnostics {
-		fmt.Fprintf(&b, "\t%s (version %d):\n", name, params.Version)
-		for _, d := range params.Diagnostics {
-			fmt.Fprintf(&b, "\t\t%d:%d [%s]: %s\n", d.Range.Start.Line, d.Range.Start.Character, d.Source, d.Message)
-		}
-	}
-	b.WriteString("\n")
-	b.WriteString("#### outstanding work:\n")
-	for token, state := range s.work {
-		if state.complete {
-			continue
-		}
-		name := state.title
-		if name == "" {
-			name = fmt.Sprintf("!NO NAME(token: %s)", token)
-		}
-		fmt.Fprintf(&b, "\t%s: %.2f\n", name, state.percent)
-	}
-	b.WriteString("#### completed work:\n")
-	for name, count := range s.completedWork {
-		fmt.Fprintf(&b, "\t%s: %d\n", name, count)
-	}
-	return b.String()
+type awaitResult struct {
+	verdict Verdict
+	reason  string
 }
 
-// A condition is satisfied when all expectations are simultaneously
-// met. At that point, the 'met' channel is closed. On any failure, err is set
-// and the failed channel is closed.
+// A condition is satisfied when its expectation is [Met] or [Unmeetable]. The
+// result is sent on the verdict channel.
 type condition struct {
-	expectations []Expectation
-	verdict      chan Verdict
+	expectation Expectation
+	verdict     chan awaitResult
 }
 
 func (a *Awaiter) onDiagnostics(_ context.Context, d *protocol.PublishDiagnosticsParams) error {
@@ -334,27 +297,13 @@ func (a *Awaiter) onUnregisterCapability(_ context.Context, m *protocol.Unregist
 
 func (a *Awaiter) checkConditionsLocked() {
 	for id, condition := range a.waiters {
-		if v, _ := checkExpectations(a.state, condition.expectations); v != Unmet {
+		if v, why := condition.expectation.Check(a.state); v != Unmet {
 			delete(a.waiters, id)
-			condition.verdict <- v
+			condition.verdict <- awaitResult{v, why}
 		}
 	}
 }
 
-// checkExpectations reports whether s meets all expectations.
-func checkExpectations(s State, expectations []Expectation) (Verdict, string) {
-	finalVerdict := Met
-	var summary strings.Builder
-	for _, e := range expectations {
-		v := e.Check(s)
-		if v > finalVerdict {
-			finalVerdict = v
-		}
-		fmt.Fprintf(&summary, "%v: %s\n", v, e.Description)
-	}
-	return finalVerdict, summary.String()
-}
-
 // Await blocks until the given expectations are all simultaneously met.
 //
 // Generally speaking Await should be avoided because it blocks indefinitely if
@@ -363,38 +312,38 @@ func checkExpectations(s State, expectations []Expectation) (Verdict, string) {
 // waiting.
 func (e *Env) Await(expectations ...Expectation) {
 	e.T.Helper()
-	if err := e.Awaiter.Await(e.Ctx, expectations...); err != nil {
+	if err := e.Awaiter.Await(e.Ctx, AllOf(expectations...)); err != nil {
 		e.T.Fatal(err)
 	}
 }
 
 // OnceMet blocks until the precondition is met by the state or becomes
 // unmeetable. If it was met, OnceMet checks that the state meets all
 // expectations in mustMeets.
-func (e *Env) OnceMet(precondition Expectation, mustMeets ...Expectation) {
+func (e *Env) OnceMet(pre Expectation, mustMeets ...Expectation) {
 	e.T.Helper()
-	e.Await(OnceMet(precondition, mustMeets...))
+	e.Await(OnceMet(pre, AllOf(mustMeets...)))
 }
 
 // Await waits for all expectations to simultaneously be met. It should only be
 // called from the main test goroutine.
-func (a *Awaiter) Await(ctx context.Context, expectations ...Expectation) error {
+func (a *Awaiter) Await(ctx context.Context, expectation Expectation) error {
 	a.mu.Lock()
 	// Before adding the waiter, we check if the condition is currently met or
 	// failed to avoid a race where the condition was realized before Await was
 	// called.
-	switch verdict, summary := checkExpectations(a.state, expectations); verdict {
+	switch verdict, why := expectation.Check(a.state); verdict {
 	case Met:
 		a.mu.Unlock()
 		return nil
 	case Unmeetable:
-		err := fmt.Errorf("unmeetable expectations:\n%s\nstate:\n%v", summary, a.state)
+		err := fmt.Errorf("unmeetable expectation:\n%s\nreason:\n%s", indent(expectation.Description), indent(why))
 		a.mu.Unlock()
 		return err
 	}
 	cond := &condition{
-		expectations: expectations,
-		verdict:      make(chan Verdict),
+		expectation: expectation,
+		verdict:     make(chan awaitResult),
 	}
 	a.waiters[nextAwaiterRegistration.Add(1)] = cond
 	a.mu.Unlock()
@@ -403,19 +352,17 @@ func (a *Awaiter) Await(ctx context.Context, expectations ...Expectation) error
 	select {
 	case <-ctx.Done():
 		err = ctx.Err()
-	case v := <-cond.verdict:
-		if v != Met {
-			err = fmt.Errorf("condition has final verdict %v", v)
+	case res := <-cond.verdict:
+		if res.verdict != Met {
+			err = fmt.Errorf("the following condition is %s:\n%s\nreason:\n%s",
+				res.verdict, indent(expectation.Description), indent(res.reason))
 		}
 	}
-	a.mu.Lock()
-	defer a.mu.Unlock()
-	_, summary := checkExpectations(a.state, expectations)
+	return err
+}
 
-	// Debugging an unmet expectation can be tricky, so we put some effort into
-	// nicely formatting the failure.
-	if err != nil {
-		return fmt.Errorf("waiting on:\n%s\nerr:%v\n\nstate:\n%v", summary, err, a.state)
-	}
-	return nil
+// indent indents all lines of msg, including the first.
+func indent(msg string) string {
+	const prefix = "  "
+	return prefix + strings.ReplaceAll(msg, "\n", "\n"+prefix)
 }