quarkusio / quarkus

Quarkus: Supersonic Subatomic Java.
https://quarkus.io
Apache License 2.0
13.53k stars 2.61k forks source link

Quarkus 3.10 issue with OpenTelemetry? #42087

Open matzew opened 1 month ago

matzew commented 1 month ago

Describe the bug

We get a unti test failure when trying to bump to Quarkus 3.10 (from 3.8).

java.lang.AssertionError: 
Expected size: 3 but was: 2 in:
[SpanData{spanContext=ImmutableSpanContext{traceId=b3af604008204ef273725923bf652a00, spanId=59f302b88a8e9bb0, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=b3af604008204ef273725923bf652a00, spanId=410e1d8a6485bd43, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=true, valid=true}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.32.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=io.vertx, version=null, schemaUrl=null, attributes={}}, name=POST, kind=SERVER, startEpochNanos=1721749113517586397, endEpochNanos=1721749113534142078, attributes=AttributesMap{data={http.request.method=POST, url.path=/broker-ns/broker-name, http.status_code=202, http.scheme=http, messaging.message_source=/hello, messaging.message_type=type, http.method=POST, http.response.status_code=202, http.url=http://localhost:8083/broker-ns/broker-name, messaging.message_id=1234}, capacity=128, totalAddedValues=10}, totalAttributeCount=10, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true},
    SpanData{spanContext=ImmutableSpanContext{traceId=b3af604008204ef273725923bf652a00, spanId=410e1d8a6485bd43, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.32.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=io.vertx, version=null, schemaUrl=null, attributes={}}, name=POST, kind=CLIENT, startEpochNanos=1721749113491976322, endEpochNanos=1721749113538305773, attributes=AttributesMap{data={http.request.method=POST, http.status_code=202, http.method=POST, url.full=http://localhost:8083/broker-ns/broker-name, http.response.status_code=202, http.url=http://localhost:8083/broker-ns/broker-name}, capacity=128, totalAddedValues=6}, totalAttributeCount=6, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true}]

    at dev.knative.eventing.kafka.broker.receiver.impl.ReceiverVerticleTracingTest.traceIsPropagated(ReceiverVerticleTracingTest.java:190)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)

Expected behavior

Like in 3.8 and its telemetry libray no issue

Actual behavior

Test fails...

How to Reproduce?

Output of uname -a or ver

Fedora

Output of java -version

21 (prow) and 22 (my fedora)

Quarkus version or git rev

3.10.2

Build tool (ie. output of mvnw --version or gradlew --version)

No response

Additional information

The error:


java.lang.AssertionError: 
Expected size: 3 but was: 2 in:
[SpanData{spanContext=ImmutableSpanContext{traceId=b3af604008204ef273725923bf652a00, spanId=59f302b88a8e9bb0, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=b3af604008204ef273725923bf652a00, spanId=410e1d8a6485bd43, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=true, valid=true}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.32.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=io.vertx, version=null, schemaUrl=null, attributes={}}, name=POST, kind=SERVER, startEpochNanos=1721749113517586397, endEpochNanos=1721749113534142078, attributes=AttributesMap{data={http.request.method=POST, url.path=/broker-ns/broker-name, http.status_code=202, http.scheme=http, messaging.message_source=/hello, messaging.message_type=type, http.method=POST, http.response.status_code=202, http.url=http://localhost:8083/broker-ns/broker-name, messaging.message_id=1234}, capacity=128, totalAddedValues=10}, totalAttributeCount=10, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true},
    SpanData{spanContext=ImmutableSpanContext{traceId=b3af604008204ef273725923bf652a00, spanId=410e1d8a6485bd43, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.32.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=io.vertx, version=null, schemaUrl=null, attributes={}}, name=POST, kind=CLIENT, startEpochNanos=1721749113491976322, endEpochNanos=1721749113538305773, attributes=AttributesMap{data={http.request.method=POST, http.status_code=202, http.method=POST, url.full=http://localhost:8083/broker-ns/broker-name, http.response.status_code=202, http.url=http://localhost:8083/broker-ns/broker-name}, capacity=128, totalAddedValues=6}, totalAttributeCount=6, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true}]

    at dev.knative.eventing.kafka.broker.receiver.impl.ReceiverVerticleTracingTest.traceIsPropagated(ReceiverVerticleTracingTest.java:190)
    at java.base/java.lang.reflect.Method.invoke(Method.java:580)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)
    at java.base/java.util.ArrayList.forEach(ArrayList.java:1597)
quarkus-bot[bot] commented 1 month ago

/cc @geoand (knative), @iocanel (knative)

geoand commented 1 month ago

cc @brunobat

matzew commented 1 month ago

there are other tracing related errors, such as -> https://prow.knative.dev/view/gs/knative-prow/pr-logs/pull/knative-extensions_eventing-kafka-broker/3872/reconciler-tests_eventing-kafka-broker_main/1815775631011483648

all w/ the bump to 3.10

brunobat commented 1 month ago

looking into it

brunobat commented 1 month ago

@matzew what are the 3 traces that you are expecting on that test, here: https://github.com/matzew/eventing-kafka-broker/blob/6e1d381b21f48d893aa925729ed50e903d378e83/data-plane/receiver/src/test/java/dev/knative/eventing/kafka/broker/receiver/impl/ReceiverVerticleTracingTest.java#L190

matzew commented 1 month ago

Hello @brunobat! Thanks for looking

the following is what I get w/ the main branch, which is based on 3.8.4.

[SpanData{spanContext=ImmutableSpanContext{traceId=6273d8419d395e889553065c78013690, spanId=ff7b1c1a3554ed79, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=6273d8419d395e889553065c78013690, spanId=6539dc73d2f4b5e7, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=true, valid=true}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.32.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=io.vertx, version=null, schemaUrl=null, attributes={}}, name=POST, kind=SERVER, startEpochNanos=1721837107852469627, endEpochNanos=1721837107870432134, attributes=AttributesMap{data={http.url=http://localhost:8083/broker-ns/broker-name, messaging.message_id=1234, http.path=/broker-ns/broker-name, messaging.message_source=/hello, http.scheme=http, http.method=POST, messaging.message_type=type, http.status_code=202}, capacity=128, totalAddedValues=8}, totalAttributeCount=8, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true},
    SpanData{spanContext=ImmutableSpanContext{traceId=6273d8419d395e889553065c78013690, spanId=6539dc73d2f4b5e7, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=00000000000000000000000000000000, spanId=0000000000000000, traceFlags=00, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=false}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.32.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=io.vertx, version=null, schemaUrl=null, attributes={}}, name=POST, kind=CLIENT, startEpochNanos=1721837107819775285, endEpochNanos=1721837107874186712, attributes=AttributesMap{data={http.url=http://localhost:8083/broker-ns/broker-name, http.method=POST, http.status_code=202}, capacity=128, totalAddedValues=3}, totalAttributeCount=3, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true},
    SpanData{spanContext=ImmutableSpanContext{traceId=6273d8419d395e889553065c78013690, spanId=f0fc29ae84665066, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, parentSpanContext=ImmutableSpanContext{traceId=6273d8419d395e889553065c78013690, spanId=ff7b1c1a3554ed79, traceFlags=01, traceState=ArrayBasedTraceState{entries=[]}, remote=false, valid=true}, resource=Resource{schemaUrl=null, attributes={service.name="unknown_service:java", telemetry.sdk.language="java", telemetry.sdk.name="opentelemetry", telemetry.sdk.version="1.32.0"}}, instrumentationScopeInfo=InstrumentationScopeInfo{name=io.vertx, version=null, schemaUrl=null, attributes={}}, name=kafka_send, kind=PRODUCER, startEpochNanos=1721837107864910614, endEpochNanos=1721837107882621204, attributes=AttributesMap{data={peer.address=, message_bus.destination=topic-name-42, peer.service=kafka}, capacity=128, totalAddedValues=3}, totalAttributeCount=3, events=[], totalRecordedEvents=0, links=[], totalRecordedLinks=0, status=ImmutableStatusData{statusCode=UNSET, description=}, hasEnded=true}]

See: https://github.com/knative-extensions/eventing-kafka-broker/blob/main/data-plane/pom.xml#L64

and the version of telemetry -> https://github.com/knative-extensions/eventing-kafka-broker/blob/main/data-plane/pom.xml#L49

matzew commented 1 month ago

I see this here too, and I think it is just when I use the vertx-opentelemetry version 4.5.x: https://github.com/knative-extensions/eventing-kafka-broker/pull/3929#pullrequestreview-2198980757

But not yet exactly sure, on what's the diff between 4.4.7 and 4.5.7 (which is what our core is based on, via quarkus)