spring-projects
Exception thrown on application shutdown when using redis with RedisIndexedWebSession enabled
Please Note I filed this bug in https://github.com/spring-projects/spring-data-redis/issues/2983 but the comment I received was to file this over here.
Spring boot throws exception on application shutdown. It does not happen when I replace @EnableRedisIndexedWebSession with @EnableRedisWebSession. Something else I've also tried not specifying my own LettuceClientConfiguration in the RedisConfig below which also works.
I am using the following Spring dependencies:
org.springframework.session:spring-session-data-redis:3.31 org.springframework.boot:spring-boot-starter-data-redis-reactive:3.3.2
Exception Thrown:
`Disconnected from the target VM, address: '127.0.0.1:51013', transport: 'socket' 2024-09-05 12:04:03,671 destroy LettucePoolingConnectionProvider contains unreleased connections {} 2024-09-05 12:04:03,805 error Operator called default onErrorDropped {} reactor.core.Exceptions$ErrorCallbackNotImplemented: org.springframework.data.redis.connection.PoolException: Returned connection io.lettuce.core.pubsub.StatefulRedisPubSubConnectionImpl@40b6b5f3 was either previously returned or does not belong to this connection provider Caused by: org.springframework.data.redis.connection.PoolException: Returned connection io.lettuce.core.pubsub.StatefulRedisPubSubConnectionImpl@40b6b5f3 was either previously returned or does not belong to this connection provider at org.springframework.data.redis.connection.lettuce.LettucePoolingConnectionProvider.releaseAsync(LettucePoolingConnectionProvider.java:192) at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.releaseAsync(LettuceConnectionFactory.java:1834) at org.springframework.data.redis.connection.lettuce.LettuceReactiveRedisConnection$AsyncConnect.lambda$close$3(LettuceReactiveRedisConnection.java:373) at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:45) at reactor.core.publisher.Mono.subscribe(Mono.java:4568) at reactor.core.publisher.FluxFlatMap$FlatMapMain.onNext(FluxFlatMap.java:430) at reactor.core.publisher.FluxArray$ArraySubscription.slowPath(FluxArray.java:126) at reactor.core.publisher.FluxArray$ArraySubscription.request(FluxArray.java:99) at reactor.core.publisher.FluxFlatMap$FlatMapMain.onSubscribe(FluxFlatMap.java:373) at reactor.core.publisher.FluxMerge.subscribe(FluxMerge.java:73) at reactor.core.publisher.MonoFromFluxOperator.subscribe(MonoFromFluxOperator.java:83) at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53) at reactor.core.publisher.Mono.subscribe(Mono.java:4568) at reactor.core.publisher.Mono.subscribeWith(Mono.java:4634) at reactor.core.publisher.Mono.subscribe(Mono.java:4395) at org.springframework.data.redis.core.ReactiveRedisTemplate.lambda$listenTo$4(ReactiveRedisTemplate.java:289) at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.runFinally(FluxDoFinally.java:146) at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.cancel(FluxDoFinally.java:135) at reactor.core.publisher.FluxFlatMap$FlatMapMain.cancel(FluxFlatMap.java:361) at reactor.core.publisher.LambdaSubscriber.dispose(LambdaSubscriber.java:191) at org.springframework.session.data.redis.ReactiveRedisIndexedSessionRepository.destroy(ReactiveRedisIndexedSessionRepository.java:338) at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:211) at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:587) at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:559) at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:1202) at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:520) at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:1195) at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1195) at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1156) at org.springframework.boot.web.reactive.context.ReactiveWebServerApplicationContext.doClose(ReactiveWebServerApplicationContext.java:149) at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:1102) at org.springframework.boot.SpringApplicationShutdownHook.closeAndWait(SpringApplicationShutdownHook.java:145) at java.base/java.lang.Iterable.forEach(Iterable.java:75) at org.springframework.boot.SpringApplicationShutdownHook.run(SpringApplicationShutdownHook.java:114) at java.base/java.lang.Thread.run(Thread.java:840)
2024-09-05 12:04:03,806 error Operator called default onErrorDropped {} reactor.core.Exceptions$ErrorCallbackNotImplemented: org.springframework.data.redis.connection.PoolException: Returned connection io.lettuce.core.pubsub.StatefulRedisPubSubConnectionImpl@126a7e1b was either previously returned or does not belong to this connection provider Caused by: org.springframework.data.redis.connection.PoolException: Returned connection io.lettuce.core.pubsub.StatefulRedisPubSubConnectionImpl@126a7e1b was either previously returned or does not belong to this connection provider at org.springframework.data.redis.connection.lettuce.LettucePoolingConnectionProvider.releaseAsync(LettucePoolingConnectionProvider.java:192) at org.springframework.data.redis.connection.lettuce.LettuceConnectionFactory$ExceptionTranslatingConnectionProvider.releaseAsync(LettuceConnectionFactory.java:1834) at org.springframework.data.redis.connection.lettuce.LettuceReactiveRedisConnection$AsyncConnect.lambda$close$3(LettuceReactiveRedisConnection.java:373) at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:45) at reactor.core.publisher.Mono.subscribe(Mono.java:4568) at reactor.core.publisher.FluxFlatMap$FlatMapMain.onNext(FluxFlatMap.java:430) at reactor.core.publisher.FluxArray$ArraySubscription.slowPath(FluxArray.java:126) at reactor.core.publisher.FluxArray$ArraySubscription.request(FluxArray.java:99) at reactor.core.publisher.FluxFlatMap$FlatMapMain.onSubscribe(FluxFlatMap.java:373) at reactor.core.publisher.FluxMerge.subscribe(FluxMerge.java:73) at reactor.core.publisher.MonoFromFluxOperator.subscribe(MonoFromFluxOperator.java:83) at reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:53) at reactor.core.publisher.Mono.subscribe(Mono.java:4568) at reactor.core.publisher.Mono.subscribeWith(Mono.java:4634) at reactor.core.publisher.Mono.subscribe(Mono.java:4395) at org.springframework.data.redis.core.ReactiveRedisTemplate.lambda$listenTo$4(ReactiveRedisTemplate.java:289) at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.runFinally(FluxDoFinally.java:146) at reactor.core.publisher.FluxDoFinally$DoFinallySubscriber.cancel(FluxDoFinally.java:135) at reactor.core.publisher.FluxFlatMap$FlatMapMain.cancel(FluxFlatMap.java:361) at reactor.core.publisher.LambdaSubscriber.dispose(LambdaSubscriber.java:191) at org.springframework.session.data.redis.ReactiveRedisIndexedSessionRepository.destroy(ReactiveRedisIndexedSessionRepository.java:338) at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:211) at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:587) at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:559) at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:1202) at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:520) at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:1195) at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1195) at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1156) at org.springframework.boot.web.reactive.context.ReactiveWebServerApplicationContext.doClose(ReactiveWebServerApplicationContext.java:149) at org.springframework.context.support.AbstractApplicationContext.close(AbstractApplicationContext.java:1102) at org.springframework.boot.SpringApplicationShutdownHook.closeAndWait(SpringApplicationShutdownHook.java:145) at java.base/java.lang.Iterable.forEach(Iterable.java:75) at org.springframework.boot.SpringApplicationShutdownHook.run(SpringApplicationShutdownHook.java:114) at java.base/java.lang.Thread.run(Thread.java:840)`
My sample configuration below:
RedisConfig.java
`@Configuration public class RedisConfig {
@Bean
public LettuceConnectionFactory redisConnectionFactory() {
GenericObjectPoolConfig<?> genericObjectPoolConfig = new GenericObjectPoolConfig<>();
genericObjectPoolConfig.setMaxTotal(10);
genericObjectPoolConfig.setMaxIdle(5);
genericObjectPoolConfig.setMinIdle(1);
genericObjectPoolConfig.setTestOnBorrow(true);
LettuceClientConfiguration clientConfig = LettucePoolingClientConfiguration.builder()
.poolConfig(genericObjectPoolConfig)
.build();
RedisStandaloneConfiguration redisStandaloneConfiguration = new RedisStandaloneConfiguration();
redisStandaloneConfiguration.setDatabase(0);
redisStandaloneConfiguration.setHostName("localhost");
redisStandaloneConfiguration.setPort(6379);
return new LettuceConnectionFactory(redisStandaloneConfiguration, clientConfig);
}
}`
SessionConfig.java
@Configuration @EnableRedisIndexedWebSession public class SessionConfig { }
Hello,
This issue is also reproducible with the non-reactive version RedisIndexedSessionRepository, running with the following:
- Spring Boot
3.3.7 -
spring-session-data-redisversion3.3.5 - Jedis as the connection provider
To help reproduce and diagnose the issue, I have put up a sample project here: https://github.com/njuneau-coveo/spring-session-shutdown-demo . Upon shutdown, a stack trace similar to @ronniiii (but with Jedis instead of Lettuce) will appear in the logs at least once:
java.lang.IllegalStateException: JedisConnectionFactory has been STOPPED. Use start() to initialize it
at org.springframework.data.redis.connection.jedis.JedisConnectionFactory.assertInitialized(JedisConnectionFactory.java:1059) ~[spring-data-redis-3.3.7.jar!/:3.3.7]
at org.springframework.data.redis.connection.jedis.JedisConnectionFactory.getConnection(JedisConnectionFactory.java:880) ~[spring-data-redis-3.3.7.jar!/:3.3.7]
at org.springframework.data.redis.core.RedisConnectionUtils.fetchConnection(RedisConnectionUtils.java:195) ~[spring-data-redis-3.3.7.jar!/:3.3.7]
[...]
at org.springframework.session.data.redis.RedisSessionExpirationPolicy.cleanExpiredSessions(RedisSessionExpirationPolicy.java:132) ~[spring-session-data-redis-3.3.5.jar!/:3.3.5]
at org.springframework.session.data.redis.RedisIndexedSessionRepository.cleanUpExpiredSessions(RedisIndexedSessionRepository.java:489) ~[spring-session-data-redis-3.3.5.jar!/:3.3.5]
at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-6.1.16.jar!/:6.1.16]
at org.springframework.scheduling.concurrent.ReschedulingRunnable.run(ReschedulingRunnable.java:96) ~[spring-context-6.1.16.jar!/:6.1.16]
As mentioned in https://github.com/spring-projects/spring-data-redis/issues/2983 , RedisIndexedSessionRepository shuts down its cleanup job too late in the process since JedisConnectionFactory moved to SmartLifecycle.
The demo project provides an exaggerated cleanup cron and a Thread.sleep to make the issue consistently visible for debugging, but we have observed it in the wild in some of our actual projects.
Hopefully this will help out :)
