Support for Graceful Shutdown in @SchedulerLock

[Junuu]

Is your feature request related to a problem? Please describe.
When utilizing @SchedulerLock, we registered TaskScheduler as a Spring Bean and set setAwaitTerminationSeconds.

1. Upon receiving the SIGTERM signal
2. the scheduled job terminates,
3. attempts to release the lock,
4. encounters a LockException during the release process
5. however, despite the exception, the lock is successfully released.

Describe the solution you'd like
It would be nice if @SchedulerLock supported graceful shtudown.
Or if there are other alternatives I'm missing, I'd love to hear about them.

Additional context

@Scheduled(fixedDelay = 1000 * 11)
    @SchedulerLock(name = "run3", lockAtLeastFor = "PT10S", lockAtMostFor = "PT10S")
    fun run3(){
        LockAssert.assertLocked();
        logger.info { "Hello ScheduledTask3 - processing!" }
        val result = RestTemplate().getForEntity<String>("http://httpbin.org/delay/10")
        logger.info { "Hello ScheduledTask3 - done!" }
    }

@Configuration
class ScheduledConfig {

    @Bean
    fun scheduledThreadPool(): TaskScheduler{
        val taskScheduler = ThreadPoolTaskScheduler()
        taskScheduler.poolSize = 10
        taskScheduler.setThreadNamePrefix("custom-name")
        taskScheduler.setAwaitTerminationSeconds(20)
        taskScheduler.setWaitForTasksToCompleteOnShutdown(true)
        return taskScheduler
    }
}

[lukas-krecan]

Hi, can you please share the whole exception stack trace?

[Junuu]

Sorry for the confusion earlier, the full stack trace is below.

2024-05-05T23:14:10.225+09:00  INFO 14440 --- [   custom-name2] com.example.study.log.Logging            : Hello ScheduledTask4 - processing!
2024-05-05T23:14:12.039+09:00  INFO 14440 --- [ionShutdownHook] o.s.b.w.e.tomcat.GracefulShutdown        : Commencing graceful shutdown. Waiting for active requests to complete
2024-05-05T23:14:12.044+09:00  INFO 14440 --- [tomcat-shutdown] o.s.b.w.e.tomcat.GracefulShutdown        : Graceful shutdown complete
2024-05-05T23:14:20.705+09:00  INFO 14440 --- [   custom-name2] com.example.study.log.Logging            : Hello ScheduledTask4 - done!
2024-05-05T23:14:20.707+09:00 ERROR 14440 --- [   custom-name2] o.s.s.s.TaskUtils$LoggingErrorHandler    : Unexpected error occurred in scheduled task

net.javacrumbs.shedlock.support.LockException: Can not remove node
	at net.javacrumbs.shedlock.provider.redis.spring.RedisLockProvider$RedisLock.doUnlock(RedisLockProvider.java:143) ~[shedlock-provider-redis-spring-5.13.0.jar:na]
	at net.javacrumbs.shedlock.core.AbstractSimpleLock.unlock(AbstractSimpleLock.java:30) ~[shedlock-core-5.13.0.jar:na]
	at net.javacrumbs.shedlock.core.DefaultLockingTaskExecutor.executeWithLock(DefaultLockingTaskExecutor.java:75) ~[shedlock-core-5.13.0.jar:na]
	at net.javacrumbs.shedlock.spring.aop.MethodProxyScheduledLockAdvisor$LockingInterceptor.invoke(MethodProxyScheduledLockAdvisor.java:79) ~[shedlock-spring-5.13.0.jar:na]
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:184) ~[spring-aop-6.0.9.jar:6.0.9]
	at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-6.0.9.jar:6.0.9]
	at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:702) ~[spring-aop-6.0.9.jar:6.0.9]
	at com.example.study.scheduled.ScheduledTask$$SpringCGLIB$$0.run4(<generated>) ~[main/:na]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
	at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
	at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-6.0.9.jar:6.0.9]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-6.0.9.jar:6.0.9]
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
	at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[na:na]
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
	at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]
Caused by: org.springframework.data.redis.RedisSystemException: Redis command interrupted
	at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:60) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.lettuce.LettuceExceptionConverter.convert(LettuceExceptionConverter.java:41) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.PassThroughExceptionTranslationStrategy.translate(PassThroughExceptionTranslationStrategy.java:40) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.FallbackExceptionTranslationStrategy.translate(FallbackExceptionTranslationStrategy.java:38) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.lettuce.LettuceConnection.convertLettuceAccessException(LettuceConnection.java:248) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.lettuce.LettuceConnection.await(LettuceConnection.java:961) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.lettuce.LettuceConnection.lambda$doInvoke$4(LettuceConnection.java:818) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.lettuce.LettuceInvoker$Synchronizer.invoke(LettuceInvoker.java:665) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.lettuce.LettuceInvoker.just(LettuceInvoker.java:94) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.lettuce.LettuceKeyCommands.del(LettuceKeyCommands.java:91) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.DefaultedRedisConnection.del(DefaultedRedisConnection.java:100) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.connection.DefaultStringRedisConnection.del(DefaultStringRedisConnection.java:307) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.core.RedisTemplate.lambda$delete$5(RedisTemplate.java:588) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.core.RedisTemplate.lambda$doWithKeys$22(RedisTemplate.java:785) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:406) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.core.RedisTemplate.execute(RedisTemplate.java:373) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.core.RedisTemplate.doWithKeys(RedisTemplate.java:785) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at org.springframework.data.redis.core.RedisTemplate.delete(RedisTemplate.java:588) ~[spring-data-redis-3.1.0.jar:3.1.0]
	at net.javacrumbs.shedlock.provider.redis.spring.RedisLockProvider$RedisLock.doUnlock(RedisLockProvider.java:141) ~[shedlock-provider-redis-spring-5.13.0.jar:na]
	... 19 common frames omitted
Caused by: io.lettuce.core.RedisCommandInterruptedException: Command interrupted
	at io.lettuce.core.protocol.AsyncCommand.await(AsyncCommand.java:87) ~[lettuce-core-6.2.4.RELEASE.jar:6.2.4.RELEASE]
	at io.lettuce.core.internal.Futures.awaitOrCancel(Futures.java:244) ~[lettuce-core-6.2.4.RELEASE.jar:6.2.4.RELEASE]
	at io.lettuce.core.LettuceFutures.awaitOrCancel(LettuceFutures.java:74) ~[lettuce-core-6.2.4.RELEASE.jar:6.2.4.RELEASE]
	at org.springframework.data.redis.connection.lettuce.LettuceConnection.await(LettuceConnection.java:959) ~[spring-data-redis-3.1.0.jar:3.1.0]
	... 32 common frames omitted
Caused by: java.lang.InterruptedException: null
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:386) ~[na:na]
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2096) ~[na:na]
	at io.lettuce.core.protocol.AsyncCommand.await(AsyncCommand.java:83) ~[lettuce-core-6.2.4.RELEASE.jar:6.2.4.RELEASE]
	... 35 common frames omitted


Process finished with exit code 130

[lukas-krecan]

Hi, as you can see from the stack-trace, ShedLock tried to unlock the lock, but the thread was interrupted (most likely due to the shutdown). There is not much we can do.

[Junuu]

Thank you for your response.
As for the direction you recommend, should I provide control for graceful shutdown in the code that uses the library?

[lukas-krecan]

You can try the trick described here