search

lukas-krecan / ShedLock

Distributed lock for your scheduled tasks
Apache License 2.0
3.65k stars 517 forks source link

Error while trying to get the lock #1485

Closed fredericks closed 1 year ago

fredericks commented 1 year ago

Hello, I'm getting an error every time I start my springboot application with shedlock and it tries to get the lock of a scheduled task for the first time. I'm adding some information as suggested by your guidelines.

Version of Shedlock: 5.3.0 Lock Provider is: JdbcTemplateLockProvider with MySql

Expected behavior: I am expecting no exceptions

Actual behavior I get the exception listed in the log below

My DBMS is MySql.

The table is exactly the one described in the documentation:

CREATE TABLE shedlock ( name VARCHAR(64) NOT NULL COLLATE 'utf8mb4_general_ci', lock_until TIMESTAMP(3) NULL DEFAULT NULL, locked_at TIMESTAMP(3) NULL DEFAULT NULL, locked_by VARCHAR(255) NULL DEFAULT NULL COLLATE 'utf8mb4_general_ci', PRIMARY KEY (name) USING BTREE ) COLLATE='utf8mb4_general_ci' ENGINE=InnoDB ;

I get the error below, only the first time the application tries to get the lock. After that, next time it tries to get the lock, there is no exception, just the message "Not executing 'Unanswered Questions'. It's locked.".

Here is the logs:

2023-07-19 11:11:01 DEBUG JdbcTemplateStorageAccessor:70 - insertRecord(...) Duplicate key org.springframework.dao.DuplicateKeyException: PreparedStatementCallback; SQL [INSERT INTO shedlock(name, lock_until, locked_at, locked_by) VALUES(?, ?, ?, ?)]; Duplicate entry 'Unanswered Questions' for key 'PRIMARY'; nested exception is java.sql.SQLIntegrityConstraintViolationException: Duplicate entry 'Unanswered Questions' for key 'PRIMARY' at org.springframework.jdbc.support.SQLErrorCodeSQLExceptionTranslator.doTranslate(SQLErrorCodeSQLExceptionTranslator.java:247) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:70) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.core.JdbcTemplate.translateException(JdbcTemplate.java:1541) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:667) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:960) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.core.JdbcTemplate.update(JdbcTemplate.java:981) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.update(NamedParameterJdbcTemplate.java:328) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.core.namedparam.NamedParameterJdbcTemplate.update(NamedParameterJdbcTemplate.java:333) ~[spring-jdbc-5.3.27.jar:5.3.27] at net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateStorageAccessor.lambda$execute$0(JdbcTemplateStorageAccessor.java:119) ~[shedlock-provider-jdbc-template-5.3.0.jar:?] at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.3.27.jar:5.3.27] at net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateStorageAccessor.execute(JdbcTemplateStorageAccessor.java:119) ~[shedlock-provider-jdbc-template-5.3.0.jar:?] at net.javacrumbs.shedlock.provider.jdbctemplate.JdbcTemplateStorageAccessor.insertRecord(JdbcTemplateStorageAccessor.java:68) ~[shedlock-provider-jdbc-template-5.3.0.jar:?] at net.javacrumbs.shedlock.support.StorageBasedLockProvider.doLock(StorageBasedLockProvider.java:79) ~[shedlock-core-5.3.0.jar:?] at net.javacrumbs.shedlock.support.StorageBasedLockProvider.lock(StorageBasedLockProvider.java:62) ~[shedlock-core-5.3.0.jar:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?] at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?] at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?] at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?] at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.27.jar:5.3.27] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) ~[spring-aop-5.3.27.jar:5.3.27] at jdk.proxy2.$Proxy80.lock(Unknown Source) ~[?:?] at net.javacrumbs.shedlock.core.DefaultLockingTaskExecutor.executeWithLock(DefaultLockingTaskExecutor.java:60) ~[shedlock-core-5.3.0.jar:?] at net.javacrumbs.shedlock.spring.aop.MethodProxyScheduledLockAdvisor$LockingInterceptor.invoke(MethodProxyScheduledLockAdvisor.java:83) ~[shedlock-spring-5.3.0.jar:?] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.27.jar:5.3.27] at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.27.jar:5.3.27] at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115) ~[spring-aop-5.3.27.jar:5.3.27] at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?] at java.lang.Thread.run(Thread.java:833) [?:?] Caused by: java.sql.SQLIntegrityConstraintViolationException: Duplicate entry 'Unanswered Questions' for key 'PRIMARY' at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:118) ~[mysql-connector-j-8.0.33.jar:8.0.33] at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122) ~[mysql-connector-j-8.0.33.jar:8.0.33] at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:916) ~[mysql-connector-j-8.0.33.jar:8.0.33] at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1061) ~[mysql-connector-j-8.0.33.jar:8.0.33] at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1009) ~[mysql-connector-j-8.0.33.jar:8.0.33] at com.mysql.cj.jdbc.ClientPreparedStatement.executeLargeUpdate(ClientPreparedStatement.java:1320) ~[mysql-connector-j-8.0.33.jar:8.0.33] at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:994) ~[mysql-connector-j-8.0.33.jar:8.0.33] at com.zaxxer.hikari.pool.ProxyPreparedStatement.executeUpdate(ProxyPreparedStatement.java:61) ~[HikariCP-4.0.3.jar:?] at com.zaxxer.hikari.pool.HikariProxyPreparedStatement.executeUpdate(HikariProxyPreparedStatement.java) ~[HikariCP-4.0.3.jar:?] at org.springframework.jdbc.core.JdbcTemplate.lambda$update$2(JdbcTemplate.java:965) ~[spring-jdbc-5.3.27.jar:5.3.27] at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:651) ~[spring-jdbc-5.3.27.jar:5.3.27] ... 26 more 2023-07-19 11:11:01 DEBUG DefaultLockingTaskExecutor:93 - executeWithLock(...) Not executing 'Unanswered Questions'. It's locked.

fredericks commented 1 year ago

All right, my bad, I was behind with updates. So I updated to 5.5.0 and the problem disappeared.

Thanks anyway