Ensure that the name generated in opentelemetry matches the endpoint being called #44523

jcuero · 2024-11-15T04:05:10Z

When combining multiple unis, the operationName field retains the last uni processed instead of retaining the value it was initialized with.

Fixes: Traces are generated with an inconsistent operationName value when combining multiple unis #44524

quarkus-bot · 2024-11-15T04:05:31Z

/cc @brunobat (opentelemetry), @radcortez (opentelemetry)

geoand · 2024-11-15T06:54:22Z

Thanks a lot for this!

I agree the problem needs to be fixed, but I am not convinced this is the proper solution. I will spend some time looking into it as I think the way ClientObservabilityHandler is being used was incorrect from the start.

geoand · 2024-11-15T07:31:52Z

...ctive/client/runtime/src/main/java/org/jboss/resteasy/reactive/client/impl/HandlerChain.java

+    private HandlerChain(ClientRestHandler clientCaptureCurrentContextRestHandler,
+            ClientRestHandler clientSwitchToRequestContextRestHandler, ClientRestHandler clientSendHandler,
+            ClientRestHandler clientSetResponseEntityRestHandler, ClientRestHandler clientResponseCompleteRestHandler,
+            ClientRestHandler clientErrorHandler) {
+        this.clientCaptureCurrentContextRestHandler = clientCaptureCurrentContextRestHandler;
+        this.clientSwitchToRequestContextRestHandler = clientSwitchToRequestContextRestHandler;
+        this.clientSendHandler = clientSendHandler;
+        this.clientSetResponseEntityRestHandler = clientSetResponseEntityRestHandler;
+        this.clientResponseCompleteRestHandler = clientResponseCompleteRestHandler;
+        this.clientErrorHandler = clientErrorHandler;
+    }
+
+    private HandlerChain newInstance() {
+        return new HandlerChain(clientCaptureCurrentContextRestHandler, clientSwitchToRequestContextRestHandler,
+                clientSendHandler, clientSetResponseEntityRestHandler, clientResponseCompleteRestHandler, clientErrorHandler);
+    }
+
    HandlerChain setPreClientSendHandler(ClientRestHandler preClientSendHandler) {
-        this.preClientSendHandler = preClientSendHandler;
-        return this;
+        HandlerChain newHandlerChain = newInstance();
+        newHandlerChain.preClientSendHandler = preClientSendHandler;
+        return newHandlerChain;


Wouldn't the changes here alone be enough to fix the problem? Asking because the change to ClientRequestContextImpl don't seem necessary (although the might be correct)

geoand · 2024-11-15T07:32:04Z

...e/client/runtime/src/test/java/org/jboss/resteasy/reactive/client/impl/HandlerChainTest.java

@@ -15,16 +12,18 @@
 import org.jboss.resteasy.reactive.common.jaxrs.ConfigurationImpl;
 import org.junit.jupiter.api.Test;

+import static org.junit.jupiter.api.Assertions.*;


Please avoid star imports

geoand · 2024-11-15T09:10:52Z

I am also interested to know if CI passed on your fork with this change

brunobat

This makes sense to me and the test is thorough.
Left just a minor thingy.

brunobat · 2024-11-15T08:58:06Z

...ntelemetry-reactive/src/main/java/io/quarkus/it/opentelemetry/reactive/ReactiveResource.java

+                client.helloGet("Naruto"),
+                client.helloGet("Goku"),
+                client.helloGetUniExecutor())
+            .combinedWith((s, s2, s3, s4) -> s + " and " + s2 + " and " + s3 + " and " + s4);


'combinedWith(io. smallrye. mutiny. tuples. Functions. Function4<T1,T2,T3,T4,O>)' is deprecated and marked for removal. Can you please use something else?

geoand · 2024-11-15T09:13:57Z

.../runtime/src/main/java/org/jboss/resteasy/reactive/client/impl/ClientRequestContextImpl.java

-        Context ctxt = Vertx.currentContext();
-        if (ctxt != null && VertxContext.isDuplicatedContext(ctxt)) {
-            this.context = ctxt;
-        } else {
-            Context current = client.vertx.getOrCreateContext();
-            this.context = VertxContext.createNewDuplicatedContext(current);
-        }
+        Context current = client.vertx.getOrCreateContext();
+        this.context = VertxContext.createNewDuplicatedContext(current);


I'm actually unsure of this. I would really like to know if the tests pass without this change

It fails, I tried the test without the main changes.

Well, I am not confident about this change at all, at least until somebody convinces me that it needs to be this way. I would like to understand why this is needed.

Note that if I do not ensure that a DuplicateContext instance is created, the result in the trace is still inconsistent.

Now, without modifying this logic and only keeping the changes made in HandlerChain, the only thing different is that there are two traces where "operationName": "GET /step_3". but still inconsistent.

Trace Data

{ "data": [ { "traceID": "f839289a74ed082f3839bc6968765708", "spans": [ { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "f1cf382a3d83054f", "operationName": "GET /wizard-server/start", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "298e03112df3e297" } ], "startTime": 1731672920394667, "duration": 2020218, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "client.address", "type": "string", "value": "127.0.0.1" }, { "key": "user_agent.original", "type": "string", "value": "Quarkus REST Client" }, { "key": "url.path", "type": "string", "value": "/wizard-server/start" }, { "key": "code.namespace", "type": "string", "value": "org.acme.server.WizardServerResource" }, { "key": "http.response.body.size", "type": "int64", "value": 10 }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "code.function", "type": "string", "value": "start" }, { "key": "http.route", "type": "string", "value": "/wizard-server/start" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.scheme", "type": "string", "value": "http" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "server" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "9aabd1c958cde2cc", "operationName": "GET /step_3", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "97a9eae6612ae05c" } ], "startTime": 1731672922433087, "duration": 1004952, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.full", "type": "string", "value": "http://localhost:8080/wizard-server/step_3" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "client" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "298e03112df3e297", "operationName": "GET /start", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "97a9eae6612ae05c" } ], "startTime": 1731672920392373, "duration": 2026956, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.full", "type": "string", "value": "http://localhost:8080/wizard-server/start" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "client" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "34bbf1dbe559e321", "operationName": "GET /wizard-server/step_3", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "9aabd1c958cde2cc" } ], "startTime": 1731672922434013, "duration": 1003499, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "client.address", "type": "string", "value": "127.0.0.1" }, { "key": "user_agent.original", "type": "string", "value": "Quarkus REST Client" }, { "key": "url.path", "type": "string", "value": "/wizard-server/step_3" }, { "key": "code.namespace", "type": "string", "value": "org.acme.server.WizardServerResource" }, { "key": "http.response.body.size", "type": "int64", "value": 11 }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "code.function", "type": "string", "value": "step3" }, { "key": "http.route", "type": "string", "value": "/wizard-server/step_3" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.scheme", "type": "string", "value": "http" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "server" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "f4af771e76197e50", "operationName": "GET /wizard-server/step_1", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "e83972f0306f2118" } ], "startTime": 1731672922432499, "duration": 1007849, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "client.address", "type": "string", "value": "127.0.0.1" }, { "key": "user_agent.original", "type": "string", "value": "Quarkus REST Client" }, { "key": "url.path", "type": "string", "value": "/wizard-server/step_1" }, { "key": "code.namespace", "type": "string", "value": "org.acme.server.WizardServerResource" }, { "key": "http.response.body.size", "type": "int64", "value": 11 }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "code.function", "type": "string", "value": "step1" }, { "key": "http.route", "type": "string", "value": "/wizard-server/step_1" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.scheme", "type": "string", "value": "http" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "server" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "e83972f0306f2118", "operationName": "GET /step_1", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "97a9eae6612ae05c" } ], "startTime": 1731672922431589, "duration": 1009121, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.full", "type": "string", "value": "http://localhost:8080/wizard-server/step_1" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "client" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "97a9eae6612ae05c", "operationName": "GET /wizard-client/work", "references": [], "startTime": 1731672920336452, "duration": 7116351, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "client.address", "type": "string", "value": "127.0.0.1" }, { "key": "url.path", "type": "string", "value": "/wizard-client/work" }, { "key": "code.namespace", "type": "string", "value": "org.acme.client.WizardClientResource" }, { "key": "http.response.body.size", "type": "int64", "value": 10 }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "http.route", "type": "string", "value": "/wizard-client/work" }, { "key": "user_agent.original", "type": "string", "value": "IntelliJ HTTP Client/IntelliJ IDEA 2024.2.3" }, { "key": "code.function", "type": "string", "value": "work" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "http.request.body.size", "type": "int64", "value": 0 }, { "key": "url.scheme", "type": "string", "value": "http" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "server" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "ed26d8a51091431c", "operationName": "GET /wizard-server/step_2", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "6ef91de78192d16b" } ], "startTime": 1731672922433616, "duration": 4006163, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "client.address", "type": "string", "value": "127.0.0.1" }, { "key": "user_agent.original", "type": "string", "value": "Quarkus REST Client" }, { "key": "url.path", "type": "string", "value": "/wizard-server/step_2" }, { "key": "code.namespace", "type": "string", "value": "org.acme.server.WizardServerResource" }, { "key": "http.response.body.size", "type": "int64", "value": 11 }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "code.function", "type": "string", "value": "step2" }, { "key": "http.route", "type": "string", "value": "/wizard-server/step_2" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.scheme", "type": "string", "value": "http" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "server" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "b320954bb3eadbb7", "operationName": "GET /complete", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "97a9eae6612ae05c" } ], "startTime": 1731672926443614, "duration": 1007537, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.full", "type": "string", "value": "http://localhost:8080/wizard-server/complete" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "client" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "a92ac52b7309b7e6", "operationName": "GET /wizard-server/complete", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "b320954bb3eadbb7" } ], "startTime": 1731672926444862, "duration": 1005187, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "client.address", "type": "string", "value": "127.0.0.1" }, { "key": "user_agent.original", "type": "string", "value": "Quarkus REST Client" }, { "key": "url.path", "type": "string", "value": "/wizard-server/complete" }, { "key": "code.namespace", "type": "string", "value": "org.acme.server.WizardServerResource" }, { "key": "http.response.body.size", "type": "int64", "value": 13 }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "code.function", "type": "string", "value": "complete" }, { "key": "http.route", "type": "string", "value": "/wizard-server/complete" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.scheme", "type": "string", "value": "http" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "server" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null }, { "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "6ef91de78192d16b", "operationName": "GET /step_3", "references": [ { "refType": "CHILD_OF", "traceID": "f839289a74ed082f3839bc6968765708", "spanID": "97a9eae6612ae05c" } ], "startTime": 1731672922432678, "duration": 4007676, "tags": [ { "key": "server.address", "type": "string", "value": "localhost" }, { "key": "http.request.method", "type": "string", "value": "GET" }, { "key": "server.port", "type": "int64", "value": 8080 }, { "key": "url.full", "type": "string", "value": "http://localhost:8080/wizard-server/step_2" }, { "key": "http.response.status_code", "type": "int64", "value": 200 }, { "key": "span.kind", "type": "string", "value": "client" }, { "key": "internal.span.format", "type": "string", "value": "otlp" } ], "logs": [], "processID": "p1", "warnings": null } ], "processes": { "p1": { "serviceName": "quarkus-open-telemetry-bug", "tags": [ { "key": "host.name", "type": "string", "value": "....local" }, { "key": "otel.library.name", "type": "string", "value": "io.quarkus.opentelemetry" }, { "key": "service.version", "type": "string", "value": "1.0.0-SNAPSHOT" }, { "key": "telemetry.sdk.language", "type": "string", "value": "java" }, { "key": "telemetry.sdk.name", "type": "string", "value": "opentelemetry" }, { "key": "telemetry.sdk.version", "type": "string", "value": "1.42.1" }, { "key": "webengine.name", "type": "string", "value": "Quarkus" }, { "key": "webengine.version", "type": "string", "value": "999-SNAPSHOT" } ] } }, "warnings": null } ], "total": 0, "limit": 0, "offset": 0, "errors": null }

When ClientObservabilityHandler calls this constructor, It does this for each of the identified template paths. So if you reuse the instance, some ClientObservabilityHandler will override the ClientUrlPathTemplate which is used to construct the correct operationName value.

https://github.com/quarkusio/quarkus/blob/main/independent-projects/resteasy-reactive/client/runtime/src/main/java/org/jboss/resteasy/reactive/client/handlers/ClientObservabilityHandler.java#L21

Okay, thanks.

I still am not a fan of this, so I want to spend a little more time next week exploring alternatives.

In any case, you've done excellent work here! I am going to try it out some more next week.

One reason I am skeptical, is that initially we did do it way you are proposing here, but it was changed in ac1a11e

Sounds good. Thank you so much for your support. I appreciate it.

I found that change (ac1a11e) two days ago but I didn't find the reasons why it was reverted. Please let me know if you find a better solution.

I will keep you updated

geoand · 2024-11-15T15:34:38Z

Can you please squash the commits and force push?

I would like to take this out of draft and see what CI says about it, because the more I look at it, the more I think the context handling here is correct

jcuero · 2024-11-15T16:14:28Z

Can you please squash the commits and force push?

I would like to take this out of draft and see what CI says about it, because the more I look at it, the more I think the context handling here is correct

Done!

brunobat · 2024-11-18T08:31:20Z

Please do a local build so imports get automatically sorted and the squash changes and push force again.

…dpoint being called Replacing the deprecated combinedWith Importing specific method instead of using * Organizing imports

quarkus-bot · 2024-11-18T13:07:18Z

Status for workflow `Quarkus CI`

This is the status report for running Quarkus CI on commit e3dda7e.

✅ The latest workflow run for the pull request has completed successfully.

It should be safe to merge provided you have a look at the other checks in the summary.

You can consult the Develocity build scans.

This comment was marked as resolved.

Sign in to view

quarkus-bot bot added the area/tracing label Nov 15, 2024

geoand changed the title ~~Fix: Ensuring that the name generated in opentelemetry matches the endpoint being called~~ Ensure that the name generated in opentelemetry matches the endpoint being called Nov 15, 2024

geoand reviewed Nov 15, 2024

View reviewed changes

brunobat requested changes Nov 15, 2024

View reviewed changes

geoand reviewed Nov 15, 2024

View reviewed changes

jcuero force-pushed the main branch from 02dbba1 to de6720b Compare November 15, 2024 16:13

geoand marked this pull request as ready for review November 18, 2024 06:12

This comment has been minimized.

Sign in to view

Fix: Ensuring that the name generated in opentelemetry matches the en…

e3dda7e

…dpoint being called Replacing the deprecated combinedWith Importing specific method instead of using * Organizing imports

jcuero force-pushed the main branch from de6720b to e3dda7e Compare November 18, 2024 11:04

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Ensure that the name generated in opentelemetry matches the endpoint being called #44523

Ensure that the name generated in opentelemetry matches the endpoint being called #44523

jcuero commented Nov 15, 2024 •

edited by geoand

Loading

This comment was marked as resolved.

quarkus-bot bot commented Nov 15, 2024

geoand commented Nov 15, 2024

geoand Nov 15, 2024

geoand Nov 15, 2024

geoand commented Nov 15, 2024

brunobat left a comment

brunobat Nov 15, 2024

geoand Nov 15, 2024

brunobat Nov 15, 2024 •

edited

Loading

geoand Nov 15, 2024 •

edited

Loading

jcuero Nov 15, 2024

jcuero Nov 15, 2024

geoand Nov 15, 2024

geoand Nov 15, 2024 •

edited

Loading

jcuero Nov 15, 2024

geoand Nov 15, 2024

geoand commented Nov 15, 2024 •

edited

Loading

jcuero commented Nov 15, 2024

This comment has been minimized.

brunobat commented Nov 18, 2024

quarkus-bot bot commented Nov 18, 2024 •

edited by github-actions bot

Loading

Ensure that the name generated in opentelemetry matches the endpoint being called #44523

Are you sure you want to change the base?

Ensure that the name generated in opentelemetry matches the endpoint being called #44523

Conversation

jcuero commented Nov 15, 2024 • edited by geoand Loading

This comment was marked as resolved.

quarkus-bot bot commented Nov 15, 2024

geoand commented Nov 15, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

geoand commented Nov 15, 2024

brunobat left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

brunobat Nov 15, 2024 • edited Loading

Choose a reason for hiding this comment

geoand Nov 15, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

geoand Nov 15, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

geoand commented Nov 15, 2024 • edited Loading

jcuero commented Nov 15, 2024

This comment has been minimized.

brunobat commented Nov 18, 2024

quarkus-bot bot commented Nov 18, 2024 • edited by github-actions bot Loading

Status for workflow Quarkus CI

jcuero commented Nov 15, 2024 •

edited by geoand

Loading

brunobat Nov 15, 2024 •

edited

Loading

geoand Nov 15, 2024 •

edited

Loading

geoand Nov 15, 2024 •

edited

Loading

geoand commented Nov 15, 2024 •

edited

Loading

quarkus-bot bot commented Nov 18, 2024 •

edited by github-actions bot

Loading

Status for workflow `Quarkus CI`