jeecgboot / JeecgBoot

🔥「企业级低代码平台」前后端分离架构SpringBoot 2.x/3.x,SpringCloud,Ant Design&Vue3,Mybatis,Shiro,JWT。强大的代码生成器让前后端代码一键生成,无需写任何代码! 引领新的开发模式,引入AI模型能力 OnlineCoding->代码生成->手工MERGE,帮助Java项目解决70%重复工作,让开发更关注业务,既能快速提高效率,帮助公司节省成本,同时又不失灵活性。
http://www.jeecg.com
Apache License 2.0
40.57k stars 14.82k forks source link

quartz定时任务重启之后不会自动恢复 #5440

Closed lq-java closed 1 year ago

lq-java commented 1 year ago
版本号:

3.5.0

前端版本:vue3版?还是 vue2版?

vue3

问题描述:

quartz再重启服务之后不会自动恢复,并且调用任务的启用接口,会报Lock wait timeout exceeded; try restarting transaction,可是搜索数据库并没有锁,只要调用启用接口,就会有锁。我是单节点的,并不存在集群之类的问题。

截图&代码:

以下为我nacos的配置内容 image

以下为启动和请求启动定时任务的输出日志 `2023-10-02 17:01:15.722 [main] INFO org.jeecg.common.modules.redis.config.RedisConfig:56 - --- redis config init --- 2023-10-02 17:01:23.129 [main] INFO org.quartz.impl.StdSchedulerFactory:1220 - Using default implementation for ThreadExecutor 2023-10-02 17:01:23.130 [main] INFO org.quartz.simpl.SimpleThreadPool:268 - Job execution threads will use class loader of thread: main 2023-10-02 17:01:23.144 [main] INFO org.quartz.core.SchedulerSignalerImpl:61 - Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl 2023-10-02 17:01:23.144 [main] INFO org.quartz.core.QuartzScheduler:229 - Quartz Scheduler v.2.3.2 created. 2023-10-02 17:01:24.700 [main] INFO o.s.scheduling.quartz.LocalDataSourceJobStore:672 - Using db table-based data access locking (synchronization). 2023-10-02 17:01:24.704 [main] INFO o.s.scheduling.quartz.LocalDataSourceJobStore:145 - JobStoreCMT initialized. 2023-10-02 17:01:25.313 [main] INFO org.quartz.core.QuartzScheduler:294 - Scheduler meta-data: Quartz Scheduler (v2.3.2) 'MyScheduler' with instanceId 'NON_CLUSTERED' Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally. NOT STARTED. Currently in standby mode. Number of jobs executed: 0 Using thread pool 'org.quartz.simpl.SimpleThreadPool' - with 10 threads. Using job-store 'org.springframework.scheduling.quartz.LocalDataSourceJobStore' - which supports persistence. and is not clustered.

2023-10-02 17:01:25.314 [main] INFO org.quartz.impl.StdSchedulerFactory:1374 - Quartz scheduler 'MyScheduler' initialized from an externally provided properties instance. 2023-10-02 17:01:25.314 [main] INFO org.quartz.impl.StdSchedulerFactory:1378 - Quartz scheduler version: 2.3.2 2023-10-02 17:01:25.314 [main] INFO org.quartz.core.QuartzScheduler:2293 - JobFactory set to: org.springframework.scheduling.quartz.SpringBeanJobFactory@bc70176 2023-10-02 17:01:26.525 [main] INFO o.s.cloud.openfeign.FeignClientFactoryBean:418 - For 'jeecg-merchant' URL not provided. Will try picking an instance via load-balancing. 2023-10-02 17:01:30.898 [main] INFO o.j.modules.jmreport.config.JmReportExecutorConfig:42 - Init JimuReport Config [ 线程池 ] 2023-10-02 17:01:31.957 [main] INFO c.alibaba.cloud.sentinel.SentinelWebMvcConfigurer:52 - [Sentinel Starter] register SentinelWebInterceptor with urlPatterns: [/**]. 2023-10-02 17:01:32.838 [main] INFO o.s.b.actuate.endpoint.web.EndpointLinksResolver:58 - Exposing 28 endpoint(s) beneath base path '/actuator' 2023-10-02 17:01:33.038 [main] INFO org.jeecg.config.init.CodeGenerateDbConfig:46 - Init CodeGenerate Config [ Get Db Config From application.yml ] 2023-10-02 17:01:33.299 [main] INFO o.j.boot.starter.rabbitmq.client.RabbitMqClient:76 - 初始化队列...method.........methodRabbitListener=@org.springframework.amqp.rabbit.annotation.RabbitListener(queuesToDeclare=[@org.springframework.amqp.rabbit.annotation.Queue(durable=, declare=true, ignoreDeclarationExceptions=false, autoDelete=, name=, exclusive=, arguments=[], value=delivery.order.timeout, admins=[])], containerFactory=, converterWinsContentType=true, bindings=[], admin=, messageConverter=, replyContentType=, priority=, concurrency=, autoStartup=, queues=[], executor=, replyPostProcessor=, returnExceptions=, ackMode=, exclusive=false, errorHandler=, id=, group=) 2023-10-02 17:01:33.301 [main] INFO o.s.a.rabbit.connection.CachingConnectionFactory:638 - Attempting to connect to: [114.115.148.162:5672] 2023-10-02 17:01:33.449 [main] INFO o.s.a.rabbit.connection.CachingConnectionFactory:589 - Created new connection: rabbitConnectionFactory#33ef701e:0/SimpleConnection@27ddc4d3 [delegate=amqp://hsby@114.115.148.162:5672/, localPort= 52501] | |. __ | . .
| | |\/|
)(| | |\ |)|||\ | () | | | / | / 1.4.5 2023-10-02 17:01:35.013 [main] INFO o.s.c.stream.messaging.DirectWithAttributesChannel:174 - Channel 'jeecg-system.springCloudBusInput' has 1 subscriber(s). 2023-10-02 17:01:36.187 [main] INFO o.s.integration.monitor.IntegrationMBeanExporter:681 - Registering MessageChannel errorChannel 2023-10-02 17:01:36.258 [main] INFO o.s.integration.monitor.IntegrationMBeanExporter:681 - Registering MessageChannel springCloudBusInput 2023-10-02 17:01:36.303 [main] INFO o.s.integration.monitor.IntegrationMBeanExporter:681 - Registering MessageChannel nullChannel 2023-10-02 17:01:36.328 [main] INFO o.s.integration.monitor.IntegrationMBeanExporter:703 - Registering MessageHandler _org.springframework.integration.errorLogger 2023-10-02 17:01:36.398 [main] INFO o.s.integration.endpoint.EventDrivenConsumer:174 - Adding {logging-channel-adapter:_org.springframework.integration.errorLogger} as a subscriber to the 'errorChannel' channel 2023-10-02 17:01:36.399 [main] INFO o.s.integration.channel.PublishSubscribeChannel:174 - Channel 'jeecg-system.errorChannel' has 1 subscriber(s). 2023-10-02 17:01:36.399 [main] INFO o.s.integration.endpoint.EventDrivenConsumer:292 - started bean '_org.springframework.integration.errorLogger' 2023-10-02 17:01:36.421 [main] INFO o.s.cloud.stream.binder.DefaultBinderFactory:251 - Creating binder: rabbit 2023-10-02 17:01:36.517 [main] INFO o.s.cloud.stream.binder.DefaultBinderFactory:294 - Caching the binder: rabbit 2023-10-02 17:01:36.518 [main] INFO o.s.cloud.stream.binder.DefaultBinderFactory:298 - Retrieving cached binder: rabbit 2023-10-02 17:01:36.621 [main] INFO o.s.c.s.b.r.p.RabbitExchangeQueueProvisioner:241 - declaring queue for inbound: springCloudBus.anonymous.Xl4uX5RLT1GxmVf2c2J85Q, bound to: springCloudBus 2023-10-02 17:01:36.700 [main] INFO o.s.cloud.stream.binder.BinderErrorChannel:174 - Channel 'springCloudBus.anonymous.Xl4uX5RLT1GxmVf2c2J85Q.errors' has 1 subscriber(s). 2023-10-02 17:01:36.700 [main] INFO o.s.cloud.stream.binder.BinderErrorChannel:174 - Channel 'springCloudBus.anonymous.Xl4uX5RLT1GxmVf2c2J85Q.errors' has 2 subscriber(s). 2023-10-02 17:01:36.773 [main] INFO o.s.i.amqp.inbound.AmqpInboundChannelAdapter:292 - started bean 'inbound.springCloudBus.anonymous.Xl4uX5RLT1GxmVf2c2J85Q' 2023-10-02 17:01:36.777 [main] INFO org.apache.coyote.http11.Http11NioProtocol:173 - Starting ProtocolHandler ["http-nio-7001"] 2023-10-02 17:01:36.797 [main] INFO o.s.boot.web.embedded.tomcat.TomcatWebServer:220 - Tomcat started on port(s): 7001 (http) with context path '' 2023-10-02 17:01:36.805 [main] INFO c.a.cloud.nacos.registry.NacosServiceRegistry:75 - nacos registry, DEFAULT_GROUP jeecg-system 192.168.1.125:7001 register finished 2023-10-02 17:01:40.441 [main] INFO o.s.integration.monitor.IntegrationMBeanExporter:681 - Registering MessageChannel springCloudBus.anonymous.Xl4uX5RLT1GxmVf2c2J85Q.errors 2023-10-02 17:01:40.583 [main] INFO org.jeecg.JeecgSystemCloudApplication:61 - Started JeecgSystemCloudApplication in 39.023 seconds (JVM running for 40.408) 2023-10-02 17:01:40.631 [main] INFO org.jeecg.config.init.SystemInitListener:30 - 服务已启动,初始化路由配置 ################### 2023-10-02 17:01:40.632 [redisContainer-2] WARN org.jeecg.common.util.SpringContextHolder:53 - Customize redis listener handle [ loderRouderHandler ], does not exist! Creating a new SqlSession SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@254c4757] was not registered for synchronization because synchronization is not active original SQL: SELECT
id,router_id,name,uri,predicates,filters,strip_prefix,retryable,persistable,show_api,status,create_by,create_time FROM sys_gateway_route SQL to parse, SQL: SELECT
id,router_id,name,uri,predicates,filters,strip_prefix,retryable,persistable,show_api,status,create_by,create_time FROM sys_gateway_route parse the finished SQL: SELECT id, router_id, name, uri, predicates, filters, strip_prefix, retryable, persistable, show_api, status, create_by, create_time FROM sys_gateway_route JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@421b4cf3] will not be managed by Spring ==> Preparing: SELECT id, router_id, name, uri, predicates, filters, strip_prefix, retryable, persistable, show_api, status, create_by, create_time FROM sys_gateway_route ==> Parameters: <== Columns: id, router_id, name, uri, predicates, filters, strip_prefix, retryable, persistable, show_api, status, create_by, create_time <== Row: 1331051599401857026, jeecg-demo-websocket, jeecg-demo-websocket, lb:ws://jeecg-demo, <>, <>, null, null, null, null, 1, admin, 2020-11-24 09:46:46 <== Row: jeecg-cloud-websocket, jeecg-system-websocket, jeecg-system-websocket, lb:ws://jeecg-system, <>, <>, null, null, null, null, 1, admin, 2020-11-16 19:41:51 <== Row: jeecg-demo, jeecg-demo, jeecg-demo, lb://jeecg-demo, <>, <>, null, null, null, null, 1, admin, 2020-11-16 19:41:51 <== Row: jeecg-system, jeecg-system, jeecg-system, lb://jeecg-system, <>, <>, null, null, null, null, 1, admin, 2020-11-16 19:41:51 <== Total: 4 Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@254c4757] 2023-10-02 17:01:40.936 [main] INFO org.jeecg.config.init.CodeTemplateInitListener:30 - Init Code Generate Template [ 检测如果是JAR启动环境,Copy模板到config目录 ] 2023-10-02 17:01:40.962 [main] INFO c.a.cloud.nacos.refresh.NacosContextRefresher:105 - listening config: dataId=jeecg-dev.yaml, group=dev 2023-10-02 17:01:40.963 [main] INFO c.a.cloud.nacos.refresh.NacosContextRefresher:105 - listening config: dataId=jeecg.yaml, group=dev 2023-10-02 17:01:40.964 [main] INFO org.jeecg.JeecgSystemCloudApplication:50 - Application Jeecg-Boot is running! Access URLs: Local: http://localhost:7001/doc.html External: http://192.168.1.125:7001/doc.html Swagger文档: http://192.168.1.125:7001/doc.html 2023-10-02 17:01:41.134 [RMI TCP Connection(10)-192.168.1.125] INFO o.a.c.core.ContainerBase.[Tomcat].[localhost].[/]:173 - Initializing Spring DispatcherServlet 'dispatcherServlet' 2023-10-02 17:01:41.135 [RMI TCP Connection(10)-192.168.1.125] INFO org.springframework.web.servlet.DispatcherServlet:525 - Initializing Servlet 'dispatcherServlet' 2023-10-02 17:01:41.144 [RMI TCP Connection(10)-192.168.1.125] INFO org.springframework.web.servlet.DispatcherServlet:547 - Completed initialization in 8 ms INFO: Sentinel log output type is: file INFO: Sentinel log charset is: utf-8 INFO: Sentinel log base directory is: C:\Users\Administrator\logs\csp\ INFO: Sentinel log name use pid is: false 2023-10-02 17:01:56.389 [http-nio-7001-exec-2] INFO org.jeecg.config.shiro.filters.JwtFilter:95 - JwtFilter-->>>isAccessAllowed-Method:init() 2023-10-02 17:01:56.389 [http-nio-7001-exec-2] INFO org.jeecg.config.shiro.filters.JwtFilter:135 - JwtFilter-->>>isLoginAttempt-Method:init() 2023-10-02 17:01:56.390 [http-nio-7001-exec-2] INFO org.jeecg.config.shiro.filters.JwtFilter:137 - isLoginAttempt--req.URI-->>>/sys/quartzJob/resume 2023-10-02 17:01:56.390 [http-nio-7001-exec-2] INFO org.jeecg.config.shiro.filters.JwtFilter:159 - JwtFilter-->>>executeLogin-Method:init() 2023-10-02 17:01:56.390 [http-nio-7001-exec-2] INFO org.jeecg.config.shiro.filters.JwtFilter:161 - executeLogin--req.URI-->>>/sys/quartzJob/resume Creating a new SqlSession SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@23eee7bc] was not registered for synchronization because synchronization is not active original SQL: SELECT id,create_by,create_time,del_flag,update_by,update_time,job_class_name,cron_expression,parameter,description,status FROM sys_quartz_job WHERE id=? SQL to parse, SQL: SELECT id,create_by,create_time,del_flag,update_by,update_time,job_class_name,cron_expression,parameter,description,status FROM sys_quartz_job WHERE id=? parse the finished SQL: SELECT id, create_by, create_time, del_flag, update_by, update_time, job_class_name, cron_expression, parameter, description, status FROM sys_quartz_job WHERE id = ? JDBC Connection [com.alibaba.druid.proxy.jdbc.ConnectionProxyImpl@421b4cf3] will not be managed by Spring ==> Preparing: SELECT id, create_by, create_time, del_flag, update_by, update_time, job_class_name, cron_expression, parameter, description, status FROM sys_quartz_job WHERE id = ? ==> Parameters: 1708737747921846273(String) <== Columns: id, create_by, create_time, del_flag, update_by, update_time, job_class_name, cron_expression, parameter, description, status <== Row: 1708737747921846273, null, null, 0, null, null, org.jeecg.modules.quartz.job.SampleJob, 0/10 ? , null, 测试定时任务, 0 <== Total: 1 Closing non transactional SqlSession [org.apache.ibatis.session.defaults.DefaultSqlSession@23eee7bc] 2023-10-02 17:02:50.988 [http-nio-7001-exec-2] ERROR druid.sql.Statement:149 - {conn-10004, pstmt-20012} execute error. SELECT FROM qrtz_LOCKS WHERE SCHED_NAME = 'MyScheduler' AND LOCK_NAME = ? FOR UPDATE com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:123) at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122) at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:916) at com.mysql.cj.jdbc.ClientPreparedStatement.executeQuery(ClientPreparedStatement.java:972) at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3240) at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(FilterEventAdapter.java:465) at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3237) at com.alibaba.druid.wall.WallFilter.preparedStatement_executeQuery(WallFilter.java:647) at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3237) at com.alibaba.druid.filter.FilterEventAdapter.preparedStatement_executeQuery(FilterEventAdapter.java:465) at com.alibaba.druid.filter.FilterChainImpl.preparedStatement_executeQuery(FilterChainImpl.java:3237) at com.alibaba.druid.proxy.jdbc.PreparedStatementProxyImpl.executeQuery(PreparedStatementProxyImpl.java:181) at com.alibaba.druid.pool.DruidPooledPreparedStatement.executeQuery(DruidPooledPreparedStatement.java:227) at org.quartz.impl.jdbcjobstore.StdRowLockSemaphore.executeSQL(StdRowLockSemaphore.java:123) at org.quartz.impl.jdbcjobstore.DBSemaphore.obtainLock(DBSemaphore.java:113) at org.quartz.impl.jdbcjobstore.JobStoreSupport.executeInNonManagedTXLock(JobStoreSupport.java:3857) at org.quartz.impl.jdbcjobstore.JobStoreSupport.recoverJobs(JobStoreSupport.java:839) at org.quartz.impl.jdbcjobstore.JobStoreSupport.schedulerStarted(JobStoreSupport.java:695) at org.quartz.core.QuartzScheduler.start(QuartzScheduler.java:539) at org.quartz.impl.StdScheduler.start(StdScheduler.java:142) at org.jeecg.modules.quartz.service.impl.QuartzJobServiceImpl.schedulerAdd(QuartzJobServiceImpl.java:141) at org.jeecg.modules.quartz.service.impl.QuartzJobServiceImpl.resumeJob(QuartzJobServiceImpl.java:68)`

友情提示(为了提高issue处理效率):

lq-java commented 1 year ago

image 这里任务启动的事务注释掉就可以正常启动定时任务了,不知道是不是qz底层的事务传播机制、隔离级别之类的问题

zhangdaiscott commented 1 year ago

收到。后面我们观察下,我们暂时未发现问题

AnAloneJaver commented 10 months ago

截止2023年12月26日 10:32:19 image 这个问题仍然没有被解决