# Bug8538复现 **Repository Path**: bnyte/bug8538-reproduced ## Basic Information - **Project Name**: Bug8538复现 - **Description**: No description available - **Primary Language**: Java - **License**: Not specified - **Default Branch**: main - **Homepage**: None - **GVP Project**: No ## Statistics - **Stars**: 0 - **Forks**: 0 - **Created**: 2024-03-13 - **Last Updated**: 2024-03-13 ## Categories & Tags **Categories**: Uncategorized **Tags**: None ## README # Bug8538复现 ## 问题背景 某一个整个大的事务中有一个小事务在Java代码中执行时长超出了数据库配置的锁等待超时时间依然没有提交或者回滚事务。 ## 系统环境 见[pom.xml](pom.xml) ## 系统配置 见[application.yaml](./src/main/resources/application.yaml) ## 复现操作 > ⚠️注意:在你执行复现操作之前请先修改系统配置的数据库配置!!!! 见 [IssueControllerTest](./src/test/java/me/liujixiang/cloudrun/controller/IssueControllerTest.java#L18)的`init()`测试方法。 ## 注意事项 如果你想复现锁表操作(如下日志)问题,请去掉[IssueServiceImpl](./src/main/java/me/liujixiang/cloudrun/service/impl/IssueServiceImpl.java#L27)的事务注解。 当去掉该注解之后我们会把整个事务交给 `父级事务管理` 即父级事务提交之后其中的事务才能被提交 而当我们的事务时长超出了mysql配置的锁等待超时时间(使用`show variables like 'innodb_lock_wait_timeout';`查看)就会抛出`Lock wait timeout exceeded; try restarting transaction`如下日志所示 同时我们可以通过`show processlist;`(也可以使用`select * from information_schema.processlist;`因为`show processlist;`数据来自该表)以确认我们当前数据库中有哪些进程,如果这个进程中的`Time(单位为秒)`大于或者等于`innodb_lock_wait_timeout`时就会抛出如下异常。 如果想快速解决可以将某一个超时的sql抽离出来,请加上[IssueServiceImpl](./src/main/java/me/liujixiang/cloudrun/service/impl/IssueServiceImpl.java#L27)的事务注解。 核心思路就是 将子事务交给他自己管理,让其自己创建一个新的事务,下面粘贴一段关于官方代码上的注释描述 ``` /** * Create a new transaction, and suspend the current transaction if one exists. * Analogous to the EJB transaction attribute of the same name. *

NOTE: Actual transaction suspension will not work out-of-the-box * on all transaction managers. This in particular applies to * {@link org.springframework.transaction.jta.JtaTransactionManager}, * which requires the {@code javax.transaction.TransactionManager} to be * made available it to it (which is server-specific in standard Java EE). * @see org.springframework.transaction.jta.JtaTransactionManager#setTransactionManager */ REQUIRES_NEW(TransactionDefinition.PROPAGATION_REQUIRES_NEW), ``` ``` Exception in thread "Thread-4" org.springframework.dao.CannotAcquireLockException: could not execute statement; SQL [n/a]; nested exception is org.hibernate.exception.LockAcquisitionException: could not execute statement at org.springframework.orm.jpa.vendor.HibernateJpaDialect.convertHibernateAccessException(HibernateJpaDialect.java:269) at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:244) at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:488) at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:59) at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:213) at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:147) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:133) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:57) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213) at com.sun.proxy.$Proxy89.updateById(Unknown Source) at me.liujixiang.cloudrun.service.impl.IssueServiceImpl.updateById(IssueServiceImpl.java:27) at me.liujixiang.cloudrun.controller.IssueController.init(IssueController.java:36) at me.liujixiang.cloudrun.controller.IssueController$$FastClassBySpringCGLIB$$3c015895.invoke() at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204) at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673) at me.liujixiang.cloudrun.controller.IssueController$$EnhancerBySpringCGLIB$$8f5de706.init() at me.liujixiang.cloudrun.controller.IssueControllerTest.lambda$init$0(IssueControllerTest.java:21) at java.lang.Thread.run(Thread.java:748) Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement at org.hibernate.dialect.MySQLDialect$3.convert(MySQLDialect.java:524) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:42) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:95) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:207) at org.hibernate.engine.query.spi.NativeSQLQueryPlan.performExecuteUpdate(NativeSQLQueryPlan.java:194) at org.hibernate.internal.SessionImpl.executeNativeUpdate(SessionImpl.java:1373) at org.hibernate.internal.SQLQueryImpl.executeUpdate(SQLQueryImpl.java:373) at org.hibernate.jpa.internal.QueryImpl.internalExecuteUpdate(QueryImpl.java:405) at org.hibernate.jpa.spi.AbstractQueryImpl.executeUpdate(AbstractQueryImpl.java:61) at org.springframework.data.jpa.repository.query.JpaQueryExecution$ModifyingExecution.doExecute(JpaQueryExecution.java:238) at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:85) at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:116) at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:106) at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:483) at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:461) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:56) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136) ... 23 more Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at com.mysql.jdbc.Util.handleNewInstance(Util.java:404) at com.mysql.jdbc.Util.getInstance(Util.java:387) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:950) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3966) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3902) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2526) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2673) at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2549) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1861) at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2073) at com.mysql.jdbc.PreparedStatement.executeUpdateInternal(PreparedStatement.java:2009) at com.mysql.jdbc.PreparedStatement.executeLargeUpdate(PreparedStatement.java:5098) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:1994) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114) at com.sun.proxy.$Proxy97.executeUpdate(Unknown Source) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:204) ... 42 more ``` > 以下为`show processlist;`执行结果 | Id | User | Host | db | Command | Time | State | Info | |----|------|----------------|------|---------|------|----------|----------------------------------------------------------| | 1 | root | 127.0.0.1:2352 | user | Sleep | 31 | starting | /* ApplicationName=DataGrip 2023.3.4 */ show processlist | ``` id: 这个线程的唯一表示 User: 这个线程的用户 Host: 发送请求的客户端的IP和端口号 DB: 当前执行的命令是在哪一个数据库上,如果没有置顶数据库,则为NULL Command: 指此刻该线程正在执行的命令 Time:指该线程处于当前状态的时间 State:线程的状态 Info: 一般记录的是该县城执行的语句,默认只显示前100个字符,要看全部信息需要使用`show full processlist` ```