RestClient & Multi emitter splat: maximum forwards exceeded #8795

roysjosh · 2020-04-23T17:27:25Z

Describe the bug
Using Quarkus 1.3.2, a FooResource returning a Multi and using an emitter gets a splat after making a certain number of RestClient calls to an external REST API.

javax.ws.rs.BadRequestException: RESTEASY003315: You have exceeded your maximum forwards ResteasyProviderFactory allows.

Expected behavior
There should not be a limitation on number of calls an injected RestClient can make.

Actual behavior
While querying external resources and associated sub-resources, any reference to the resource/object (e.g. emitter.emit(foo.getField()) increases org.jboss.resteasy.core.ResteasyContext.getContextDataLevelCount() eventually hitting the limit of 20.

To Reproduce

@Path("/projects")
public class FooResource {
 
    @Inject
    @RestClient
    FooClient fooClient;
 
    @GET
    @Path("/{orgName}/analyze")
    @Produces(MediaType.SERVER_SENT_EVENTS)
    public Multi<Object> analyzeOrgProjects(
            @HeaderParam(HttpHeaders.AUTHORIZATION) String auth,
            @PathParam("orgName") String orgName) {
 
        return Multi.createFrom().emitter(emitter -> {
            // XXX lots of fooClient.getFoo calls here
            // XXX some of them return a Set and we recurse into them with .forEach
            // XXX it seems to splat based on number of calls not depth though
        });
    }
}

Screenshots

javax.ws.rs.BadRequestException: RESTEASY003315: You have exceeded your maximum forwards ResteasyProviderFactory allows.  Last good uri: /projects/joshuaroys0870/analyze
	at org.jboss.resteasy.core.ResteasyContext.addContextDataLevel(ResteasyContext.java:68)
	at org.jboss.resteasy.core.ResteasyContext.addCloseableContextDataLevel(ResteasyContext.java:77)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.pushProvidersContext(ClientInvocation.java:664)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:482)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:149)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invoke(ClientInvoker.java:112)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientProxy.invoke(ClientProxy.java:76)
	at com.sun.proxy.$Proxy26.getProjectBuildChanges(Unknown Source)
	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.microprofile.client.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:149)
	at com.sun.proxy.$Proxy29.getProjectBuildChanges(Unknown Source)
	at com.foo.skunk.theia.FooResource.lambda$analyzeOrgProjects$3(FooResource.java:91)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at com.foo.skunk.theia.FooResource.lambda$analyzeOrgProjects$4(FooResource.java:88)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at com.foo.skunk.theia.FooResource.lambda$analyzeOrgProjects$5(FooResource.java:59)
	at io.smallrye.mutiny.operators.multi.builders.EmitterBasedMulti.subscribe(EmitterBasedMulti.java:53)
	at io.smallrye.mutiny.operators.AbstractMulti.subscribe(AbstractMulti.java:48)
	at io.smallrye.mutiny.groups.MultiSubscribe.withSubscriber(MultiSubscribe.java:48)
	at io.smallrye.mutiny.context.ContextPropagationMultiInterceptor$2.lambda$subscribe$0(ContextPropagationMultiInterceptor.java:58)
	at io.smallrye.context.SmallRyeThreadContext.lambda$withContext$0(SmallRyeThreadContext.java:215)
	at io.smallrye.mutiny.context.ContextPropagationMultiInterceptor$2.subscribe(ContextPropagationMultiInterceptor.java:58)
	at org.jboss.resteasy.core.AsyncResponseConsumer$AsyncStreamResponseConsumer.subscribe(AsyncResponseConsumer.java:322)
	at org.jboss.resteasy.core.ResourceMethodInvoker.afterInvoke(ResourceMethodInvoker.java:516)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:495)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:437)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:362)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:439)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:400)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:374)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:67)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:488)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:259)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:160)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:362)
	at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:163)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:245)
	at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:122)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.access$000(VertxRequestHandler.java:36)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:87)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2027)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1551)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1442)
	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)

Environment (please complete the following information):

Output of uname -a or ver: Darwin $HOSTNAME 19.4.0 Darwin Kernel Version 19.4.0: Wed Mar 4 22:28:40 PST 2020; root:xnu-6153.101.6~15/RELEASE_X86_64 x86_64
Output of java -version:

openjdk version "11.0.6" 2020-01-14 LTS
OpenJDK Runtime Environment Corretto-11.0.6.10.1 (build 11.0.6+10-LTS)
OpenJDK 64-Bit Server VM Corretto-11.0.6.10.1 (build 11.0.6+10-LTS, mixed mode)

GraalVM version (if different from Java):
Quarkus version or git rev: 1.3.2.Final
Build tool (ie. output of mvnw --version or gradlew --version):

Gradle 5.6.4

Build time: 2019-11-01 20:42:00 UTC
Revision: dd870424f9bd8e195d614dc14bb140f43c22da98

Kotlin: 1.3.41
Groovy: 2.5.4
Ant: Apache Ant(TM) version 1.9.14 compiled on March 12 2019
JVM: 11.0.6 (Amazon.com Inc. 11.0.6+10-LTS)
OS: Mac OS X 10.15.4 x86_64

Additional context
:(

The text was updated successfully, but these errors were encountered:

gsmet · 2020-04-23T20:31:04Z

/cc @cescoffier @FroMage @asoldano

FroMage · 2020-04-24T09:03:15Z

Could you give me a reproducer? This looks like I have to guess what to put in the method body.

FroMage · 2020-04-24T10:17:18Z

This looks like the client is pushing too many contexts and not popping them.

FroMage · 2020-04-24T10:17:38Z

I could try with subsequent 20 calls.

FroMage · 2020-04-24T12:59:51Z

I can't reproduce it, even with 400 calls. Perhaps it's due to the Multi use, where each call is on the stack and we end up making a client call within the context of another client call?

It'd be easier if you could give me a reproducer.

@cescoffier opinions?

FroMage · 2020-04-24T13:21:43Z

Perhaps it's due to the Multi use, where each call is on the stack and we end up making a client call within the context of another client call?

Looking at the stack trace it seems highly impossible.

roysjosh · 2020-04-24T14:17:09Z

Cheesed, I mean pleased, to digitally meet you. Thanks for taking a look.

https://github.com/roysjosh/quarkus-restclient-multi-splat

2020-04-24 10:08:15,343 INFO  [io.quarkus] (main) splat 1.0.0 (powered by Quarkus 1.3.2.Final) started in 0.929s. Listening on: http://0.0.0.0:8080
2020-04-24 10:08:15,382 INFO  [io.quarkus] (main) Profile prod activated. 
2020-04-24 10:08:15,383 INFO  [io.quarkus] (main) Installed features: [cdi, mutiny, rest-client, resteasy, resteasy-jsonb, resteasy-mutiny]
Querying postal code 75009 with context level 1
Querying postal code 75008 with context level 2
Querying postal code 75019 with context level 3
Querying postal code 75007 with context level 4
Querying postal code 75018 with context level 5
Querying postal code 75006 with context level 6
Querying postal code 75017 with context level 7
Querying postal code 75005 with context level 8
Querying postal code 75016 with context level 9
Querying postal code 75004 with context level 10
Querying postal code 75015 with context level 11
Querying postal code 75003 with context level 12
Querying postal code 75014 with context level 13
Querying postal code 75002 with context level 14
Querying postal code 75013 with context level 15
Querying postal code 75001 with context level 16
Querying postal code 75012 with context level 17
Querying postal code 75011 with context level 18
Querying postal code 75010 with context level 19
Querying postal code 75020 with context level 20
javax.ws.rs.BadRequestException: RESTEASY003315: You have exceeded your maximum forwards ResteasyProviderFactory allows.  Last good uri: /hello
	at org.jboss.resteasy.core.ResteasyContext.addContextDataLevel(ResteasyContext.java:68)
	at org.jboss.resteasy.core.ResteasyContext.addCloseableContextDataLevel(ResteasyContext.java:77)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.pushProvidersContext(ClientInvocation.java:664)
	at org.jboss.resteasy.client.jaxrs.internal.ClientInvocation.invoke(ClientInvocation.java:482)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invokeSync(ClientInvoker.java:149)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientInvoker.invoke(ClientInvoker.java:112)
	at org.jboss.resteasy.client.jaxrs.internal.proxy.ClientProxy.invoke(ClientProxy.java:76)
	at com.sun.proxy.$Proxy25.getCommunes(Unknown Source)
	at jdk.internal.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
	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.microprofile.client.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:149)
	at com.sun.proxy.$Proxy28.getCommunes(Unknown Source)
	at com.example.fr.SplatResource.lambda$hello$0(SplatResource.java:32)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at com.example.fr.SplatResource.lambda$hello$1(SplatResource.java:29)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at com.example.fr.SplatResource.lambda$hello$2(SplatResource.java:28)
	at io.smallrye.mutiny.operators.multi.builders.EmitterBasedMulti.subscribe(EmitterBasedMulti.java:53)
	at io.smallrye.mutiny.operators.AbstractMulti.subscribe(AbstractMulti.java:48)
	at io.smallrye.mutiny.groups.MultiSubscribe.withSubscriber(MultiSubscribe.java:48)
	at io.smallrye.mutiny.context.ContextPropagationMultiInterceptor$2.lambda$subscribe$0(ContextPropagationMultiInterceptor.java:58)
	at io.smallrye.context.SmallRyeThreadContext.lambda$withContext$0(SmallRyeThreadContext.java:215)
	at io.smallrye.mutiny.context.ContextPropagationMultiInterceptor$2.subscribe(ContextPropagationMultiInterceptor.java:58)
	at org.jboss.resteasy.core.AsyncResponseConsumer$AsyncStreamResponseConsumer.subscribe(AsyncResponseConsumer.java:322)
	at org.jboss.resteasy.core.ResourceMethodInvoker.afterInvoke(ResourceMethodInvoker.java:516)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:495)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$2(ResourceMethodInvoker.java:437)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:362)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:439)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:400)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:374)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:67)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:488)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:259)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:160)
	at org.jboss.resteasy.core.interception.jaxrs.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:362)
	at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:163)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:245)
	at io.quarkus.resteasy.runtime.standalone.RequestDispatcher.service(RequestDispatcher.java:73)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.dispatch(VertxRequestHandler.java:122)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler.access$000(VertxRequestHandler.java:36)
	at io.quarkus.resteasy.runtime.standalone.VertxRequestHandler$1.run(VertxRequestHandler.java:87)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:2027)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1551)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1442)
	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 · 2020-05-04T14:48:22Z

@FroMage could you have a look at the reproducer? This looks like a serious issue.

Thanks!

FroMage · 2020-05-05T07:47:51Z

Yeah, I was finally able to find where it's coming from. Working on a fix in RESTEasy.

FroMage · 2020-05-05T08:54:16Z

Logged at https://issues.redhat.com/projects/RESTEASY/issues/RESTEASY-2573

FroMage · 2020-05-05T09:13:52Z

Fix is at resteasy/resteasy#2383

FroMage · 2020-05-15T14:34:47Z

Fixed upstream. Now waiting for a release.

FroMage · 2020-06-16T12:34:05Z

Upstream says this is fixed in 4.5.4.Final but it's not. Something went wrong with the release: https://issues.redhat.com/browse/RESTEASY-2573?focusedCommentId=14159817&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-14159817

asoldano · 2020-06-16T12:41:18Z

Yes, the team is aware of this, a new release (4.5.5.Final) is being tagged today.

FroMage · 2020-06-16T12:48:40Z

Oh, OK, great news, thanks :)

FroMage · 2020-06-17T08:50:38Z

I validate that 4.5.5.Final fixes it, made a PR to bump our RESTEasy dep and added a test for this at #10069.

gsmet · 2020-07-18T14:55:46Z

This one has been solved in 1.6.0.CR1.

roysjosh added the kind/bug Something isn't working label Apr 23, 2020

gsmet added the triage/backport? label Apr 23, 2020

FroMage added a commit to FroMage/quarkus that referenced this issue Jun 17, 2020

Bump RESTEasy version to 4.5.5.Final, added test for quarkusio#8795

9eb721e

johnaohara pushed a commit to johnaohara/quarkus that referenced this issue Jun 29, 2020

Bump RESTEasy version to 4.5.5.Final, added test for quarkusio#8795

93e0fc6

gsmet added this to the 1.6.0.CR1 milestone Jul 18, 2020

gsmet removed the triage/backport? label Jul 18, 2020

gsmet closed this as completed Jul 18, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

RestClient & Multi emitter splat: maximum forwards exceeded #8795

RestClient & Multi emitter splat: maximum forwards exceeded #8795

roysjosh commented Apr 23, 2020 •

edited

Gradle 5.6.4

gsmet commented Apr 23, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

roysjosh commented Apr 24, 2020

gsmet commented May 4, 2020

FroMage commented May 5, 2020

FroMage commented May 5, 2020

FroMage commented May 5, 2020

FroMage commented May 15, 2020

FroMage commented Jun 16, 2020

asoldano commented Jun 16, 2020

FroMage commented Jun 16, 2020

FroMage commented Jun 17, 2020

gsmet commented Jul 18, 2020

RestClient & Multi emitter splat: maximum forwards exceeded #8795

RestClient & Multi emitter splat: maximum forwards exceeded #8795

Comments

roysjosh commented Apr 23, 2020 • edited

Gradle 5.6.4

gsmet commented Apr 23, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

FroMage commented Apr 24, 2020

roysjosh commented Apr 24, 2020

gsmet commented May 4, 2020

FroMage commented May 5, 2020

FroMage commented May 5, 2020

FroMage commented May 5, 2020

FroMage commented May 15, 2020

FroMage commented Jun 16, 2020

asoldano commented Jun 16, 2020

FroMage commented Jun 16, 2020

FroMage commented Jun 17, 2020

gsmet commented Jul 18, 2020

roysjosh commented Apr 23, 2020 •

edited