e2e: include more information in pod timeout error

The advantage is that the extra error information is guaranteed to be printed
directly before the failure and we avoid one extra log line that would have to
be correlated with the failure.

test/e2e/framework/pod/wait.go

@@ -25,7 +25,6 @@ import (
 	"time"
 
 	"github.com/onsi/ginkgo"
-	"github.com/onsi/gomega/format"
 
 	v1 "k8s.io/api/core/v1"
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
@@ -67,16 +66,18 @@ const (
 type podCondition func(pod *v1.Pod) (bool, error)
 
 type timeoutError struct {
-	msg string
+	msg             string
+	observedObjects []interface{}
 }
 
 func (e *timeoutError) Error() string {
 	return e.msg
 }
 
-func TimeoutError(format string, args ...interface{}) *timeoutError {
+func TimeoutError(msg string, observedObjects ...interface{}) *timeoutError {
 	return &timeoutError{
-		msg: fmt.Sprintf(format, args...),
+		msg:             msg,
+		observedObjects: observedObjects,
 	}
 }
 
@@ -85,7 +86,7 @@ func TimeoutError(format string, args ...interface{}) *timeoutError {
 // e.g. "waiting for pod to be running".
 func maybeTimeoutError(err error, taskFormat string, taskArgs ...interface{}) error {
 	if IsTimeout(err) {
-		return TimeoutError("timed out while "+taskFormat, taskArgs...)
+		return TimeoutError(fmt.Sprintf("timed out while "+taskFormat, taskArgs...))
 	} else if err != nil {
 		return fmt.Errorf("error while %s: %w", fmt.Sprintf(taskFormat, taskArgs...), err)
 	} else {
@@ -275,9 +276,10 @@ func WaitForPodCondition(c clientset.Interface, ns, podName, conditionDesc strin
 	if err == nil {
 		return nil
 	}
-	if IsTimeout(err) {
+	if IsTimeout(err) && lastPod != nil {
-		e2elog.Logf("Timed out while waiting for pod %s to be %s. Last observed as: %s",
+		return TimeoutError(fmt.Sprintf("timed out while waiting for pod %s to be %s", podIdentifier(ns, podName), conditionDesc),
-			podIdentifier(ns, podName), conditionDesc, format.Object(lastPod, 1))
+			lastPod,
+		)
 	}
 	if lastPodError != nil {
 		// If the last API call was an error.
@@ -494,9 +496,10 @@ func WaitForPodNotFoundInNamespace(c clientset.Interface, podName, ns string, ti
 	if err == nil {
 		return nil
 	}
-	if IsTimeout(err) {
+	if IsTimeout(err) && lastPod != nil {
-		e2elog.Logf("Timed out while waiting for pod %s to be Not Found. Last observed as: %s",
+		return TimeoutError(fmt.Sprintf("timed out while waiting for pod %s to be Not Found", podIdentifier(ns, podName)),
-			podIdentifier(ns, podName), format.Object(lastPod, 1))
+			lastPod,
+		)
 	}
 	return maybeTimeoutError(err, "waiting for pod %s not found", podIdentifier(ns, podName))
 }
@@ -530,8 +533,9 @@ func WaitForPodToDisappear(c clientset.Interface, ns, podName string, label labe
 		return nil
 	}
 	if IsTimeout(err) {
-		e2elog.Logf("Timed out while waiting for pod %s to disappear. Last observed as: %s",
+		return TimeoutError(fmt.Sprintf("timed out while waiting for pod %s to disappear", podIdentifier(ns, podName)),
-			podIdentifier(ns, podName), format.Object(lastPod, 1))
+			lastPod,
+		)
 	}
 	return maybeTimeoutError(err, "waiting for pod %s to disappear", podIdentifier(ns, podName))
 }

test/e2e/framework/pod/wait_test.go

@@ -81,7 +81,6 @@ INFO: Ignoring NotFound error while getting pod default/no-such-pod
 INFO: Ignoring NotFound error while getting pod default/no-such-pod
 INFO: Ignoring NotFound error while getting pod default/no-such-pod
 INFO: Ignoring NotFound error while getting pod default/no-such-pod
-INFO: Timed out while waiting for pod default/no-such-pod to be running. Last observed as:     <*v1.Pod>: nil
 INFO: Unexpected error: 
     <*fmt.wrapError>: {
         msg: "error while waiting for pod default/no-such-pod to be running: pods \"no-such-pod\" not found",
@@ -125,84 +124,86 @@ INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: <elapsed
 INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: <elapsed>
 INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: <elapsed>
 INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: <elapsed>
-INFO: Timed out while waiting for pod default/pending-pod to be running. Last observed as:     <*v1.Pod>: {
-        TypeMeta: {Kind: "", APIVersion: ""},
-        ObjectMeta: {
-            Name: "pending-pod",
-            GenerateName: "",
-            Namespace: "default",
-            SelfLink: "",
-            UID: "",
-            ResourceVersion: "",
-            Generation: 0,
-            CreationTimestamp: {
-                Time: 0001-01-01T00:00:00Z,
-            },
-            DeletionTimestamp: nil,
-            DeletionGracePeriodSeconds: nil,
-            Labels: nil,
-            Annotations: nil,
-            OwnerReferences: nil,
-            Finalizers: nil,
-            ManagedFields: nil,
-        },
-        Spec: {
-            Volumes: nil,
-            InitContainers: nil,
-            Containers: nil,
-            EphemeralContainers: nil,
-            RestartPolicy: "",
-            TerminationGracePeriodSeconds: nil,
-            ActiveDeadlineSeconds: nil,
-            DNSPolicy: "",
-            NodeSelector: nil,
-            ServiceAccountName: "",
-            DeprecatedServiceAccount: "",
-            AutomountServiceAccountToken: nil,
-            NodeName: "",
-            HostNetwork: false,
-            HostPID: false,
-            HostIPC: false,
-            ShareProcessNamespace: nil,
-            SecurityContext: nil,
-            ImagePullSecrets: nil,
-            Hostname: "",
-            Subdomain: "",
-            Affinity: nil,
-            SchedulerName: "",
-            Tolerations: nil,
-            HostAliases: nil,
-            PriorityClassName: "",
-            Priority: nil,
-            DNSConfig: nil,
-            ReadinessGates: nil,
-            RuntimeClassName: nil,
-            EnableServiceLinks: nil,
-            PreemptionPolicy: nil,
-            Overhead: nil,
-            TopologySpreadConstraints: nil,
-            SetHostnameAsFQDN: nil,
-            OS: nil,
-        },
-        Status: {
-            Phase: "",
-            Conditions: nil,
-            Message: "",
-            Reason: "",
-            NominatedNodeName: "",
-            HostIP: "",
-            PodIP: "",
-            PodIPs: nil,
-            StartTime: nil,
-            InitContainerStatuses: nil,
-            ContainerStatuses: nil,
-            QOSClass: "",
-            EphemeralContainerStatuses: nil,
-        },
-    }
 INFO: Unexpected error: wait for pod pending-pod running: 
     <*pod.timeoutError>: {
         msg: "timed out while waiting for pod default/pending-pod to be running",
+        observedObjects: [
+            {
+                TypeMeta: {Kind: "", APIVersion: ""},
+                ObjectMeta: {
+                    Name: "pending-pod",
+                    GenerateName: "",
+                    Namespace: "default",
+                    SelfLink: "",
+                    UID: "",
+                    ResourceVersion: "",
+                    Generation: 0,
+                    CreationTimestamp: {
+                        Time: {wall: 0, ext: 0, loc: nil},
+                    },
+                    DeletionTimestamp: nil,
+                    DeletionGracePeriodSeconds: nil,
+                    Labels: nil,
+                    Annotations: nil,
+                    OwnerReferences: nil,
+                    Finalizers: nil,
+                    ManagedFields: nil,
+                },
+                Spec: {
+                    Volumes: nil,
+                    InitContainers: nil,
+                    Containers: nil,
+                    EphemeralContainers: nil,
+                    RestartPolicy: "",
+                    TerminationGracePeriodSeconds: nil,
+                    ActiveDeadlineSeconds: nil,
+                    DNSPolicy: "",
+                    NodeSelector: nil,
+                    ServiceAccountName: "",
+                    DeprecatedServiceAccount: "",
+                    AutomountServiceAccountToken: nil,
+                    NodeName: "",
+                    HostNetwork: false,
+                    HostPID: false,
+                    HostIPC: false,
+                    ShareProcessNamespace: nil,
+                    SecurityContext: nil,
+                    ImagePullSecrets: nil,
+                    Hostname: "",
+                    Subdomain: "",
+                    Affinity: nil,
+                    SchedulerName: "",
+                    Tolerations: nil,
+                    HostAliases: nil,
+                    PriorityClassName: "",
+                    Priority: nil,
+                    DNSConfig: nil,
+                    ReadinessGates: nil,
+                    RuntimeClassName: nil,
+                    EnableServiceLinks: nil,
+                    PreemptionPolicy: nil,
+                    Overhead: nil,
+                    TopologySpreadConstraints: nil,
+                    SetHostnameAsFQDN: nil,
+                    OS: nil,
+                },
+                Status: {
+                    Phase: "",
+                    Conditions: nil,
+                    Message: "",
+                    Reason: "",
+                    NominatedNodeName: "",
+                    HostIP: "",
+                    PodIP: "",
+                    PodIPs: nil,
+                    StartTime: nil,
+                    InitContainerStatuses: nil,
+                    ContainerStatuses: nil,
+                    QOSClass: "",
+                    EphemeralContainerStatuses: nil,
+                },
+            },
+        ],
     }
 FAIL: wait for pod pending-pod running: timed out while waiting for pod default/pending-pod to be running