CSRFFilter should have set the attribute csrf-token, but it is null after upgrade to 3.6.4

[yazalulloa]

Describe the bug

I upgraded from 3.6.3 to 3.6.4, and since then the CsrfTokenParameterProvider getToken() fails 'CSRFFilter should have set the attribute csrf-token, but it is null ' after the first load of the page, subsequent load or GET requests fails with the same error

2023-12-23 19:46:30,719 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (vert.x-eventloop-thread-0) HTTP Request to /api/table failed, error id: ace42e7c-bf2e-495b-b24f-52711085a983-2: io.quarkus.qute.TemplateException
at io.quarkus.qute.CompletedStage.get(CompletedStage.java:65)
at io.quarkus.qute.MultiResultNode.process(MultiResultNode.java:20)
at io.quarkus.qute.MultiResultNode.process(MultiResultNode.java:20)
at io.quarkus.qute.MultiResultNode.process(MultiResultNode.java:20)
at io.quarkus.qute.TemplateImpl$TemplateInstanceImpl.lambda$renderData$5(TemplateImpl.java:239)
at io.quarkus.qute.CompletedStage.whenComplete(CompletedStage.java:285)
at io.quarkus.qute.TemplateImpl$TemplateInstanceImpl.renderData(TemplateImpl.java:233)
at io.quarkus.qute.TemplateImpl$TemplateInstanceImpl.renderAsyncNoTimeout(TemplateImpl.java:224)
at io.smallrye.context.impl.wrappers.SlowContextualSupplier.get(SlowContextualSupplier.java:21)
at io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage.subscribe(UniCreateFromCompletionStage.java:24)
at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
at io.smallrye.mutiny.operators.uni.UniFailOnTimeout.subscribe(UniFailOnTimeout.java:36)
at io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
at io.smallrye.mutiny.groups.UniSubscribe.withSubscriber(UniSubscribe.java:51)
at io.smallrye.mutiny.groups.UniSubscribe.with(UniSubscribe.java:110)
at io.smallrye.mutiny.groups.UniSubscribe.with(UniSubscribe.java:88)
at org.jboss.resteasy.reactive.server.handlers.UniResponseHandler.handle(UniResponseHandler.java:19)
at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:150)
at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:147)
at org.jboss.resteasy.reactive.server.handlers.RestInitialHandler.beginProcessing(RestInitialHandler.java:48)
at org.jboss.resteasy.reactive.server.vertx.ResteasyReactiveVertxHandler.handle(ResteasyReactiveVertxHandler.java:23)
at org.jboss.resteasy.reactive.server.vertx.ResteasyReactiveVertxHandler.handle(ResteasyReactiveVertxHandler.java:10)
at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1286)
at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:177)
at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:144)
at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:102)
at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:88)
at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1286)
at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:140)
at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:144)
at io.vertx.ext.web.handler.impl.StaticHandlerImpl.lambda$sendStatic$1(StaticHandlerImpl.java:290)
at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54)
at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: java.lang.IllegalStateException: CSRFFilter should have set the attribute csrf-token, but it is null
at io.quarkus.csrf.reactive.runtime.CsrfTokenParameterProvider.getToken(CsrfTokenParameterProvider.java:42)
at io.quarkus.csrf.reactive.runtime.CsrfTokenParameterProvider_ClientProxy.getToken(Unknown Source)
at io.quarkus.csrf.reactive.runtime.CsrfTokenParameterProvider_ValueResolver.resolve(Unknown Source)
at io.quarkus.qute.EvaluatorImpl.resolve(EvaluatorImpl.java:211)
at io.quarkus.qute.EvaluatorImpl.resolveReference(EvaluatorImpl.java:131)
at io.quarkus.qute.EvaluatorImpl.lambda$evaluate$0(EvaluatorImpl.java:78)
at io.quarkus.qute.CompletedStage.thenCompose(CompletedStage.java:249)
at io.quarkus.qute.EvaluatorImpl.evaluate(EvaluatorImpl.java:77)
at io.quarkus.qute.ResolutionContextImpl$ChildResolutionContext.evaluate(ResolutionContextImpl.java:87)
at io.quarkus.qute.ExpressionNode.resolve(ExpressionNode.java:36)
at io.quarkus.qute.SectionNode$SectionResolutionContextImpl.execute(SectionNode.java:228)
at io.quarkus.qute.SectionHelper$SectionResolutionContext.execute(SectionHelper.java:76)
at io.quarkus.qute.LoopSectionHelper.nextElement(LoopSectionHelper.java:141)
at io.quarkus.qute.LoopSectionHelper.lambda$resolve$0(LoopSectionHelper.java:58)
at io.quarkus.qute.CompletedStage.thenCompose(CompletedStage.java:249)
at io.quarkus.qute.LoopSectionHelper.resolve(LoopSectionHelper.java:47)
at io.quarkus.qute.SectionNode.resolve(SectionNode.java:53)
at io.quarkus.qute.SectionNode.resolve(SectionNode.java:58)
at io.quarkus.qute.SectionNode$SectionResolutionContextImpl.execute(SectionNode.java:228)
at io.quarkus.qute.SectionHelper$SectionResolutionContext.execute(SectionHelper.java:66)
at io.quarkus.qute.Parser$1.resolve(Parser.java:1288)
at io.quarkus.qute.SectionNode.resolve(SectionNode.java:53)
at io.quarkus.qute.SectionNode.resolve(SectionNode.java:58)
... 35 more

Expected behavior

The CSRF token should be in context

Actual behavior

The CSRF token is not in contett

How to Reproduce?

clone https://github.com/yazalulloa/quarkus-csrf-signature-bug

Run quarkus project

Go to http://localhost:9898/some-page

Output of uname -a or ver

Linux yaz-laptop 6.2.0-39-generic #40~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Thu Nov 16 10:53:04 UTC 2 x86_64 x86_64 x86_64 GNU/Linux

Output of java -version

openjdk version "21" 2023-09-19 OpenJDK Runtime Environment GraalVM CE 21+35.1 (build 21+35-jvmci-23.1-b15) OpenJDK 64-Bit Server VM GraalVM CE 21+35.1 (build 21+35-jvmci-23.1-b15, mixed mode, sharing)

Quarkus version or git rev

3.6.4

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

maven 3.9.3

Additional information

No response

[sberyozkin]

@yazalulloa The only thing that changed is #37723, there setting the csrf token is delayed until the existing token has been verified, as opposed to using the cookie value immediately - which was causing a double signature issue.
So it should not be affecting it on the first load - since that cookie is not available anyway, and we have several tests.

If you'd like, please debug, or please create a simpler HTMX based reproducer, when I was looking at it last time, I could not do anything with it.

[yazalulloa]

Ok, I'll try to debug what's happening, one question though, where does the csrf_token get initialized in the RoutingContext, I'm asking because in io.quarkus.csrf.reactive.runtime.CsrfTokenParameterProvider getToken() is looking for it, and does not find it.

Can I ask, what was the problem with the repo I posted it?

[sberyozkin]

@yazalulloa Thanks, so, when the first GET arrives, the csrf_token is generated at https://github.com/quarkusio/quarkus/blob/main/extensions/csrf-reactive/runtime/src/main/java/io/quarkus/csrf/reactive/runtime/CsrfRequestResponseReactiveFilter.java#L86, which is why it is not clear how this code can be skipped on the first load as in your reproducer.

Then if it is one of the follow up requests, it is set once it has been verified, https://github.com/quarkusio/quarkus/blob/main/extensions/csrf-reactive/runtime/src/main/java/io/quarkus/csrf/reactive/runtime/CsrfRequestResponseReactiveFilter.java#L160

However, now that I'm looking at this code, I wonder, if you have repeated GETs, in which case, if it is a 2nd GET with the existing cookie (it would not be the first load), then https://github.com/quarkusio/quarkus/blob/main/extensions/csrf-reactive/runtime/src/main/java/io/quarkus/csrf/reactive/runtime/CsrfRequestResponseReactiveFilter.java#L86 would miss setting the csrf_token, this is probably it. I can try to get a PR addressing that.

When I was trying your reproducer there were repeated requests to the endpoint and I could not reproduce the double signature problem, so I ended up coming up with a test case with multiple forms which reproduced it.

[sberyozkin]

@yazalulloa FYI, this issue will be fixed by #37725 after a minor update there

[FroMage]

Yeah, got hit by this one too on 3.6.4 :(

[FroMage]

Thanks @gsmet