Spring Webflux 5 instrumentation tests are flaky

[PerfectSlayer]

Test suite

Redirect test from SingleThreadedSpringWebfluxTest Marked flaky by CircleCI

Error

Condition failed with Exception:

assertTraces(4) { sortSpansByStart() // TODO: why order of spans is different in these traces? def traceParent1, traceParent2, traceParent3 trace(2) { traceParent1 = clientSpan(it, null, "http.request", "spring-webflux-client", "GET", URI.create(url), 307) traceParent2 =  clientSpan(it, span(0), "netty.client.request", "netty-client", "GET", URI.create(url), 307) } trace(2) { clientSpan(it, traceParent1, "http.request", "spring-webflux-client", "GET", URI.create(finalUrl)) traceParent3 =  clientSpan(it, span(0), "netty.client.request", "netty-client", "GET", URI.create(finalUrl)) } trace(2) { span { resourceName "GET /double-greet-redirect" operationName "netty.request" spanType DDSpanTypes.HTTP_SERVER childOf(traceParent2) tags { "$Tags.COMPONENT" "netty" "$Tags.SPAN_KIND" Tags.SPAN_KIND_SERVER "$Tags.PEER_HOST_IPV4" "127.0.0.1" "$Tags.PEER_PORT" Integer "$Tags.HTTP_URL" url "$Tags.HTTP_HOSTNAME" "localhost" "$Tags.HTTP_METHOD" "GET" "$Tags.HTTP_STATUS" 307 "$Tags.HTTP_USER_AGENT" String "$Tags.HTTP_CLIENT_IP" "127.0.0.1" "$Tags.HTTP_ROUTE" "/double-greet-redirect" defaultTags(true) } } span { resourceName "RedirectComponent.lambda" operationName "RedirectComponent.lambda" spanType DDSpanTypes.HTTP_SERVER childOf(span(0)) tags { "$Tags.COMPONENT" "spring-webflux-controller" "$Tags.SPAN_KIND" Tags.SPAN_KIND_SERVER "request.predicate" "(GET && /double-greet-redirect)" "handler.type" { String tagVal -> return (tagVal.contains(INNER_HANDLER_FUNCTION_CLASS_TAG_PREFIX) || tagVal.contains("Lambda")) } defaultTags() } } } trace(2) { span { resourceName "GET /double-greet" operationName "netty.request" spanType DDSpanTypes.HTTP_SERVER traceParent3 tags { "$Tags.COMPONENT" "netty" "$Tags.SPAN_KIND" Tags.SPAN_KIND_SERVER "$Tags.PEER_HOST_IPV4" "127.0.0.1" "$Tags.PEER_PORT" Integer "$Tags.HTTP_URL" finalUrl "$Tags.HTTP_HOSTNAME" "localhost" "$Tags.HTTP_METHOD" "GET" "$Tags.HTTP_STATUS" 200 "$Tags.HTTP_USER_AGENT" String "$Tags.HTTP_CLIENT_IP" "127.0.0.1" "$Tags.HTTP_ROUTE" "/double-greet" defaultTags(true) } } span { resourceNameContains(SpringWebFluxTestApplication.getSimpleName() + "\$", ".handle") operationNameContains(SpringWebFluxTestApplication.getSimpleName() + "\$", ".handle") spanType DDSpanTypes.HTTP_SERVER childOf(span(0)) tags { "$Tags.COMPONENT" "spring-webflux-controller" "$Tags.SPAN_KIND" Tags.SPAN_KIND_SERVER "request.predicate" "(GET && /double-greet)" "handler.type" { String tagVal -> return tagVal.contains(INNER_HANDLER_FUNCTION_CLASS_TAG_PREFIX) } defaultTags() } } } }

	at SpringWebfluxTest.Redirect test(SpringWebfluxTest.groovy:509)
Caused by: java.util.concurrent.TimeoutException: Timeout waiting for 4 trace(s). ListWriter.size() == 3 : [[DDSpan [ t_id=109, s_id=111, p_id=110 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/netty.request/GET /double-greet-redirect *measured* tags={_dd.profiling.ctx=test, _dd.profiling.enabled=0, _dd.trace_span_attribute_schema=0, _sample_rate=1, component=netty, http.client_ip=127.0.0.1, http.hostname=localhost, http.method=GET, http.route=/double-greet-redirect, http.status_code=307, http.url=http://localhost:45125/double-greet-redirect, http.useragent=ReactorNetty/0.7.15.RELEASE, language=jvm, peer.ipv4=127.0.0.1, peer.port=34040, process_id=5312, runtime-id=004cd152-94dc-4ec3-a5fc-794777bc6282, span.kind=server, thread.id=51, thread.name=reactor-http-epoll-6}, duration_ns=2617920, forceKeep=false, links=[], DDSpan [ t_id=109, s_id=112, p_id=111 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/RedirectComponent.lambda/RedirectComponent.lambda *measured* tags={component=spring-webflux-controller, handler.type=dd.trace.instrumentation.springwebflux.server.RedirectComponent$$Lambda/0x00007efe4c7836d0, language=jvm, request.predicate=(GET && /double-greet-redirect), span.kind=server, thread.id=51, thread.name=reactor-http-epoll-6}, duration_ns=1473465, forceKeep=false, links=[]], [DDSpan [ t_id=109, s_id=116, p_id=115 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/SpringWebFluxTestApplication$4.handle/SpringWebFluxTestApplication$4.handle *measured* tags={component=spring-webflux-controller, handler.type=dd.trace.instrumentation.springwebflux.server.SpringWebFluxTestApplication$4, language=jvm, request.predicate=(GET && /double-greet), span.kind=server, thread.id=49, thread.name=reactor-http-epoll-4}, duration_ns=4565024, forceKeep=false, links=[], DDSpan [ t_id=109, s_id=115, p_id=114 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/netty.request/GET /double-greet *measured* tags={_dd.profiling.ctx=test, _dd.profiling.enabled=0, _dd.trace_span_attribute_schema=0, _sample_rate=1, component=netty, http.client_ip=127.0.0.1, http.hostname=localhost, http.method=GET, http.route=/double-greet, http.status_code=200, http.url=http://localhost:45125/double-greet, http.useragent=ReactorNetty/0.7.15.RELEASE, language=jvm, peer.ipv4=127.0.0.1, peer.port=55054, process_id=5312, runtime-id=004cd152-94dc-4ec3-a5fc-794777bc6282, span.kind=server, thread.id=49, thread.name=reactor-http-epoll-4}, duration_ns=5374062, forceKeep=false, links=[]], [DDSpan [ t_id=109, s_id=113, p_id=108 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/http.request/GET /double-greet *measured* tags={component=spring-webflux-client, http.method=GET, http.status_code=200, http.url=http://localhost:45125/double-greet, peer.hostname=localhost, peer.port=45125, span.kind=client, thread.id=50, thread.name=reactor-http-epoll-5}, duration_ns=56968151, forceKeep=false, links=[], DDSpan [ t_id=109, s_id=114, p_id=113 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/netty.client.request/GET /double-greet *measured* tags={component=netty-client, http.method=GET, http.status_code=200, http.url=http://localhost:45125/double-greet, peer.hostname=localhost, peer.ipv4=127.0.0.1, peer.port=45125, span.kind=client, thread.id=48, thread.name=reactor-http-epoll-3}, duration_ns=50727011, forceKeep=false, links=[], DDSpan [ t_id=109, s_id=108, p_id=0 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/http.request/GET /double-greet-redirect *measured* tags={_dd.agent_psr=1.0, _dd.profiling.ctx=test, _dd.profiling.enabled=0, _dd.trace_span_attribute_schema=0, _sample_rate=1, component=spring-webflux-client, http.method=GET, http.status_code=307, http.url=http://localhost:45125/double-greet-redirect, language=jvm, peer.hostname=localhost, peer.port=45125, process_id=5312, runtime-id=004cd152-94dc-4ec3-a5fc-794777bc6282, span.kind=client, thread.id=1, thread.name=Test worker}, duration_ns=38578045, forceKeep=false, links=[], DDSpan [ t_id=109, s_id=110, p_id=108 ] trace=worker.org.gradle.process.internal.worker.GradleWorkerMain/netty.client.request/GET /double-greet-redirect *measured* tags={component=netty-client, http.method=GET, http.status_code=307, http.url=http://localhost:45125/double-greet-redirect, peer.hostname=localhost, peer.ipv4=127.0.0.1, peer.port=45125, span.kind=client, thread.id=50, thread.name=reactor-http-epoll-5}, duration_ns=9283589, forceKeep=false, links=[]]]
	at datadog.trace.common.writer.ListWriter.waitForTraces(ListWriter.java:86)
	at datadog.trace.agent.test.asserts.ListWriterAssert.assertTraces(ListWriterAssert.groovy:50)
	at datadog.trace.agent.test.asserts.ListWriterAssert.assertTraces(ListWriterAssert.groovy:41)
	at datadog.trace.agent.test.AgentTestRunner.assertTraces(AgentTestRunner.groovy:600)
	at datadog.trace.agent.test.AgentTestRunner.assertTraces(AgentTestRunner.groovy:589)
	... 1 more

Cause

Only 3 spans received while expecting 4.

Environment

Java 21, Instrumentation latest

Logs

latestBoot20Test.zip