From 2b299526b24e6e50163ace169441d633b8838ca0 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Thu, 5 May 2022 16:38:02 +0200 Subject: [PATCH] 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 | 30 +++--- test/e2e/framework/pod/wait_test.go | 153 ++++++++++++++-------------- 2 files changed, 94 insertions(+), 89 deletions(-) diff --git a/test/e2e/framework/pod/wait.go b/test/e2e/framework/pod/wait.go index f3ebc56a922..ccdaa3d2d5c 100644 --- a/test/e2e/framework/pod/wait.go +++ b/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) { - e2elog.Logf("Timed out while waiting for pod %s to be %s. Last observed as: %s", - podIdentifier(ns, podName), conditionDesc, format.Object(lastPod, 1)) + if IsTimeout(err) && lastPod != nil { + return TimeoutError(fmt.Sprintf("timed out while waiting for pod %s to be %s", podIdentifier(ns, podName), conditionDesc), + 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) { - e2elog.Logf("Timed out while waiting for pod %s to be Not Found. Last observed as: %s", - podIdentifier(ns, podName), format.Object(lastPod, 1)) + if IsTimeout(err) && lastPod != nil { + return TimeoutError(fmt.Sprintf("timed out while waiting for pod %s to be Not Found", podIdentifier(ns, podName)), + 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", - podIdentifier(ns, podName), format.Object(lastPod, 1)) + return TimeoutError(fmt.Sprintf("timed out while waiting for pod %s to disappear", podIdentifier(ns, podName)), + lastPod, + ) } return maybeTimeoutError(err, "waiting for pod %s to disappear", podIdentifier(ns, podName)) } diff --git a/test/e2e/framework/pod/wait_test.go b/test/e2e/framework/pod/wait_test.go index 9e21dccfe9e..99b8d8e25c6 100644 --- a/test/e2e/framework/pod/wait_test.go +++ b/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: INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. 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