quarkusio / quarkus

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

REST request fails after adding maven dependency to quarkus-opentelemetry #41854

Open bechhansen opened 3 weeks ago

bechhansen commented 3 weeks ago

Describe the bug

After adding the quarkus-opentelemetry dependency to our maven project, we have experienced endpoints using URL prefix and a default empty path is failing.

If we don't use URL prefix we don't see the error, and this is currently our workaround.

Apparently the way URLs are evaluated in quarkus-opentelemetry is different from resteasy reactive I expect the solution to this issue is to use the same getPathWithoutPrefix method both places.

Please have a look at https://github.com/quarkusio/quarkus/blob/main/extensions/resteasy-reactive/rest/runtime/src/main/java/io/quarkus/resteasy/reactive/server/runtime/observability/ObservabilityIntegrationRecorder.java#L119 and https://github.com/quarkusio/quarkus/blob/main/independent-projects/resteasy-reactive/server/runtime/src/main/java/org/jboss/resteasy/reactive/server/core/ResteasyReactiveRequestContext.java#L431

When the path evaluation is out of sync, we will get an error when calling substring here: https://github.com/quarkusio/quarkus/blob/main/independent-projects/resteasy-reactive/server/runtime/src/main/java/org/jboss/resteasy/reactive/server/mapping/RequestMapper.java#L112

Expected behavior

We expect existing rest endpoint to keep working after adding the quarkus-opentelemetry dependency

Actual behavior

Our rest request fails after the quarkus-opentelemetry dependency was added.

This is the returned stacktrace:

{
    "details": "Error id 657d1068-0aae-47f2-9bf6-f98dab005dc9-1, java.lang.StringIndexOutOfBoundsException: Range [1, 1) out of bounds for length 0",
    "stack": "java.lang.StringIndexOutOfBoundsException: Range [1, 1) out of bounds for length 0\r\n\tat java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:55)\r\n\tat java.base/jdk.internal.util.Preconditions$1.apply(Preconditions.java:52)\r\n\tat java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:213)\r\n\tat java.base/jdk.internal.util.Preconditions$4.apply(Preconditions.java:210)\r\n\tat java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:98)\r\n\tat java.base/jdk.internal.util.Preconditions.outOfBoundsCheckFromToIndex(Preconditions.java:112)\r\n\tat java.base/jdk.internal.util.Preconditions.checkFromToIndex(Preconditions.java:349)\r\n\tat java.base/java.lang.String.checkBoundsBeginEnd(String.java:4865)\r\n\tat java.base/java.lang.String.substring(String.java:2834)\r\n\tat org.jboss.resteasy.reactive.server.mapping.RequestMapper.mapFromPathMatcher(RequestMapper.java:112)\r\n\tat org.jboss.resteasy.reactive.server.mapping.RequestMapper.map(RequestMapper.java:53)\r\n\tat io.quarkus.resteasy.reactive.server.runtime.observability.ObservabilityIntegrationRecorder.setTemplatePath(ObservabilityIntegrationRecorder.java:56)\r\n\tat io.quarkus.resteasy.reactive.server.runtime.ResteasyReactiveRecorder$13.handle(ResteasyReactiveRecorder.java:352)\r\n\tat io.quarkus.resteasy.reactive.server.runtime.ResteasyReactiveRecorder$13.handle(ResteasyReactiveRecorder.java:347)\r\n\tat io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1285)\r\n\tat io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)\r\n\tat io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:137)\r\n\tat io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AuthenticationHandler$3$1.onItem(HttpSecurityRecorder.java:311)\r\n\tat io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AuthenticationHandler$3$1.onItem(HttpSecurityRecorder.java:301)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:60)\r\n\tat io.smallrye.mutiny.operators.uni.builders.DefaultUniEmitter.complete(DefaultUniEmitter.java:37)\r\n\tat io.smallrye.mutiny.groups.UniOnNull.lambda$failWith$1(UniOnNull.java:46)\r\n\tat io.smallrye.context.impl.wrappers.SlowContextualBiConsumer.accept(SlowContextualBiConsumer.java:21)\r\n\tat io.smallrye.mutiny.groups.UniOnItem.lambda$transformToUni$4(UniOnItem.java:177)\r\n\tat io.smallrye.context.impl.wrappers.SlowContextualConsumer.accept(SlowContextualConsumer.java:21)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateWithEmitter.subscribe(UniCreateWithEmitter.java:22)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.performInnerSubscription(UniOnItemTransformToUni.java:81)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:57)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription.forward(UniCreateFromKnownItem.java:38)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem.subscribe(UniCreateFromKnownItem.java:23)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni.subscribe(UniOnItemTransformToUni.java:25)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:51)\r\n\tat io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AuthenticationHandler$3.onItem(HttpSecurityRecorder.java:301)\r\n\tat io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AuthenticationHandler$3.onItem(HttpSecurityRecorder.java:286)\r\n\tat io.smallrye.mutiny.operators.uni.UniMemoizeOp.forwardTo(UniMemoizeOp.java:123)\r\n\tat io.smallrye.mutiny.operators.uni.UniMemoizeOp.notifyAwaiters(UniMemoizeOp.java:135)\r\n\tat io.smallrye.mutiny.operators.uni.UniMemoizeOp.onItem(UniMemoizeOp.java:97)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:60)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription.forward(UniCreateFromKnownItem.java:38)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem.subscribe(UniCreateFromKnownItem.java:23)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.performInnerSubscription(UniOnItemTransformToUni.java:81)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:57)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:60)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription.forward(UniCreateFromKnownItem.java:38)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem.subscribe(UniCreateFromKnownItem.java:23)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.performInnerSubscription(UniOnItemTransformToUni.java:81)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor.onItem(UniOnItemTransformToUni.java:57)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransform$UniOnItemTransformProcessor.onItem(UniOnItemTransform.java:43)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransform$UniOnItemTransformProcessor.onItem(UniOnItemTransform.java:43)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription.forward(UniCreateFromKnownItem.java:38)\r\n\tat io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem.subscribe(UniCreateFromKnownItem.java:23)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransform.subscribe(UniOnItemTransform.java:22)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransform.subscribe(UniOnItemTransform.java:22)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni.subscribe(UniOnItemTransformToUni.java:25)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni.subscribe(UniOnItemTransformToUni.java:25)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:51)\r\n\tat io.smallrye.mutiny.operators.uni.UniMemoizeOp.subscribe(UniMemoizeOp.java:59)\r\n\tat io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)\r\n\tat io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:51)\r\n\tat io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AuthenticationHandler.handle(HttpSecurityRecorder.java:286)\r\n\tat io.quarkus.vertx.http.runtime.security.HttpSecurityRecorder$AuthenticationHandler.handle(HttpSecurityRecorder.java:233)\r\n\tat io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1285)\r\n\tat io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)\r\n\tat io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:137)\r\n\tat io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup$5.handle(VertxHttpHotReplacementSetup.java:204)\r\n\tat io.quarkus.vertx.http.runtime.devmode.VertxHttpHotReplacementSetup$5.handle(VertxHttpHotReplacementSetup.java:192)\r\n\tat io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)\r\n\tat io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)\r\n\tat io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)\r\n\tat io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)\r\n\tat io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)\r\n\tat io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)\r\n\tat io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)\r\n\tat io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)\r\n\tat java.base/java.lang.Thread.run(Thread.java:1583)"
}

How to Reproduce?

I have created a small project that reproduces the issue.

Start the server and make a request for http://localhost:8080/demo Notice the issue only occur when we have another rest endpoint defined that takes URL parameters. rest-json-quickstart.zip

Output of uname -a or ver

Microsoft Windows [Version 10.0.19045.4529]

Output of java -version

openjdk version "21.0.2" 2024-01-16 LTS

Quarkus version or git rev

3.12.2

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

Apache Maven 3.9.2 (c9616018c7a021c1c39be70fb2843d6f5f9b8a1c)

Additional information

No response

quarkus-bot[bot] commented 3 weeks ago

/cc @brunobat (opentelemetry), @quarkusio/devtools (maven), @radcortez (opentelemetry)

brunobat commented 3 weeks ago

@bechhansen what do you mean by url prefix? can you please provide an example of an endpoint that will trigger that error in the sample project?

bechhansen commented 3 weeks ago

@bechhansen what do you mean by url prefix? can you please provide an example of an endpoint that will trigger that error in the sample project?

Hey @brunobat Wow, quick response.

By url prefix I mean the url defined by the annotation @ApplicationPath in the jakarta.ws.rs.core.Application subclass.

package com.demo;

import jakarta.ws.rs.ApplicationPath;
import jakarta.ws.rs.core.Application;

@ApplicationPath("/demo")
public class DemoApplication extends Application {
}

I have added a very simple project as a zip to this issue. It contains configuration and an endpoint that reproduces the issue. The path is http://localhost:8080/demo

brunobat commented 3 weeks ago

This is strange. When you define @ApplicationPath("/demo") you are saying that all endpoints will be after that. Then you define a class with @Path("/{id}/dummy") And another with @Path("/") If you call http://localhost:8080/demo you get an exception, But if you call http://localhost:8080/demo/ it works ok. Looks almost like we are missing a "" entry for the initMappers here: https://github.com/quarkusio/quarkus/blob/8694c5ca9ca542638f511b7b06844bbdd188bd09/extensions/resteasy-reactive/rest/runtime/src/main/java/io/quarkus/resteasy/reactive/server/runtime/observability/ObservabilityIntegrationRecorder.java#L55

brunobat commented 3 weeks ago

what do you think @geoand ?

geoand commented 3 weeks ago

I'll check next week

geoand commented 3 weeks ago

@bechhansen as you have already analyzed the situation, care to provide a Pull Request with the fix you have in mind? Including a test would be awesome :)

bechhansen commented 3 weeks ago

@bechhansen as you have already analyzed the situation, care to provide a Pull Request with the fix you have in mind? Including a test would be awesome :)

I'll try to find time to have a look during this week.

geoand commented 3 weeks ago

Cool, thanks

bechhansen commented 2 weeks ago

@geoand how do you like this solution? https://github.com/quarkusio/quarkus/commit/28cc1dcfb8044d3d1618591ba192958cb2946928

I have yet to write tests.

geoand commented 2 weeks ago

Yeah, that looks nice. A few tests and it should be good to go :)

bechhansen commented 2 weeks ago

Hi. I wrote a test that reproduced the issue and verifies that the change will fix it. I think ObservabilityIntegrationRecorder could use some more testing, but I do not have the time to do more testing not relevant for this issue. I hope it is sufficient.

geoand commented 2 weeks ago

Yeah, that should be fine

bechhansen commented 2 weeks ago

Excellent. Am I to do more, or will the PR eventually be merged?

geoand commented 2 weeks ago

Go ahead and open it and I'll have a closer look tomorrow