When a polled function returns an error, keep track of the actual and report on the matcher state of the last non-errored actual

...also, improve failure reporting across the board for Eventually and Eventually(f(g Gomega)).Should(Succeed())

Author: onsi

internal/async_assertion.go

@@ -2,6 +2,7 @@ package internal
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"reflect"
 	"runtime"
@@ -16,6 +17,22 @@ var errInterface = reflect.TypeOf((*error)(nil)).Elem()
 var gomegaType = reflect.TypeOf((*types.Gomega)(nil)).Elem()
 var contextType = reflect.TypeOf(new(context.Context)).Elem()
 
+type formattedGomegaError interface {
+	FormattedGomegaError() string
+}
+
+type asyncPolledActualError struct {
+	message string
+}
+
+func (err *asyncPolledActualError) Error() string {
+	return err.message
+}
+
+func (err *asyncPolledActualError) FormattedGomegaError() string {
+	return err.message
+}
+
 type contextWithAttachProgressReporter interface {
 	AttachProgressReporter(func() string) func()
 }
@@ -148,7 +165,9 @@ func (assertion *AsyncAssertion) buildDescription(optionalDescription ...interfa
 
 func (assertion *AsyncAssertion) processReturnValues(values []reflect.Value) (interface{}, error) {
 	if len(values) == 0 {
-		return nil, fmt.Errorf("No values were returned by the function passed to Gomega")
+		return nil, &asyncPolledActualError{
+			message: fmt.Sprintf("The function passed to %s did not return any values", assertion.asyncType),
+		}
 	}
 
 	actual := values[0].Interface()
@@ -171,10 +190,12 @@ func (assertion *AsyncAssertion) processReturnValues(values []reflect.Value) (in
 			continue
 		}
 		if i == len(values)-2 && extraType.Implements(errInterface) {
-			err = fmt.Errorf("function returned error: %w", extra.(error))
+			err = extra.(error)
 		}
 		if err == nil {
-			err = fmt.Errorf("Unexpected non-nil/non-zero return value at index %d:\n\t<%T>: %#v", i+1, extra, extra)
+			err = &asyncPolledActualError{
+				message: fmt.Sprintf("The function passed to %s had an unexpected non-nil/non-zero return value at index %d:\n%s", assertion.asyncType, i+1, format.Object(extra, 1)),
+			}
 		}
 	}
 
@@ -253,7 +274,9 @@ func (assertion *AsyncAssertion) buildActualPoller() (func() (interface{}, error
 				skip = callerSkip[0]
 			}
 			_, file, line, _ := runtime.Caller(skip + 1)
-			assertionFailure = fmt.Errorf("Assertion in callback at %s:%d failed:\n%s", file, line, message)
+			assertionFailure = &asyncPolledActualError{
+				message: fmt.Sprintf("The function passed to %s failed at %s:%d with:\n%s", assertion.asyncType, file, line, message),
+			}
 			// we throw an asyncGomegaHaltExecutionError so that defer GinkgoRecover() can catch this error if the user makes an assertion in a goroutine
 			panic(asyncGomegaHaltExecutionError{})
 		})))
@@ -359,46 +382,85 @@ func (assertion *AsyncAssertion) match(matcher types.GomegaMatcher, desiredMatch
 	timeout := assertion.afterTimeout()
 	lock := sync.Mutex{}
 
-	var matches bool
-	var err error
+	var matches, hasLastValidActual bool
+	var actual, lastValidActual interface{}
+	var actualErr, matcherErr error
 	var oracleMatcherSaysStop bool
 
 	assertion.g.THelper()
 
-	pollActual, err := assertion.buildActualPoller()
-	if err != nil {
-		assertion.g.Fail(err.Error(), 2+assertion.offset)
+	pollActual, buildActualPollerErr := assertion.buildActualPoller()
+	if buildActualPollerErr != nil {
+		assertion.g.Fail(buildActualPollerErr.Error(), 2+assertion.offset)
 		return false
 	}
 
-	value, err := pollActual()
-	if err == nil {
-		oracleMatcherSaysStop = assertion.matcherSaysStopTrying(matcher, value)
-		matches, err = assertion.pollMatcher(matcher, value)
+	actual, actualErr = pollActual()
+	if actualErr == nil {
+		lastValidActual = actual
+		hasLastValidActual = true
+		oracleMatcherSaysStop = assertion.matcherSaysStopTrying(matcher, actual)
+		matches, matcherErr = assertion.pollMatcher(matcher, actual)
+	}
+
+	renderError := func(preamble string, err error) string {
+		message := ""
+		if pollingSignalErr, ok := AsPollingSignalError(err); ok {
+			message = err.Error()
+			for _, attachment := range pollingSignalErr.Attachments {
+				message += fmt.Sprintf("\n%s:\n", attachment.Description)
+				message += format.Object(attachment.Object, 1)
+			}
+		} else {
+			message = preamble + "\n" + err.Error() + "\n" + format.Object(err, 1)
+		}
+		return message
 	}
 
 	messageGenerator := func() string {
 		// can be called out of band by Ginkgo if the user requests a progress report
 		lock.Lock()
 		defer lock.Unlock()
 		message := ""
-		if err != nil {
-			if pollingSignalErr, ok := AsPollingSignalError(err); ok && pollingSignalErr.IsStopTrying() {
-				message = err.Error()
-				for _, attachment := range pollingSignalErr.Attachments {
-					message += fmt.Sprintf("\n%s:\n", attachment.Description)
-					message += format.Object(attachment.Object, 1)
+
+		if actualErr == nil {
+			if matcherErr == nil {
+				if desiredMatch {
+					message += matcher.FailureMessage(actual)
+				} else {
+					message += matcher.NegatedFailureMessage(actual)
 				}
 			} else {
-				message = "Error: " + err.Error() + "\n" + format.Object(err, 1)
+				var fgErr formattedGomegaError
+				if errors.As(actualErr, &fgErr) {
+					message += fgErr.FormattedGomegaError() + "\n"
+				} else {
+					message += renderError(fmt.Sprintf("The matcher passed to %s returned the following error:", assertion.asyncType), matcherErr)
+				}
 			}
 		} else {
-			if desiredMatch {
-				message = matcher.FailureMessage(value)
+			var fgErr formattedGomegaError
+			if errors.As(actualErr, &fgErr) {
+				message += fgErr.FormattedGomegaError() + "\n"
 			} else {
-				message = matcher.NegatedFailureMessage(value)
+				message += renderError(fmt.Sprintf("The function passed to %s returned the following error:", assertion.asyncType), actualErr)
+			}
+			if hasLastValidActual {
+				message += fmt.Sprintf("\nAt one point, however, the function did return successfully.  But %s failed because", assertion.asyncType)
+				_, e := matcher.Match(lastValidActual)
+				if e != nil {
+					message += renderError(" the matcher returned the following error:", e)
+				} else {
+					message += " the matcher was not satisfied:\n"
+					if desiredMatch {
+						message += matcher.FailureMessage(lastValidActual)
+					} else {
+						message += matcher.NegatedFailureMessage(lastValidActual)
+					}
+				}
 			}
 		}
+
 		description := assertion.buildDescription(optionalDescription...)
 		return fmt.Sprintf("%s%s", description, message)
 	}
@@ -423,18 +485,20 @@ func (assertion *AsyncAssertion) match(matcher types.GomegaMatcher, desiredMatch
 		var nextPoll <-chan time.Time = nil
 		var isTryAgainAfterError = false
 
-		if pollingSignalErr, ok := AsPollingSignalError(err); ok {
-			if pollingSignalErr.IsStopTrying() {
-				fail("Told to stop trying")
-				return false
-			}
-			if pollingSignalErr.IsTryAgainAfter() {
-				nextPoll = time.After(pollingSignalErr.TryAgainDuration())
-				isTryAgainAfterError = true
+		for _, err := range []error{actualErr, matcherErr} {
+			if pollingSignalErr, ok := AsPollingSignalError(err); ok {
+				if pollingSignalErr.IsStopTrying() {
+					fail("Told to stop trying")
+					return false
+				}
+				if pollingSignalErr.IsTryAgainAfter() {
+					nextPoll = time.After(pollingSignalErr.TryAgainDuration())
+					isTryAgainAfterError = true
+				}
 			}
 		}
 
-		if err == nil && matches == desiredMatch {
+		if actualErr == nil && matcherErr == nil && matches == desiredMatch {
 			if assertion.asyncType == AsyncAssertionTypeEventually {
 				passedRepeatedlyCount += 1
 				if passedRepeatedlyCount == assertion.mustPassRepeatedly {
@@ -465,15 +529,19 @@ func (assertion *AsyncAssertion) match(matcher types.GomegaMatcher, desiredMatch
 
 		select {
 		case <-nextPoll:
-			v, e := pollActual()
+			a, e := pollActual()
 			lock.Lock()
-			value, err = v, e
+			actual, actualErr = a, e
 			lock.Unlock()
-			if err == nil {
-				oracleMatcherSaysStop = assertion.matcherSaysStopTrying(matcher, value)
-				m, e := assertion.pollMatcher(matcher, value)
+			if actualErr == nil {
+				lock.Lock()
+				lastValidActual = actual
+				hasLastValidActual = true
+				lock.Unlock()
+				oracleMatcherSaysStop = assertion.matcherSaysStopTrying(matcher, actual)
+				m, e := assertion.pollMatcher(matcher, actual)
 				lock.Lock()
-				matches, err = m, e
+				matches, matcherErr = m, e
 				lock.Unlock()
 			}
 		case <-contextDone: