Skip to content

Logout fails due to invalidated session in WebFlux application #1523

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

Closed
vpavic opened this issue Oct 4, 2019 · 8 comments
Closed

Logout fails due to invalidated session in WebFlux application #1523

vpavic opened this issue Oct 4, 2019 · 8 comments
Assignees
Labels
for: external-project For an external project and not something we can fix

Comments

@vpavic
Copy link
Contributor

vpavic commented Oct 4, 2019

This appears to be a regression somewhere between Spring WebFlux, Spring Session and Spring Security.

The problem can be reproduced using sample-websession project from this repo (note: requires locally running Redis). Steps to reproduce:

  • login using user/password
  • attempt to logout

This results in:

2019-10-04 21:17:13.645 ERROR 13603 --- [llEventLoop-4-1] a.w.r.e.AbstractErrorWebExceptionHandler : [03b45714] 500 Server Error for HTTP POST "/logout"

java.lang.IllegalStateException: Session was invalidated
	at org.springframework.session.data.redis.ReactiveRedisSessionRepository.lambda$save$1(ReactiveRedisSessionRepository.java:127) ~[spring-session-data-redis-2.2.0.RC1.jar:2.2.0.RC1]
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Error has been observed at the following site(s):
	|_ checkpoint ⇢ org.springframework.security.web.server.authentication.logout.LogoutWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.savedrequest.ServerRequestCacheWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.context.SecurityContextServerWebExchangeWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.ui.LogoutPageGeneratingWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.ui.LoginPageGeneratingWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.authentication.AuthenticationWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.context.ReactorContextWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.csrf.CsrfWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.header.HttpHeaderWriterWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.config.web.server.ServerHttpSecurity$ServerWebExchangeReactorContextWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.WebFilterChainProxy [DefaultWebFilterChain]
	|_ checkpoint ⇢ HTTP POST "/logout" [ExceptionHandlingWebHandler]
Stack trace:
		at org.springframework.session.data.redis.ReactiveRedisSessionRepository.lambda$save$1(ReactiveRedisSessionRepository.java:127) ~[spring-session-data-redis-2.2.0.RC1.jar:2.2.0.RC1]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:118) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxUsingWhen$UsingWhenSubscriber.onNext(FluxUsingWhen.java:355) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:114) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onNext(MonoFlatMapMany.java:242) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:114) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:114) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at io.lettuce.core.RedisPublisher$ImmediateSubscriber.onNext(RedisPublisher.java:900) ~[lettuce-core-5.2.0.RELEASE.jar:5.2.0.RELEASE]
		at io.lettuce.core.RedisPublisher$RedisSubscription.onNext(RedisPublisher.java:284) ~[lettuce-core-5.2.0.RELEASE.jar:5.2.0.RELEASE]
		at io.lettuce.core.RedisPublisher$SubscriptionCommand.complete(RedisPublisher.java:768) ~[lettuce-core-5.2.0.RELEASE.jar:5.2.0.RELEASE]
		at io.lettuce.core.protocol.CommandHandler.complete(CommandHandler.java:652) ~[lettuce-core-5.2.0.RELEASE.jar:5.2.0.RELEASE]
		at io.lettuce.core.protocol.CommandHandler.decode(CommandHandler.java:612) ~[lettuce-core-5.2.0.RELEASE.jar:5.2.0.RELEASE]
		at io.lettuce.core.protocol.CommandHandler.channelRead(CommandHandler.java:563) ~[lettuce-core-5.2.0.RELEASE.jar:5.2.0.RELEASE]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) ~[netty-transport-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) ~[netty-transport-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352) ~[netty-transport-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1422) ~[netty-transport-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) ~[netty-transport-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) ~[netty-transport-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:931) ~[netty-transport-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:794) ~[netty-transport-native-epoll-4.1.39.Final-linux-x86_64.jar:4.1.39.Final]
		at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:424) ~[netty-transport-native-epoll-4.1.39.Final-linux-x86_64.jar:4.1.39.Final]
		at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:326) ~[netty-transport-native-epoll-4.1.39.Final-linux-x86_64.jar:4.1.39.Final]
		at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1044) ~[netty-common-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.42.Final.jar:4.1.42.Final]
		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.42.Final.jar:4.1.42.Final]
		at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]

If Spring Boot is downgraded to 2.1.9.RELEASE, everything works. It also works when upgraded to 2.2.0.M4, the trouble starts with 2.2.0.M5 onwards.

I've also tried working with 2.1.9.RELEASE and upgrading Framework, Security and Session to current releases individually, but this also works.

@vpavic vpavic added the type: regression A regression from a previous release label Oct 4, 2019
@vpavic vpavic added this to the 2.2.0 milestone Oct 4, 2019
@rwinch
Copy link
Member

rwinch commented Oct 15, 2019

Thanks for the detailed report @vpavic I have started looking into this, but haven't gotten as far as I'd like. Here are my notes thus far.

What Changed?

Dependency Management Plugin

If I take the existing project and use the dependency management plugin instead of platform everything works just fine. You can see it in action here https://github.com/rwinch/spring-session-samples/pull/new/dependency-management

The difference in dependencies appears to be that for the platform approach Netty 4.1.42 is used while dependency management Netty 4.1.39 is used.

image

What this suggests to me is that the change in dependency has changed how Spring Session is being used slightly.

Redis Monitor

Using redis monitor during a logout demonstrated different Redis commands being invoked. If I use the dependency management plugin, I get the following events:

1571169012.368644 [0 172.17.0.1:52550] "HGETALL" "spring:session:sessions:aa5cf838-3ec6-436c-a9fe-9d014832028d"
1571169012.373971 [0 172.17.0.1:52550] "EXISTS" "spring:session:sessions:aa5cf838-3ec6-436c-a9fe-9d014832028d"
1571169012.374514 [0 172.17.0.1:52550] "EXISTS" "spring:session:sessions:aa5cf838-3ec6-436c-a9fe-9d014832028d"
1571169012.375534 [0 172.17.0.1:52550] "RENAME" "spring:session:sessions:aa5cf838-3ec6-436c-a9fe-9d014832028d" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090"
1571169012.376587 [0 172.17.0.1:52550] "HMSET" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090" "lastAccessedTime" "\xac\xed\x00\x05sr\x00\x0ejava.lang.Long;\x8b\xe4\x90\xcc\x8f#\xdf\x02\x00\x01J\x00\x05valuexr\x00\x10java.lang.Number\x86\xac\x95\x1d\x0b\x94\xe0\x8b\x02\x00\x00xp\x00\x00\x01m\xd0\xf8\x8a\x93" "sessionAttr:org.springframework.security.web.server.csrf.WebSessionServerCsrfTokenRepository.CSRF_TOKEN" "" "sessionAttr:SPRING_SECURITY_CONTEXT" ""
1571169012.377892 [0 172.17.0.1:52550] "EXPIRE" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090" "1800"
1571169012.378824 [0 172.17.0.1:52550] "HMSET" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090" "lastAccessedTime" "\xac\xed\x00\x05sr\x00\x0ejava.lang.Long;\x8b\xe4\x90\xcc\x8f#\xdf\x02\x00\x01J\x00\x05valuexr\x00\x10java.lang.Number\x86\xac\x95\x1d\x0b\x94\xe0\x8b\x02\x00\x00xp\x00\x00\x01m\xd0\xf8\x8a\x93" "sessionAttr:org.springframework.security.web.server.csrf.WebSessionServerCsrfTokenRepository.CSRF_TOKEN" "" "sessionAttr:SPRING_SECURITY_CONTEXT" ""
1571169012.379086 [0 172.17.0.1:52550] "EXPIRE" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090" "1800"
1571169012.380507 [0 172.17.0.1:52550] "EXISTS" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090"
1571169012.385436 [0 172.17.0.1:52550] "HGETALL" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090"
1571169012.387784 [0 172.17.0.1:52550] "EXISTS" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090"
1571169012.388359 [0 172.17.0.1:52550] "RENAME" "spring:session:sessions:2d4ceddb-e8d8-4e70-8b17-1e2aa759c090" "spring:session:sessions:82d215a3-5c16-4651-a0d7-9b3baa7e2abb"
1571169012.389002 [0 172.17.0.1:52550] "HMSET" "spring:session:sessions:82d215a3-5c16-4651-a0d7-9b3baa7e2abb" "lastAccessedTime" "\xac\xed\x00\x05sr\x00\x0ejava.lang.Long;\x8b\xe4\x90\xcc\x8f#\xdf\x02\x00\x01J\x00\x05valuexr\x00\x10java.lang.Number\x86\xac\x95\x1d\x0b\x94\xe0\x8b\x02\x00\x00xp\x00\x00\x01m\xd0\xf8\x8a\xa2" "sessionAttr:org.springframework.security.web.server.csrf.WebSessionServerCsrfTokenRepository.CSRF_TOKEN" "\xac\xed\x00\x05sr\x00=org.springframework.security.web.server.csrf.DefaultCsrfToken\x04Gq\xb4\x1a\x90&q\x02\x00\x03L\x00\nheaderNamet\x00\x12Ljava/lang/String;L\x00\rparameterNameq\x00~\x00\x01L\x00\x05tokenq\x00~\x00\x01xpt\x00\x0cX-CSRF-TOKENt\x00\x05_csrft\x00$cf87a7f6-41a0-49dc-a521-a9f8300a3093"
1571169012.389260 [0 172.17.0.1:52550] "EXPIRE" "spring:session:sessions:82d215a3-5c16-4651-a0d7-9b3baa7e2abb" "1800"
1571169012.390668 [0 172.17.0.1:52550] "EXISTS" "spring:session:sessions:82d215a3-5c16-4651-a0d7-9b3baa7e2abb"

Using the platform approach I get:

1571169145.014091 [0 172.17.0.1:52600] "HGETALL" "spring:session:sessions:8f2c18cc-a717-4250-96a4-a01180e35fa8"
1571169145.018833 [0 172.17.0.1:52600] "EXISTS" "spring:session:sessions:8f2c18cc-a717-4250-96a4-a01180e35fa8"
1571169145.019583 [0 172.17.0.1:52600] "RENAME" "spring:session:sessions:8f2c18cc-a717-4250-96a4-a01180e35fa8" "spring:session:sessions:666d09df-1ba1-40d8-814d-dd6360c6dd18"
1571169145.019868 [0 172.17.0.1:52600] "EXISTS" "spring:session:sessions:8f2c18cc-a717-4250-96a4-a01180e35fa8"
1571169145.020639 [0 172.17.0.1:52600] "HMSET" "spring:session:sessions:666d09df-1ba1-40d8-814d-dd6360c6dd18" "lastAccessedTime" "\xac\xed\x00\x05sr\x00\x0ejava.lang.Long;\x8b\xe4\x90\xcc\x8f#\xdf\x02\x00\x01J\x00\x05valuexr\x00\x10java.lang.Number\x86\xac\x95\x1d\x0b\x94\xe0\x8b\x02\x00\x00xp\x00\x00\x01m\xd0\xfa\x90\xb8" "sessionAttr:org.springframework.security.web.server.csrf.WebSessionServerCsrfTokenRepository.CSRF_TOKEN" "" "sessionAttr:SPRING_SECURITY_CONTEXT" ""
1571169145.021017 [0 172.17.0.1:52600] "EXPIRE" "spring:session:sessions:666d09df-1ba1-40d8-814d-dd6360c6dd18" "1800"
1571169145.050257 [0 172.17.0.1:52600] "EXISTS" "spring:session:sessions:666d09df-1ba1-40d8-814d-dd6360c6dd18"

Works Sometimes

I also have noticed that sometimes the sample project (as is) works while most of the time it fails.

@rwinch rwinch modified the milestones: 2.2.0, 2.2.1 Oct 15, 2019
@vpavic
Copy link
Contributor Author

vpavic commented Nov 5, 2019

With Spring Boot 2.2.0.RELEASE the change of dependency resolution approach shouldn't matter, as the managed version of Netty is set to 4.1.42.Final (in contrast to 2.2.0.RC1 where it's at 4.1.39.Final. We should probably double check this when Spring Boot 2.2.1.RELEASE is out as the current master has managed version of Netty at 4.1.43.Final.

As a sidenote, you can also use Gradle's native dependency resolution to enforce BOM's dependency versions by using enforcedPlatform instead of platform.

@rwinch
Copy link
Member

rwinch commented Nov 6, 2019

I agree this should work despite the version of Netty. However, I wanted to note that this appears to be triggering the bug to happen.

@vpavic
Copy link
Contributor Author

vpavic commented Nov 7, 2019

The situation remains unchanged with upgrade of sample project to Spring Boot 2.2.1.RELEASE. Here's the updated stack trace:

2019-11-07 21:00:05.904 ERROR 20093 --- [llEventLoop-4-1] a.w.r.e.AbstractErrorWebExceptionHandler : [88960a0e]  500 Server Error for HTTP POST "/logout"

java.lang.IllegalStateException: Session was invalidated
	at org.springframework.session.data.redis.ReactiveRedisSessionRepository.lambda$save$1(ReactiveRedisSessionRepository.java:127) ~[spring-session-data-redis-2.2.0.RELEASE.jar:2.2.0.RELEASE]
	Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Error has been observed at the following site(s):
	|_ checkpoint ⇢ org.springframework.security.web.server.authentication.logout.LogoutWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.savedrequest.ServerRequestCacheWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.context.SecurityContextServerWebExchangeWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.ui.LogoutPageGeneratingWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.ui.LoginPageGeneratingWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.authentication.AuthenticationWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.context.ReactorContextWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.csrf.CsrfWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.header.HttpHeaderWriterWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.config.web.server.ServerHttpSecurity$ServerWebExchangeReactorContextWebFilter [DefaultWebFilterChain]
	|_ checkpoint ⇢ org.springframework.security.web.server.WebFilterChainProxy [DefaultWebFilterChain]
	|_ checkpoint ⇢ HTTP POST "/logout" [ExceptionHandlingWebHandler]
Stack trace:
		at org.springframework.session.data.redis.ReactiveRedisSessionRepository.lambda$save$1(ReactiveRedisSessionRepository.java:127) ~[spring-session-data-redis-2.2.0.RELEASE.jar:2.2.0.RELEASE]
		at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:118) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxUsingWhen$UsingWhenSubscriber.onNext(FluxUsingWhen.java:355) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:114) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:73) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoFlatMapMany$FlatMapManyInner.onNext(MonoFlatMapMany.java:242) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:114) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:114) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:76) ~[reactor-core-3.3.0.RELEASE.jar:3.3.0.RELEASE]
		at io.lettuce.core.RedisPublisher$ImmediateSubscriber.onNext(RedisPublisher.java:888) ~[lettuce-core-5.2.1.RELEASE.jar:5.2.1.RELEASE]
		at io.lettuce.core.RedisPublisher$RedisSubscription.onNext(RedisPublisher.java:281) ~[lettuce-core-5.2.1.RELEASE.jar:5.2.1.RELEASE]
		at io.lettuce.core.RedisPublisher$SubscriptionCommand.complete(RedisPublisher.java:756) ~[lettuce-core-5.2.1.RELEASE.jar:5.2.1.RELEASE]
		at io.lettuce.core.protocol.CommandHandler.complete(CommandHandler.java:654) ~[lettuce-core-5.2.1.RELEASE.jar:5.2.1.RELEASE]
		at io.lettuce.core.protocol.CommandHandler.decode(CommandHandler.java:614) ~[lettuce-core-5.2.1.RELEASE.jar:5.2.1.RELEASE]
		at io.lettuce.core.protocol.CommandHandler.channelRead(CommandHandler.java:565) ~[lettuce-core-5.2.1.RELEASE.jar:5.2.1.RELEASE]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) ~[netty-transport-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) ~[netty-transport-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352) ~[netty-transport-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1422) ~[netty-transport-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374) ~[netty-transport-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360) ~[netty-transport-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:931) ~[netty-transport-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:792) ~[netty-transport-native-epoll-4.1.43.Final-linux-x86_64.jar:4.1.43.Final]
		at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:502) ~[netty-transport-native-epoll-4.1.43.Final-linux-x86_64.jar:4.1.43.Final]
		at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:407) ~[netty-transport-native-epoll-4.1.43.Final-linux-x86_64.jar:4.1.43.Final]
		at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1050) ~[netty-common-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[netty-common-4.1.43.Final.jar:4.1.43.Final]
		at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[netty-common-4.1.43.Final.jar:4.1.43.Final]
		at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]

@rwinch rwinch removed this from the 2.2.1 milestone Dec 12, 2019
@rwinch rwinch added for: external-project For an external project and not something we can fix and removed type: regression A regression from a previous release labels Dec 12, 2019
@rwinch
Copy link
Member

rwinch commented Dec 12, 2019

This is fixed via spring-projects/spring-security#7723

@rwinch rwinch closed this as completed Dec 12, 2019
@markhall82
Copy link

markhall82 commented Dec 24, 2020

Is this definitely fixed? - I'm seeing this behaviour in Spring OAuth2.0 with a Redis session store.
Here is my POM, have I got the versions that fix the issue?

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
	xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
	<modelVersion>4.0.0</modelVersion>
	<parent>
		<groupId>org.springframework.boot</groupId>
		<artifactId>spring-boot-starter-parent</artifactId>
		<version>2.3.4.RELEASE</version>
		<relativePath/> <!-- lookup parent from repository -->
	</parent>
	<groupId>com.example</groupId>
	<artifactId>webgateway</artifactId>
	<version>0.0.1-SNAPSHOT</version>
	<name>web-gateway</name>
	<description>Demo project for Spring Boot</description>

	<properties>
		<java.version>1.8</java.version>
		<spring-cloud.version>Hoxton.SR8</spring-cloud.version>
	</properties>

	<dependencies>

		<dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-oauth2-client</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.security</groupId>
			<artifactId>spring-security-oauth2-jose</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.cloud</groupId>
			<artifactId>spring-cloud-starter-security</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.security</groupId>
			<artifactId>spring-security-oauth2-jose</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.security.oauth.boot</groupId>
			<artifactId>spring-security-oauth2-autoconfigure</artifactId>
			<version>2.3.4.RELEASE</version>
		</dependency>
		<dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-thymeleaf</artifactId>
		</dependency>
		<dependency>
			<groupId>org.thymeleaf.extras</groupId>
			<artifactId>thymeleaf-extras-springsecurity5</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.session</groupId>
			<artifactId>spring-session-core</artifactId>
		</dependency>
        <dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-webflux</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.cloud</groupId>
			<artifactId>spring-cloud-starter-gateway</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-test</artifactId>
			<scope>test</scope>
		</dependency>

		<dependency>
			<groupId>com.fasterxml.jackson.core</groupId>
			<artifactId>jackson-databind</artifactId>
			<version>2.11.2</version>
		</dependency>
		<dependency>
			<groupId>com.fasterxml.jackson.core</groupId>
			<artifactId>jackson-core</artifactId>
			<version>2.11.2</version>
		</dependency>
	   <dependency>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-data-redis</artifactId>
		</dependency>
		<dependency>
			<groupId>org.springframework.session</groupId>
			<artifactId>spring-session-data-redis</artifactId>
		</dependency>
	</dependencies>

	<dependencyManagement>
		<dependencies>
			<dependency>
				<groupId>org.springframework.cloud</groupId>
				<artifactId>spring-cloud-dependencies</artifactId>
				<version>${spring-cloud.version}</version>
				<type>pom</type>
				<scope>import</scope>
			</dependency>
		</dependencies>
	</dependencyManagement>

	<build>
		<plugins>
			<plugin>
				<groupId>org.springframework.boot</groupId>
				<artifactId>spring-boot-maven-plugin</artifactId>
			</plugin>
			<plugin>
				<groupId>org.apache.maven.plugins</groupId>
				<artifactId>maven-compiler-plugin</artifactId>
				<configuration>
					<source>9</source>
					<target>9</target>
				</configuration>
			</plugin>
		</plugins>
	</build>

</project>

The error I am seeing is similar to the original post

java.lang.IllegalStateException: Session was invalidated
org.springframework.session.data.redis.ReactiveRedisSessionRepository.lambda$save$1(ReactiveRedisSessionRepository.java:127) ~[spring-session-data-redis-2.3.1.RELEASE.jar!/:2.3.1.RELEASE]
Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
Error has been observed at the following site(s):
|_ checkpoint ⇢ org.springframework.cloud.gateway.filter.WeightCalculatorWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.authorization.AuthorizationWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.authorization.ExceptionTranslationWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.authentication.logout.LogoutWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.savedrequest.ServerRequestCacheWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.context.SecurityContextServerWebExchangeWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.ui.LogoutPageGeneratingWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.ui.LoginPageGeneratingWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.oauth2.client.web.server.authentication.OAuth2LoginAuthenticationWebFilter [DefaultWebFilterChain]\n\t|_ checkpoint ⇢ org.springframework.security.oauth2.client.web.server.OAuth2AuthorizationRequestRedirectWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.context.ReactorContextWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.header.HttpHeaderWriterWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.config.web.server.ServerHttpSecurity$ServerWebExchangeReactorContextWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.security.web.server.WebFilterChainProxy [DefaultWebFilterChain]
|_ checkpoint ⇢ org.springframework.boot.actuate.metrics.web.reactive.server.MetricsWebFilter [DefaultWebFilterChain]
|_ checkpoint ⇢ HTTP POST \"/api/logger\" [ExceptionHandlingWebHandler]

@markhall82
Copy link

markhall82 commented Dec 24, 2020

Having compiled the post above, I noticed the POST url is not the logout url - could this happen if a request was sent to the server from the browser with a session cookie that has already been invalidated very soon after the logout?

@vpavic
Copy link
Contributor Author

vpavic commented Mar 3, 2021

@markhall82, if you're still having this issue I'd suggest to open a new issue describing the problem. Comments on closed issues tend to fall through the cracks quite easily.

If you do open a new issue, please consider creating a minimal sample that can be used to reproduce this. Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
for: external-project For an external project and not something we can fix
Projects
None yet
Development

No branches or pull requests

3 participants