Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

API Calls failing with exception - Entity has already been requested. Entity cannot be requested multiple times #8349

Closed
GeezFORCE opened this issue Feb 8, 2024 · 11 comments · Fixed by #8558
Assignees
Labels
4.x Version 4.x bug Something isn't working jersey MP P2 webserver
Milestone

Comments

@GeezFORCE
Copy link

We have a set of API endpoints exposed in our helidon application and after upgrading to Helidon 4, it fails with the above exception

Environment Details

  • Helidon Version: 4.0.4 (Upgrading from 3.2.2)
  • Helidon MP
  • JDK version: 21
  • OS: Mac OS
  • Docker version (if applicable): NA

Problem Description

We are trying to upgrade our Helidon application from v3 to v4. After the upgrade, requests to the API endpoints are failing with the exception "Entity has already been requested. Entity cannot be requested multiple times" (refer attached stack trace). The exception occurs before the logic of the endpoint comes into picture and it seems to come from the Helidon server itself.

Following is the full stack trace.

Internal server error
io.helidon.http.RequestException: Entity has already been requested. Entity cannot be requested multiple times
	at io.helidon.http.RequestException$Builder.build(RequestException.java:139) ~[helidon-http-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.ErrorHandlers.unhandledError(ErrorHandlers.java:202) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.ErrorHandlers.lambda$handleError$1(ErrorHandlers.java:182) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at java.util.Optional.ifPresentOrElse(Optional.java:198) ~[?:?]
	at io.helidon.webserver.http.ErrorHandlers.handleError(ErrorHandlers.java:181) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.ErrorHandlers.runWithErrorHandling(ErrorHandlers.java:118) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:121) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.observe.metrics.MetricsFeature.lambda$configureVendorMetrics$2(MetricsFeature.java:90) ~[helidon-webserver-observe-metrics-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:119) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.security.SecurityContextFilter.filter(SecurityContextFilter.java:88) ~[helidon-webserver-security-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:119) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.common.context.Contexts.runInContext(Contexts.java:117) ~[helidon-common-context-4.0.4.jar:4.0.4]
	at io.helidon.webserver.observe.tracing.TracingObserver$TracingFilter.filter(TracingObserver.java:247) ~[helidon-webserver-observe-tracing-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:119) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.common.context.Contexts.runInContext(Contexts.java:117) ~[helidon-common-context-4.0.4.jar:4.0.4]
	at io.helidon.webserver.context.ContextRoutingFeature.filter(ContextRoutingFeature.java:50) ~[helidon-webserver-context-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:119) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters.executeFilters(Filters.java:87) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters.lambda$filter$0(Filters.java:83) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.ErrorHandlers.runWithErrorHandling(ErrorHandlers.java:75) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.Filters.filter(Filters.java:83) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.HttpRouting.route(HttpRouting.java:109) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http1.Http1Connection.route(Http1Connection.java:421) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http1.Http1Connection.handle(Http1Connection.java:194) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.ConnectionHandler.run(ConnectionHandler.java:165) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.common.task.InterruptableTask.call(InterruptableTask.java:47) ~[helidon-common-task-4.0.4.jar:4.0.4]
	at io.helidon.webserver.ThreadPerTaskExecutor$ThreadBoundFuture.run(ThreadPerTaskExecutor.java:239) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at java.lang.VirtualThread.run(VirtualThread.java:309) ~[?:?]
Caused by: java.lang.IllegalStateException: Entity has already been requested. Entity cannot be requested multiple times
	at io.helidon.http.media.ReadableEntityBase.inputStream(ReadableEntityBase.java:87) ~[helidon-http-media-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.ServerRequestEntity.inputStream(ServerRequestEntity.java:97) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.microprofile.server.JaxRsService.doHandle(JaxRsService.java:207) ~[helidon-microprofile-server-4.0.4.jar:4.0.4]
	at io.helidon.microprofile.server.JaxRsService.lambda$handle$2(JaxRsService.java:185) ~[helidon-microprofile-server-4.0.4.jar:4.0.4]
	at io.helidon.common.context.Contexts.runInContext(Contexts.java:117) ~[helidon-common-context-4.0.4.jar:4.0.4]
	at io.helidon.microprofile.server.JaxRsService.handle(JaxRsService.java:185) ~[helidon-microprofile-server-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.HttpRouting$RoutingExecutor.doRoute(HttpRouting.java:668) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.HttpRouting$RoutingExecutor.call(HttpRouting.java:627) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.HttpRouting$RoutingExecutor.call(HttpRouting.java:605) ~[helidon-webserver-4.0.4.jar:4.0.4]
	at io.helidon.webserver.http.ErrorHandlers.runWithErrorHandling(ErrorHandlers.java:75) ~[helidon-webserver-4.0.4.jar:4.0.4]
	... 22 more

Since we have a bunch of teams owning different API endpoints, we have consolidated them into different Applications. We have a Main function that adds these applications and starts the server as shown in the code-block below.

I have found that the issue does not affect the endpoints of the application that gets added to the server first. For the rest of the applications, the requests are met with the mentioned exception. I have compared the different applications and the corresponding resource classes and did not find any major differences between them.

public static void startServer() {
        log.info("Building Helidon Server");
        Server.builder()
                .addApplication(App1.class)
                .addApplication(App2.class)
                .addApplication(App3.class)
                .addApplication(App4.class)
                .build()
                .start();
        log.info("Helidon Server started successfully");
    }

Steps to reproduce

  • Try to create a custom startup with multiple applications registered.
  • Try to hit the endpoints to see if the same exception happens
@m0mus m0mus added bug Something isn't working webserver P2 jersey MP 4.x Version 4.x labels Feb 8, 2024
@GeezFORCE
Copy link
Author

GeezFORCE commented Feb 9, 2024

Hi Team, we have an update to share. As part of debugging from our side, we removed all the manual application addition and let Helidon discover and register the Jax-Rs Apps. Seems that fixed this issue for now (undergoing further testing). But still we would like to know what causes this when we manually add the applications.

@Verdent
Copy link
Member

Verdent commented Feb 9, 2024

Thank you for your work on this! So you have your app working now, right?

Do not worry, we will investigate this and will keep you posted on our findings :-)

@GeezFORCE
Copy link
Author

Yes David, as per our initial testing, the application is working as expected. I will keep you posted if we face any challenges. As of now, this issue is not a blocker for us.

Thanks for all your help. I bet you will get to the bottom of this. We look forward to your findings.

@ranjankhanna
Copy link

Hello, We are using Heldion 4.0.2 and running into same issue. Is there any fix out yet?

@romain-grecourt
Copy link
Contributor

This issue is triggered when there is more than one instance of io.helidon.microprofile.server.JaxRsService in the routing chain, each instance associated with a different JaxRs application.

If the request contains an entity payload and the first service does not match because the request is for a different JaxRs application, then the next service in the chain fails as the first one has already invoked req.content().inputStream().

E.g.

public class Main {
    public static void main(String[] args) {
        Server.builder()
                .addApplication(App1.class)
                .addApplication(App2.class)
                .build()
                .start();
    }

    @ApplicationPath("/")
    @ApplicationScoped
    public static class App1 extends Application {

        @Override
        public Set<Class<?>> getClasses() {
            return Set.of(Resource.class);
        }

        @Path("/app1")
        public static class Resource {

            @GET
            public String get() {
                return "OK";
            }
        }
    }

    @ApplicationPath("/")
    @ApplicationScoped
    public static class App2 extends Application {

        @Override
        public Set<Class<?>> getClasses() {
            return Set.of(Resource.class);
        }

        @Path("/app2")
        public static class Resource {

            @GET
            public String get() {
                return "OK";
            }
        }
    }
}
curl -d "{}" http://localhost:8080/app2

Server logs:

io.helidon.http.RequestException: Entity has already been requested. Entity cannot be requested multiple times
	at io.helidon.http.RequestException$Builder.build(RequestException.java:139)
	at io.helidon.webserver.http.ErrorHandlers.unhandledError(ErrorHandlers.java:202)
	at io.helidon.webserver.http.ErrorHandlers.lambda$handleError$1(ErrorHandlers.java:182)
	at java.base/java.util.Optional.ifPresentOrElse(Optional.java:198)
	at io.helidon.webserver.http.ErrorHandlers.handleError(ErrorHandlers.java:181)
	at io.helidon.webserver.http.ErrorHandlers.runWithErrorHandling(ErrorHandlers.java:118)
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:121)
	at io.helidon.webserver.observe.metrics.MetricsFeature.lambda$configureVendorMetrics$2(MetricsFeature.java:90)
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:119)
	at io.helidon.common.context.Contexts.runInContext(Contexts.java:117)
	at io.helidon.webserver.context.ContextRoutingFeature.filter(ContextRoutingFeature.java:50)
	at io.helidon.webserver.http.Filters$FilterChainImpl.proceed(Filters.java:119)
	at io.helidon.webserver.http.Filters.executeFilters(Filters.java:87)
	at io.helidon.webserver.http.Filters.lambda$filter$0(Filters.java:83)
	at io.helidon.webserver.http.ErrorHandlers.runWithErrorHandling(ErrorHandlers.java:75)
	at io.helidon.webserver.http.Filters.filter(Filters.java:83)
	at io.helidon.webserver.http.HttpRouting.route(HttpRouting.java:109)
	at io.helidon.webserver.http1.Http1Connection.route(Http1Connection.java:421)
	at io.helidon.webserver.http1.Http1Connection.handle(Http1Connection.java:194)
	at io.helidon.webserver.ConnectionHandler.run(ConnectionHandler.java:165)
	at io.helidon.common.task.InterruptableTask.call(InterruptableTask.java:47)
	at io.helidon.webserver.ThreadPerTaskExecutor$ThreadBoundFuture.run(ThreadPerTaskExecutor.java:239)
	at java.base/java.lang.VirtualThread.run(VirtualThread.java:309)
Caused by: java.lang.IllegalStateException: Entity has already been requested. Entity cannot be requested multiple times
	at io.helidon.http.media.ReadableEntityBase.inputStream(ReadableEntityBase.java:87)
	at io.helidon.webserver.http.ServerRequestEntity.inputStream(ServerRequestEntity.java:97)
	at io.helidon.microprofile.server.JaxRsService.doHandle(JaxRsService.java:208)
	at io.helidon.microprofile.server.JaxRsService.lambda$handle$2(JaxRsService.java:185)
	at io.helidon.common.context.Contexts.runInContext(Contexts.java:117)
	at io.helidon.microprofile.server.JaxRsService.handle(JaxRsService.java:185)
	at io.helidon.webserver.http.HttpRouting$RoutingExecutor.doRoute(HttpRouting.java:668)
	at io.helidon.webserver.http.HttpRouting$RoutingExecutor.call(HttpRouting.java:627)
	at io.helidon.webserver.http.HttpRouting$RoutingExecutor.call(HttpRouting.java:605)
	at io.helidon.webserver.http.ErrorHandlers.runWithErrorHandling(ErrorHandlers.java:75)
	... 17 more

When Helidon discovers the classes, if there is no application it aggregates all resources into a single synthetic application, in this case you won't run into this issue.

However, if there is more than one application, then the issue still exist.
E.g. replace the main method above with:

io.helidon.Main.main(args);

Note that if the application classes are not annotated with @ApplicationScope you will have a single synthetic application, potentially wrongly configured (see #8502) ; in this case you won't run into this issue.

@romain-grecourt
Copy link
Contributor

romain-grecourt commented Mar 20, 2024

Potential fix:

diff --git a/microprofile/server/src/main/java/io/helidon/microprofile/server/JaxRsService.java b/microprofile/server/src/main/java/io/helidon/microprofile/server/JaxRsService.java
index e268d372f0..7eaffedaf2 100644
--- a/microprofile/server/src/main/java/io/helidon/microprofile/server/JaxRsService.java
+++ b/microprofile/server/src/main/java/io/helidon/microprofile/server/JaxRsService.java
@@ -17,6 +17,7 @@
 package io.helidon.microprofile.server;
 
 import java.io.IOException;
+import java.io.InputStream;
 import java.io.OutputStream;
 import java.io.UncheckedIOException;
 import java.lang.System.Logger.Level;
@@ -181,11 +182,19 @@ class JaxRsService implements HttpService {
         context.supply(ServerRequest.class, () -> req);
         context.supply(ServerResponse.class, () -> res);
 
+        // request entity stream can be only consumed once
+        // store it in the request context to ensure a single call to req.content().inputStream()
+        InputStream entityStream = context.get(InputStream.class).orElseGet(() -> {
+            InputStream is = req.content().inputStream();
+            context.register(is);
+            return is;
+        });
+
         // call doHandle in active context
-        Contexts.runInContext(context, () -> doHandle(context, req, res));
+        Contexts.runInContext(context, () -> doHandle(context, req, res, entityStream));
     }
 
-    private void doHandle(Context ctx, ServerRequest req, ServerResponse res) {
+    private void doHandle(Context ctx, ServerRequest req, ServerResponse res, InputStream is) {
         BaseUriRequestUri uris = BaseUriRequestUri.resolve(req);
         ContainerRequest requestContext = new ContainerRequest(uris.baseUri,
                                                                uris.requestUri,
@@ -205,7 +214,7 @@ class JaxRsService implements HttpService {
 
         JaxRsResponseWriter writer = new JaxRsResponseWriter(res);
         requestContext.setWriter(writer);
-        requestContext.setEntityStream(req.content().inputStream());
+        requestContext.setEntityStream(is);
         requestContext.setProperty("io.helidon.jaxrs.remote-host", req.remotePeer().host());
         requestContext.setProperty("io.helidon.jaxrs.remote-port", req.remotePeer().port());
         requestContext.setRequestScopedInitializer(ij -> {

@tomas-langer tomas-langer assigned tomas-langer and unassigned Verdent Mar 21, 2024
@tomas-langer

This comment was marked as resolved.

@tomas-langer

This comment was marked as resolved.

@tomas-langer

This comment was marked as resolved.

@tomas-langer
Copy link
Member

Reproduced in an integration test on main, fixing.

@tomas-langer
Copy link
Member

There is a new test added in the PR that failed before the fix.
This should now work fine regardless of number of JAX-RS applications, and whether the next consumer of request entity is JAX-RS application or web server routing.

@m0mus m0mus moved this to Closed in Backlog Aug 12, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
4.x Version 4.x bug Something isn't working jersey MP P2 webserver
Projects
Archived in project
6 participants