Skip to content
This repository was archived by the owner on Feb 13, 2026. It is now read-only.

Commit f96ffb0

Browse files
FrawlessFrawless
authored
Try to not log useless null messages in the log when timeout exception occurs (#309)
## Description I found that there is a lot of null messages in the log when wait hits timeout exceptions: ``` 2025-07-08 14:07:00 [T-39] INFO [Wait:66] Waiting for: Resource condition: readiness to be fulfilled for resource KafkaConnect/cluster-05f11c30 2025-07-08 14:17:05 [T-39] ERROR [Wait:106] Exception waiting for: Resource condition: readiness to be fulfilled for resource KafkaConnect/cluster-05f11c30, null 2025-07-08 14:20:14 [T-39] ERROR [Wait:116] Timeout after 600000 ms waiting for Resource condition: readiness to be fulfilled for resource KafkaConnect/cluster-05f11c30 io.skodjob.testframe.wait.WaitException: Timeout after 600000 ms waiting for Resource condition: readiness to be fulfilled for resource KafkaConnect/cluster-05f11c30 at io.skodjob.testframe.wait.Wait.until(Wait.java:114) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.wait.Wait.until(Wait.java:45) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.waitResourceCondition(KubeResourceManager.java:753) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.lambda$createOrUpdateResource$18(KubeResourceManager.java:512) ~[test-frame-common-1.0.0.jar:?] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) [?:?] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1796) [?:?] at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) [?:?] at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) [?:?] at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) [?:?] at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) [?:?] at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) [?:?] 2025-07-08 14:21:44 [T-1] ERROR [TestExecutionWatcher:22] ConnectST - Exception io.skodjob.testframe.wait.WaitException: Timeout after 600000 ms waiting for Resource condition: readiness to be fulfilled for resource KafkaConnect/cluster-05f11c30 has been thrown in @test. Going to collect logs from components. 2025-07-08 14:26:35 [T-1] INFO [LoggerUtils:50] ############################################################################ 2025-07-08 14:26:35 [T-1] INFO [KubeResourceManager:786] Deleting all resources for [default]/testKafkaConnectAndConnectorStateWithFileSinkPlugin 2025-07-08 14:26:35 [T-73] INFO [LoggerUtils:78] Deleting KafkaConnect/cluster-05f11c30 in namespace-0 2025-07-08 14:26:35 [T-74] INFO [LoggerUtils:78] Deleting KafkaTopic/my-topic-2008554969-992432800 in namespace-0 2025-07-08 14:26:35 [T-75] INFO [LoggerUtils:78] Deleting Kafka/cluster-05f11c30 in namespace-0 2025-07-08 14:27:12 [T-79] INFO [LoggerUtils:78] Deleting KafkaNodePool/c-0087150f in namespace-0 2025-07-08 14:27:54 [T-75] ERROR [KubeResourceManager:615] null io.fabric8.kubernetes.client.KubernetesClientException: null at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.waitForResult(OperationSupport.java:509) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handleResponse(OperationSupport.java:524) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handleGet(OperationSupport.java:467) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.handleGet(BaseOperation.java:792) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.requireFromServer(BaseOperation.java:193) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.get(BaseOperation.java:149) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.get(BaseOperation.java:98) ~[kubernetes-client-7.3.1.jar:?] at io.strimzi.systemtest.resources.types.KafkaType.delete(KafkaType.java:92) ~[systemtest-0.47.0-SNAPSHOT.jar:0.47.0-SNAPSHOT] at io.strimzi.systemtest.resources.types.KafkaType.delete(KafkaType.java:30) ~[systemtest-0.47.0-SNAPSHOT.jar:0.47.0-SNAPSHOT] at io.skodjob.testframe.resources.KubeResourceManager.deleteResource(KubeResourceManager.java:609) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.deleteResourceWithWait(KubeResourceManager.java:548) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.lambda$pushToStack$5(KubeResourceManager.java:310) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.lambda$deleteResources$22(KubeResourceManager.java:794) ~[test-frame-common-1.0.0.jar:?] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) [?:?] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1796) [?:?] at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) [?:?] at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) [?:?] at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) [?:?] at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) [?:?] at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) [?:?] Caused by: java.util.concurrent.TimeoutException at io.fabric8.kubernetes.client.utils.AsyncUtils.lambda$withTimeout$0(AsyncUtils.java:42) ~[kubernetes-client-api-7.3.1.jar:?] at io.fabric8.kubernetes.client.utils.Utils.lambda$schedule$6(Utils.java:474) ~[kubernetes-client-api-7.3.1.jar:?] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?] at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?] at java.base/java.lang.Thread.run(Thread.java:840) ~[?:?] 2025-07-08 14:27:54 [T-74] ERROR [KubeResourceManager:615] null io.fabric8.kubernetes.client.KubernetesClientException: null at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.waitForResult(OperationSupport.java:509) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handleResponse(OperationSupport.java:524) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handleDelete(OperationSupport.java:320) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.deleteAll(BaseOperation.java:535) ~[kubernetes-client-7.3.1.jar:?] at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.delete(BaseOperation.java:500) ~[kubernetes-client-7.3.1.jar:?] at io.strimzi.systemtest.resources.types.KafkaTopicType.delete(KafkaTopicType.java:54) ~[systemtest-0.47.0-SNAPSHOT.jar:0.47.0-SNAPSHOT] at io.strimzi.systemtest.resources.types.KafkaTopicType.delete(KafkaTopicType.java:20) ~[systemtest-0.47.0-SNAPSHOT.jar:0.47.0-SNAPSHOT] at io.skodjob.testframe.resources.KubeResourceManager.deleteResource(KubeResourceManager.java:[609](https://github.com/strimzi/strimzi-kafka-operator/actions/runs/16141806391/job/45560990640#step:25:610)) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.deleteResourceWithWait(KubeResourceManager.java:548) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.lambda$pushToStack$5(KubeResourceManager.java:310) ~[test-frame-common-1.0.0.jar:?] at io.skodjob.testframe.resources.KubeResourceManager.lambda$deleteResources$22(KubeResourceManager.java:794) ~[test-frame-common-1.0.0.jar:?] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804) [?:?] at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1796) [?:?] at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373) [?:?] at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182) [?:?] at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655) [?:?] at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622) [?:?] at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165) [?:?] Caused by: java.util.concurrent.TimeoutException at io.fabric8.kubernetes.client.utils.AsyncUtils.lambda$withTimeout$0(AsyncUtils.java:42) ~[kubernetes-client-api-7.3.1.jar:?] at io.fabric8.kubernetes.client.utils.Utils.lambda$schedule$6(Utils.java:474) ~[kubernetes-client-api-7.3.1.jar:?] at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[?:?] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?] at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?] at java.base/java.lang.Thread.run(Thread.java:840) ~[?:?] ``` This PR tries to remove the nulls and put into log just the cause class. ## Type of Change * New feature (non-breaking change which adds functionality) ## Checklist - [ ] My code follows the style guidelines of this project - [ ] I have performed a self-review of my own code - [ ] I have commented my code, particularly in hard-to-understand areas - [ ] I have made corresponding changes to the documentation - [ ] My changes generate no new warnings - [ ] I have added tests that prove my fix is effective or that my feature works - [ ] New and existing unit/integration tests pass locally with my changes --------- Signed-off-by: Jakub Stejskal <xstejs24@gmail.com>
1 parent 6660286 commit f96ffb0

2 files changed

Lines changed: 19 additions & 3 deletions

File tree

‎test-frame-common/src/main/java/io/skodjob/testframe/resources/KubeResourceManager.java‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -612,7 +612,8 @@ private <T extends HasMetadata> void deleteResource(boolean async, boolean waitF
612612
decideDeleteWaitAsync(waiters, async, resource);
613613
}
614614
} catch (Exception e) {
615-
LOGGER.error(e.getMessage(), e);
615+
LOGGER.error("Deletion of {}/{} failed with the following error: {}",
616+
resource.getKind(), resource.getMetadata().getName(), e.getMessage(), e);
616617
}
617618
deleteCallbacks.forEach(cb -> cb.accept(resource));
618619
}

‎test-frame-common/src/main/java/io/skodjob/testframe/wait/Wait.java‎

Lines changed: 17 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -87,7 +87,16 @@ public static void until(String description, long pollIntervalMs, long timeoutMs
8787

8888
if (++exceptionCount == exceptionAppearanceCount && exceptionMessage != null
8989
&& exceptionMessage.equals(previousExceptionMessage)) {
90-
LOGGER.info("While waiting for: {} exception occurred: {}", description, exceptionMessage);
90+
91+
if (e.getCause() instanceof TimeoutException) {
92+
LOGGER.warn("While waiting for: {} exception occurred: {}",
93+
description, e.getCause().getClass().getCanonicalName());
94+
exceptionMessage = e.getCause().getClass().getCanonicalName();
95+
} else {
96+
LOGGER.warn("While waiting for: {} exception occurred: {}/{}",
97+
description, e.getCause().getClass().getCanonicalName(), exceptionMessage);
98+
}
99+
91100
// log the stacktrace
92101
e.printStackTrace(new PrintWriter(stackTraceError));
93102
} else if (exceptionMessage != null && !exceptionMessage.equals(previousExceptionMessage)
@@ -103,7 +112,13 @@ public static void until(String description, long pollIntervalMs, long timeoutMs
103112
}
104113
if (timeLeft <= 0) {
105114
if (exceptionCount > 1) {
106-
LOGGER.error("Exception waiting for: {}, {}", description, exceptionMessage);
115+
if (exceptionMessage.equals("null")) {
116+
LOGGER.error("Latest exception while waiting for: {} was: {}",
117+
description, exceptionMessage);
118+
} else {
119+
LOGGER.error("Latest exception while waiting for: {} had message: {}",
120+
description, exceptionMessage);
121+
}
107122

108123
if (!stackTraceError.toString().isEmpty()) {
109124
// printing handled stacktrace

0 commit comments

Comments
 (0)