smallrye-jwt can not be used with JAX-RS and smallrye-open-tracing

[sberyozkin]

Describe the bug
See quarkusio/quarkus-quickstarts#369

Expected behavior
Excluding quarkus-undertow should be enough. (it should probably be excluded from quarkus-smallrye-opentracing)

Actual behavior
Adding

<dependency>
      <groupId>io.quarkus</groupId>
      <artifactId>quarkus-smallrye-opentracing</artifactId>
      <exclusions>
       <exclusion>
        <groupId>io.quarkus</groupId>
        <artifactId>quarkus-undertow</artifactId>
      </exclusion>
     </exclusions>
  </dependency>

to https://github.com/quarkusio/quarkus-quickstarts/blob/development/security-jwt-quickstart/pom.xml

cause the test failure with

org.junit.jupiter.api.extension.TestInstantiationException: TestInstanceFactory [io.quarkus.test.junit.QuarkusTestExtension] failed to instantiate test class [org.acme.jwt.TokenSecuredResourceTest]
Caused by: java.lang.ExceptionInInitializerError
Caused by: java.lang.RuntimeException: Failed to start quarkus
Caused by: java.lang.NoClassDefFoundError: io/quarkus/undertow/runtime/UndertowDeploymentRecorder
Caused by: java.lang.ClassNotFoundException: io.quarkus.undertow.runtime.UndertowDeploymentRecorder

[sean-scott-lr]

Thank you @sberyozkin

[sean-scott-lr]

Some other datapoints...

the quarkus:dev maven extension apparently pulls in some dependencies that the application doesnt need. Which causes it to pull in a servlet implementation and undertow. When not using the quarkus:dev plugin, you dont get the ClassNotFoundException above. Only when running "test" do you see that error.

[sean-scott-lr]

Also, simply adding the opentracing extension to my pom file, COMPLETELY changes the execution of the webservice. I added 'new Throwable().printStackTrace()to thehello` method. Then executed it with and without the opentracing dependency.

without opentracing:

2019-11-13 11:58:36,565 INFO  [io.quarkus] (main) Installed features: [cdi, resteasy, resteasy-jsonb, security, smallrye-jwt, vertx, vertx-web]
java.lang.Throwable
	at org.acme.jwt.TokenSecuredResource.hello(TokenSecuredResource.java:45)
	at org.acme.jwt.TokenSecuredResource_Subclass.hello$$superaccessor3(TokenSecuredResource_Subclass.zig:148)
	at org.acme.jwt.TokenSecuredResource_Subclass$$function$$3.apply(TokenSecuredResource_Subclass$$function$$3.zig:51)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
	at io.quarkus.security.runtime.interceptor.SecurityHandler.handle(SecurityHandler.java:26)
	at io.quarkus.security.runtime.interceptor.PermitAllInterceptor.intercept(PermitAllInterceptor.java:23)
	at io.quarkus.security.runtime.interceptor.PermitAllInterceptor_Bean.intercept(PermitAllInterceptor_Bean.zig:241)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
	at org.acme.jwt.TokenSecuredResource_Subclass.hello(TokenSecuredResource_Subclass.zig:1018)
	at org.acme.jwt.TokenSecuredResource_ClientProxy.hello(TokenSecuredResource_ClientProxy.zig:312)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:151)
	at org.jboss.resteasy.core.MethodInjectorImpl.lambda$invoke$3(MethodInjectorImpl.java:122)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:143)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:122)
	at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:594)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:468)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:421)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:363)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:423)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:391)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invoke$1(ResourceMethodInvoker.java:365)
	at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:143)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:365)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:477)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:252)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:153)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:363)
	at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:156)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:238)
	at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:109)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatchRequestContext(VertxRequestHandler.java:84)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.lambda$handle$0(VertxRequestHandler.java:71)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$2(ContextImpl.java:316)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:834)

With opentracing

2019-11-13 12:00:35,646 INFO  [io.quarkus] (main) Installed features: [cdi, jaeger, resteasy, resteasy-jsonb, security, servlet, smallrye-jwt, smallrye-opentracing, vertx, vertx-web]
    java.lang.Throwable
	at org.acme.jwt.TokenSecuredResource.hello(TokenSecuredResource.java:45)
	at org.acme.jwt.TokenSecuredResource_Subclass.hello$$superaccessor4(TokenSecuredResource_Subclass.zig:163)
	at org.acme.jwt.TokenSecuredResource_Subclass$$function$$4.apply(TokenSecuredResource_Subclass$$function$$4.zig:51)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
	at io.quarkus.security.runtime.interceptor.SecurityHandler.handle(SecurityHandler.java:26)
	at io.quarkus.security.runtime.interceptor.PermitAllInterceptor.intercept(PermitAllInterceptor.java:23)
	at io.quarkus.security.runtime.interceptor.PermitAllInterceptor_Bean.intercept(PermitAllInterceptor_Bean.zig:241)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:41)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:32)
	at org.acme.jwt.TokenSecuredResource_Subclass.hello(TokenSecuredResource_Subclass.zig:1018)
	at org.acme.jwt.TokenSecuredResource_ClientProxy.hello(TokenSecuredResource_ClientProxy.zig:312)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:151)
	at org.jboss.resteasy.core.MethodInjectorImpl.lambda$invoke$3(MethodInjectorImpl.java:122)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:680)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094)
	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:143)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:122)
	at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:594)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:468)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:421)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:363)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:423)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:391)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invoke$1(ResourceMethodInvoker.java:365)
	at java.base/java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235)
	at java.base/java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:143)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:365)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:477)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:252)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:153)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:363)
	at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:156)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:238)
	at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:249)
	at io.quarkus.resteasy.runtime.ResteasyFilter$ResteasyResponseWrapper.sendError(ResteasyFilter.java:65)
	at io.undertow.servlet.handlers.DefaultServlet.doGet(DefaultServlet.java:172)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:503)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
	at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
	at io.quarkus.resteasy.runtime.ResteasyFilter.doFilter(ResteasyFilter.java:28)
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
	at io.opentracing.contrib.jaxrs2.server.SpanFinishingFilter.doFilter(SpanFinishingFilter.java:52)
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
	at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
	at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:63)
	at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
	at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
	at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:133)
	at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
	at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:65)
	at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
	at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
	at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
	at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:270)
	at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:59)
	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:116)
	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:113)
	at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
	at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
	at io.quarkus.undertow.runtime.UndertowDeploymentRecorder$9$1$1.call(UndertowDeploymentRecorder.java:469)
	at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:250)
	at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:59)
	at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:82)
	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:290)
	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:669)
	at io.quarkus.runtime.CleanableExecutor$CleaningRunnable.run(CleanableExecutor.java:224)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2011)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1535)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1426)
	at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
	at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
	at java.base/java.lang.Thread.run(Thread.java:834)
	at org.jboss.threads.JBossThread.run(JBossThread.java:479)

[gsmet]

@stuartwdouglas looks like we missed OpenTracing when working on the new HTTP layer and it still depends on Undertow.

Is it something we should fix before Final?

[gsmet]

BTW, apart from that, shouldn't the smallrye-jwt extension work with Undertow anyway? I think we have 2 different issues here.

[stuartwdouglas]

@patriot1burke do you have any ideas how to make this work? This is implemented as a combination of RESTEasy feature + Servlet filter. The Feature seems to start the tracing, then it relies on the Servlet filter to either close it or register a listener to close it when the request is done.

Is it possible to do this all in RESTeasy?

[pavolloffay]

The servlet filter is used because JAX-RS response filter is not being invoked if there is an exception thrown during the invocation. The servlet filter is only used to finish the span and log exceptions (if any).

If RestEasy or any other underlying stack provides API to wire in after the request processing the fix should be easy.

Servlet filter:
https://github.com/opentracing-contrib/java-jaxrs/blob/master/opentracing-jaxrs2/src/main/java/io/opentracing/contrib/jaxrs2/server/SpanFinishingFilter.java#L67
MP TCK that tests exception in a handler https://github.com/eclipse/microprofile-opentracing/blob/c7d33bdd10a4031c75f23a597b5bb881bba03996/tck/base/src/main/java/org/eclipse/microprofile/opentracing/tck/application/TestServerWebServices.java#L239

[sberyozkin]

@gsmet quarkus-smallrye-jwt needs to work with the authentication mechanism directly and now depends on the vertx-http one. For it to also work with Undertow, we'd have to split it into quarkus-smallrye-jwt-common and the existing smallrye-jwt(-vertx is default) and smallrye-jwt-undertow. Or perhaps, have HttpAuthenticationMechanism located in the shared module which both Undertow (blocking) and VertxHTTP (non-blocking) would back up.
But since adding Undertow is only about for JAX-RS apps to have HttpServletRequest or I guess even do servlet filters, I'm not sure how critical it is. I suppose we can create an issue to investigate, but may be when some users would actually ask for it...
FYI, OIDC adapter is also Vertx based :-)
It is an interesting question, what if some not only smalrye-jwt but also OIDC users on the Vertx path would want to get HttpServletFilter/etc. For JAX-RS we can say, simply use JAX-RS contexts/types, but if they want to use servlets - no luck - I'm not sure how concerned should we be about this case... thanks

[patriot1burke]

@pavolloffay IIRC, JAX-RS response filters should be run no matter what, even if there is an exception thrown from the method.

[objectiser]

@patriot1burke Just checked, the ContainerResponseFilter is not called when an exception is thrown, so looks like using the HttpServletFilter is the only way to deal with the exception case, and finish the span.

Tried out the example from the original issue, and the tracing information is still recorded, including the exception (stream closed):

The other interesting thing is that not all endpoints are causing the exception:

(using the curl http://127.0.0.1:8080/secured/permit-all command).

[pavolloffay]

@pavolloffay IIRC, JAX-RS response filters should be run no matter what, even if there is an exception thrown from the method.

Unfortunately, this is not true for any JAX-RS implementation I could find.

[sberyozkin]

@pavolloffay I'd expect this to work as well (with at least one implementation I'm aware of), the exception has to be mapped, either to a custom or default exception (WebApplicationException) and the exceptional Response - routed through the response filters. CC @asoldano - Hi Alessio, FYI, is there a way to make it work with RestEasy ?

[asoldano]

@pavolloffay I'd expect this to work as well (with at least one implementation I'm aware of), the exception has to be mapped, either to a custom or default exception (WebApplicationException) and the exceptional Response - routed through the response filters. CC @asoldano - Hi Alessio, FYI, is there a way to make it work with RestEasy ?

I think so, but we'd have to try. Is this still relevant, given the PR is now closed?

[pavolloffay]

@asoldano IIRC there were problems with using default exception mapper.

E.g. we do not what to annotate span with an error for an application-specific exception which is properly handled and does not result in an error code. Other issue might be - is the default exception mapper invoked if there is an exception mapper for a specific exception?

Feel free to move this to https://github.com/opentracing-contrib/java-jaxrs or create a PR :)