Quarkus: @RequestScope with Filter and reactive routes

[lucaspouzac]

When I set a data in TestFilter to RequestScopedService, I cannot get data from this bean after because a new instance of RequestScopedService is created (if the request is a type POST / PUT / DELETE)

Actual behavior

$ curl -H "X-Data: test-data" http://localhost:8080
2020-11-02 20:45:49,381 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-1) Start
2020-11-02 20:45:49,382 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-1) Create RequestScopedService instance
2020-11-02 20:45:49,383 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-1) Start
2020-11-02 20:45:49,385 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-1) data: test-data
2020-11-02 20:45:49,391 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-1) End
2020-11-02 20:45:49,391 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-1) End

$ curl -X POST -H "X-Data: test-data" http://localhost:8080
2020-11-02 20:46:01,973 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-17) Start
2020-11-02 20:46:01,974 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-17) Create RequestScopedService instance
2020-11-02 20:46:01,982 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-17) End
2020-11-02 20:46:01,983 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-17) Start
KO: 2020-11-02 20:46:01,984 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-17) Create RequestScopedService instance
KO: 2020-11-02 20:46:01,984 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-17) data: null
2020-11-02 20:46:01,985 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-17) End

$ curl -X PUT -H "X-Data: test-data" http://localhost:8080
2020-11-02 20:46:20,831 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-0) Start
2020-11-02 20:46:20,832 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-0) Create RequestScopedService instance
2020-11-02 20:46:20,833 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-0) End
2020-11-02 20:46:20,834 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-0) Start
KO: 2020-11-02 20:46:20,835 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-0) Create RequestScopedService instance
KO: 2020-11-02 20:46:20,835 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-0) data: null
2020-11-02 20:46:20,837 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-0) End

$ curl -X DELETE -H "X-Data: test-data" http://localhost:8080
2020-11-02 20:46:27,962 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-8) Start
2020-11-02 20:46:27,963 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-8) Create RequestScopedService instance
2020-11-02 20:46:27,964 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-8) End
2020-11-02 20:46:27,965 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-8) Start
KO: 2020-11-02 20:46:27,965 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-8) Create RequestScopedService instance
KO: 2020-11-02 20:46:27,966 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-8) data: null
2020-11-02 20:46:27,967 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-8) End

$ curl -X OPTIONS -H "X-Data: test-data" http://localhost:8080
2020-11-02 20:46:42,326 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-22) Start
2020-11-02 20:46:42,327 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-22) Create RequestScopedService instance
2020-11-02 20:46:42,328 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-22) Start
2020-11-02 20:46:42,329 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-22) data: test-data
2020-11-02 20:46:42,330 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-22) End
2020-11-02 20:46:42,331 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-22) End

$ curl -I -H "X-Data: test-data" http://localhost:8080
2020-11-02 20:47:01,728 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-6) Start
2020-11-02 20:47:01,729 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-6) Create RequestScopedService instance
2020-11-02 20:47:01,730 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-6) Start
2020-11-02 20:47:01,731 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-6) data: test-data
2020-11-02 20:47:01,732 INFO  [io.qua.TestRoute] (vert.x-eventloop-thread-6) End
2020-11-02 20:47:01,732 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-6) End

To Reproduce

Run project in additional context

Environment (please complete the following information):

• Output of uname -a or ver:
• Output of java -version: Java version: 11.0.8, vendor: GraalVM Community, runtime: graalvm-ce-java11-20.2.0
• GraalVM version (if different from Java):
• Quarkus version or git rev: latest

Additional context
(Add any other context about the problem here.)
bug-request-scope.tar.gz

[lucaspouzac]

Probably a cleaning related to this: https://quarkus.io/guides/cdi-reference#request-context-lifecycle

[mkouba]

$ curl -X POST -H "X-Data: test-data" http://localhost:8080
2020-11-02 20:46:01,973 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-17) Start
2020-11-02 20:46:01,974 INFO  [io.qua.RequestScopedService] (vert.x-eventloop-thread-17) Create RequestScopedService instance
2020-11-02 20:46:01,982 INFO  [io.qua.TestFilter] (vert.x-eventloop-thread-17) End

^--------- This one is interesting. It seems the filter ends before the route method is executed.

UPDATE: Hm, this happens because the BodyHandler (which is used for POST, PUT, PATCH and DELETE) returns immediately and delegates to the route method asynchronously. In other words, when the filter method completes the request context is deactivated (i.e. the request context is removed from the thread local) and queued for destruction. As a result, there are two request contexts created for such an http request (one for filter, one for route).

@cescoffier @stuartwdouglas @geoand FYI

[mkouba]

~Unfortunately, I have no idea how fix this or whether it's even possible.~

UPDATE: I've sent a draft PR that should fix this problem: https://github.com/quarkusio/quarkus/pull/13458