This is an automated email from the ASF dual-hosted git repository. gnodet pushed a commit to branch fix/tracing-test-flakiness-investigation in repository https://gitbox.apache.org/repos/asf/cxf.git
commit 5dceb1c6fccf7ed13e9b0fcb98c41c0ae64a8f98 Author: Guillaume Nodet <[email protected]> AuthorDate: Fri Mar 27 11:07:43 2026 +0100 Improve tracing test diagnostics: use untilAsserted with span list output Replace await().until(() -> spans.size() == N) with await().untilAsserted(() -> assertThat(message, size, equalTo(N))) across all tracing system tests. When the Awaitility wait times out, the error message now includes the actual span count and the full list of collected spans, making it much easier to diagnose whether the failure is caused by missing spans, extra spans from cross-test contamination, or a timing issue. Co-Authored-By: Claude Opus 4.6 <[email protected]> --- .../brave/jaxrs/AbstractBraveTracingTest.java | 15 ++++++---- .../brave/jaxws/AbstractBraveTracingTest.java | 4 ++- .../JaxrsOpenTelemetryTracingTest.java | 35 +++++++++++++--------- .../opentracing/JaxrsOpenTracingTracingTest.java | 35 +++++++++++++--------- .../JaxwsOpenTelemetryTracingTest.java | 9 ++++-- .../opentracing/JaxwsOpenTracingTracingTest.java | 9 ++++-- 6 files changed, 66 insertions(+), 41 deletions(-) diff --git a/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxrs/AbstractBraveTracingTest.java b/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxrs/AbstractBraveTracingTest.java index a7db3b275a7..58faf4d261a 100644 --- a/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxrs/AbstractBraveTracingTest.java +++ b/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxrs/AbstractBraveTracingTest.java @@ -265,9 +265,10 @@ public abstract class AbstractBraveTracingTest extends AbstractClientServerTestB } // Await till flush happens, usually a second is enough - await().atMost(Duration.ofSeconds(5L)).until(()-> TestSpanHandler.getAllSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + TestSpanHandler.getAllSpans(), + TestSpanHandler.getAllSpans().size(), equalTo(4))); - assertThat(TestSpanHandler.getAllSpans().size(), equalTo(4)); assertThat(TestSpanHandler.getAllSpans().get(3).name(), equalTo("test span")); } @@ -292,9 +293,10 @@ public abstract class AbstractBraveTracingTest extends AbstractClientServerTestB } // Await till flush happens, usually a second is enough - await().atMost(Duration.ofSeconds(5L)).until(()-> TestSpanHandler.getAllSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + TestSpanHandler.getAllSpans(), + TestSpanHandler.getAllSpans().size(), equalTo(4))); - assertThat(TestSpanHandler.getAllSpans().size(), equalTo(4)); assertThat(TestSpanHandler.getAllSpans().get(3).name(), equalTo("test span")); } @@ -340,8 +342,9 @@ public abstract class AbstractBraveTracingTest extends AbstractClientServerTestB try { client.get(); } finally { - await().atMost(Duration.ofSeconds(5L)).until(()-> TestSpanHandler.getAllSpans().size() == 2); - assertThat(TestSpanHandler.getAllSpans().size(), equalTo(2)); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + TestSpanHandler.getAllSpans(), + TestSpanHandler.getAllSpans().size(), equalTo(2))); assertThat(TestSpanHandler.getAllSpans().get(0).name(), equalTo("GET " + client.getCurrentURI())); assertThat(TestSpanHandler.getAllSpans().get(0).tags(), hasKey("error")); assertThat(TestSpanHandler.getAllSpans().get(1).name(), equalTo("GET /bookstore/books/long")); diff --git a/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxws/AbstractBraveTracingTest.java b/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxws/AbstractBraveTracingTest.java index 64f6ebbaba1..d5a59823fdc 100644 --- a/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxws/AbstractBraveTracingTest.java +++ b/systests/tracing/src/test/java/org/apache/cxf/systest/brave/jaxws/AbstractBraveTracingTest.java @@ -204,7 +204,9 @@ public abstract class AbstractBraveTracingTest extends AbstractClientServerTestB service.orderBooks(); // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(() -> TestSpanHandler.getAllSpans().size() == 2); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + TestSpanHandler.getAllSpans(), + TestSpanHandler.getAllSpans().size(), equalTo(2))); assertThat(TestSpanHandler.getAllSpans().get(0).name(), equalTo("POST /BookStore")); assertThat(TestSpanHandler.getAllSpans().get(1).name(), diff --git a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentelemetry/JaxrsOpenTelemetryTracingTest.java b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentelemetry/JaxrsOpenTelemetryTracingTest.java index f49a46e068a..39389157b6d 100644 --- a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentelemetry/JaxrsOpenTelemetryTracingTest.java +++ b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentelemetry/JaxrsOpenTelemetryTracingTest.java @@ -257,10 +257,11 @@ public class JaxrsOpenTelemetryTracingTest extends AbstractClientServerTestBase final Response r = withTrace(createWebClient("/bookstore/books/async")).get(); assertEquals(Status.OK.getStatusCode(), r.getStatus()); - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 2); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(2))); final List<SpanData> spans = getSpansSorted(); - assertThat(spans.size(), equalTo(2)); assertEquals("Processing books", spans.get(0).getName()); assertEquals("GET /bookstore/books/async", spans.get(1).getName()); @@ -287,10 +288,11 @@ public class JaxrsOpenTelemetryTracingTest extends AbstractClientServerTestBase final Response r = createWebClient("/bookstore/books/async").get(); assertEquals(Status.OK.getStatusCode(), r.getStatus()); - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 2); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(2))); final List<SpanData> spans = getSpansSorted(); - assertThat(spans.size(), equalTo(2)); assertThat(spans.get(0).getName(), equalTo("Processing books")); assertThat(spans.get(1).getName(), equalTo("GET /bookstore/books/async")); } @@ -303,9 +305,10 @@ public class JaxrsOpenTelemetryTracingTest extends AbstractClientServerTestBase final Response r = client.async().get().get(1L, TimeUnit.SECONDS); assertEquals(Status.OK.getStatusCode(), r.getStatus()); - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 3); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(3))); - assertThat(otelRule.getSpans().size(), equalTo(3)); assertThat(otelRule.getSpans().get(0).getName(), equalTo("Get Books")); assertThat(otelRule.getSpans().get(1).getName(), equalTo("GET /bookstore/books")); assertThat(otelRule.getSpans().get(1).getKind(), equalTo(SpanKind.SERVER)); @@ -373,9 +376,10 @@ public class JaxrsOpenTelemetryTracingTest extends AbstractClientServerTestBase } // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(4))); - assertThat(otelRule.getSpans().size(), equalTo(4)); assertThat(otelRule.getSpans().get(3).getName(), equalTo("test span")); assertThat(otelRule.getSpans().get(3).getParentSpanContext().isValid(), equalTo(false)); } @@ -392,9 +396,10 @@ public class JaxrsOpenTelemetryTracingTest extends AbstractClientServerTestBase assertThat(Span.current().getSpanContext().getSpanId(), equalTo(span.getSpanContext().getSpanId())); - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 3); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(3))); - assertThat(otelRule.getSpans().size(), equalTo(3)); assertThat(otelRule.getSpans().get(0).getName(), equalTo("Get Books")); assertThat(otelRule.getSpans().get(0).getParentSpanContext(), notNullValue()); assertThat(otelRule.getSpans().get(1).getName(), equalTo("GET /bookstore/books")); @@ -406,9 +411,10 @@ public class JaxrsOpenTelemetryTracingTest extends AbstractClientServerTestBase } // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(4))); - assertThat(otelRule.getSpans().size(), equalTo(4)); assertThat(otelRule.getSpans().get(3).getName(), equalTo("test span")); assertThat(otelRule.getSpans().get(3).getParentSpanContext().isValid(), equalTo(false)); } @@ -443,8 +449,9 @@ public class JaxrsOpenTelemetryTracingTest extends AbstractClientServerTestBase try { client.get(); } finally { - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 2); - assertThat(otelRule.getSpans().toString(), otelRule.getSpans().size(), equalTo(2)); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(2))); assertThat(otelRule.getSpans().get(0).getName(), equalTo("GET " + client.getCurrentURI())); assertThat(otelRule.getSpans().get(0).getStatus().getStatusCode(), equalTo(StatusCode.ERROR)); assertThat(otelRule.getSpans().get(1).getName(), equalTo("GET /bookstore/books/long")); diff --git a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentracing/JaxrsOpenTracingTracingTest.java b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentracing/JaxrsOpenTracingTracingTest.java index da278ba6f20..86fd491190b 100644 --- a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentracing/JaxrsOpenTracingTracingTest.java +++ b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxrs/tracing/opentracing/JaxrsOpenTracingTracingTest.java @@ -199,10 +199,11 @@ public class JaxrsOpenTracingTracingTest extends AbstractClientServerTestBase { final Response r = withTrace(createWebClient("/bookstore/books/async"), spanId).get(); assertEquals(Status.OK.getStatusCode(), r.getStatus()); - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 2); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(2))); final List<JaegerSpan> spans = getSpansSorted(); - assertThat(spans.size(), equalTo(2)); assertEquals("Processing books", spans.get(0).getOperationName()); assertEquals("GET /bookstore/books/async", spans.get(1).getOperationName()); assertThat(spans.get(1).getReferences(), not(empty())); @@ -226,10 +227,11 @@ public class JaxrsOpenTracingTracingTest extends AbstractClientServerTestBase { final Response r = createWebClient("/bookstore/books/async").get(); assertEquals(Status.OK.getStatusCode(), r.getStatus()); - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 2); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(2))); final List<JaegerSpan> spans = getSpansSorted(); - assertThat(spans.size(), equalTo(2)); assertThat(spans.get(0).getOperationName(), equalTo("Processing books")); assertThat(spans.get(1).getOperationName(), equalTo("GET /bookstore/books/async")); } @@ -241,9 +243,10 @@ public class JaxrsOpenTracingTracingTest extends AbstractClientServerTestBase { final Response r = client.async().get().get(1L, TimeUnit.SECONDS); assertEquals(Status.OK.getStatusCode(), r.getStatus()); - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 3); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(3))); - assertThat(REPORTER.getSpans().size(), equalTo(3)); assertThat(REPORTER.getSpans().get(0).getOperationName(), equalTo("Get Books")); assertThat(REPORTER.getSpans().get(1).getOperationName(), equalTo("GET /bookstore/books")); assertThat(REPORTER.getSpans().get(1).getTags(), hasItem(Tags.SPAN_KIND.getKey(), Tags.SPAN_KIND_SERVER)); @@ -325,9 +328,10 @@ public class JaxrsOpenTracingTracingTest extends AbstractClientServerTestBase { } // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(4))); - assertThat(REPORTER.getSpans().size(), equalTo(4)); assertThat(REPORTER.getSpans().get(3).getOperationName(), equalTo("test span")); assertThat(REPORTER.getSpans().get(3).getReferences(), empty()); } @@ -342,9 +346,10 @@ public class JaxrsOpenTracingTracingTest extends AbstractClientServerTestBase { assertEquals(Status.OK.getStatusCode(), r.getStatus()); assertThat(tracer.activeSpan().context(), equalTo(span.context())); - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 3); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(3))); - assertThat(REPORTER.getSpans().size(), equalTo(3)); assertThat(REPORTER.getSpans().get(0).getOperationName(), equalTo("Get Books")); assertThat(REPORTER.getSpans().get(0).getReferences(), not(empty())); assertThat(REPORTER.getSpans().get(1).getOperationName(), equalTo("GET /bookstore/books")); @@ -356,9 +361,10 @@ public class JaxrsOpenTracingTracingTest extends AbstractClientServerTestBase { } // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(4))); - assertThat(REPORTER.getSpans().size(), equalTo(4)); assertThat(REPORTER.getSpans().get(3).getOperationName(), equalTo("test span")); assertThat(REPORTER.getSpans().get(3).getReferences(), empty()); } @@ -391,8 +397,9 @@ public class JaxrsOpenTracingTracingTest extends AbstractClientServerTestBase { try { client.get(); } finally { - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 2); - assertThat(REPORTER.getSpans().toString(), REPORTER.getSpans().size(), equalTo(2)); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(2))); assertThat(REPORTER.getSpans().get(0).getOperationName(), equalTo("GET " + client.getCurrentURI())); assertThat(REPORTER.getSpans().get(0).getTags(), hasItem(Tags.ERROR.getKey(), Boolean.TRUE)); assertThat(REPORTER.getSpans().get(1).getOperationName(), equalTo("GET /bookstore/books/long")); diff --git a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentelemetry/JaxwsOpenTelemetryTracingTest.java b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentelemetry/JaxwsOpenTelemetryTracingTest.java index 821b57e943e..449e41258fa 100644 --- a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentelemetry/JaxwsOpenTelemetryTracingTest.java +++ b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentelemetry/JaxwsOpenTelemetryTracingTest.java @@ -247,9 +247,10 @@ public class JaxwsOpenTelemetryTracingTest extends AbstractClientServerTestBase } // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(4))); - assertThat(otelRule.getSpans().size(), equalTo(4)); assertThat(otelRule.getSpans().get(3).getName(), equalTo("test span")); assertThat(otelRule.getSpans().get(3).getParentSpanContext().isValid(), equalTo(false)); } @@ -331,7 +332,9 @@ public class JaxwsOpenTelemetryTracingTest extends AbstractClientServerTestBase service.orderBooks(); // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(() -> otelRule.getSpans().size() == 2); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + otelRule.getSpans(), + otelRule.getSpans().size(), equalTo(2))); assertThat(otelRule.getSpans().get(0).getName(), equalTo("POST /BookStore")); assertThat(otelRule.getSpans().get(1).getName(), diff --git a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentracing/JaxwsOpenTracingTracingTest.java b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentracing/JaxwsOpenTracingTracingTest.java index d3f9f5e4384..b69ade7b04a 100644 --- a/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentracing/JaxwsOpenTracingTracingTest.java +++ b/systests/tracing/src/test/java/org/apache/cxf/systest/jaxws/tracing/opentracing/JaxwsOpenTracingTracingTest.java @@ -178,9 +178,10 @@ public class JaxwsOpenTracingTracingTest extends AbstractClientServerTestBase { } // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(()-> REPORTER.getSpans().size() == 4); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(4))); - assertThat(REPORTER.getSpans().size(), equalTo(4)); assertThat(REPORTER.getSpans().get(3).getOperationName(), equalTo("test span")); assertThat(REPORTER.getSpans().get(3).getReferences(), empty()); } @@ -234,7 +235,9 @@ public class JaxwsOpenTracingTracingTest extends AbstractClientServerTestBase { service.orderBooks(); // Await till flush happens, usually every second - await().atMost(Duration.ofSeconds(5L)).until(() -> REPORTER.getSpans().size() == 2); + await().atMost(Duration.ofSeconds(5L)).untilAsserted(() -> assertThat( + "Unexpected span count. Spans: " + REPORTER.getSpans(), + REPORTER.getSpans().size(), equalTo(2))); assertThat(REPORTER.getSpans().get(0).getOperationName(), equalTo("POST /BookStore")); assertThat(REPORTER.getSpans().get(1).getOperationName(),
