I have a problem with concurrent transactions using JPA-1.0, Hibernate and MySQL 5.0.84 (innoDB tables) as well as Postgres 8.1.11 (different database for different clients). I don’t know if I am missing something regarding the configuration, since I read the specifications for the JPA transactions, and according to my problem, I need to specify a specific isolation level for transaction annotation. I did this, but it just disconnects the transaction, so nothing is saved or updated.
What I am doing is triggering HTTP messages on a web server (tomcat in my case), which then tries to invoke several database transactions as HTTP requests arrive. Each transaction includes 1 insert and 2 updates. The problem always arises in the latest update, although it is based on the previous insert. So, I insert record A, and then update record B, which is the foreign key for record A.
The following is the log that I get when I execute a single HTTP request:
org.springframework.orm.jpa.JpaTransactionManager:365 - Creating new transaction with name [biz.cytrus.overlord.v2.core.ExecutionLogAPI.create]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT; '' org.springframework.orm.jpa.JpaTransactionManager:323 - Opened new EntityManager [ org.hibernate.ejb.EntityManagerImpl@221f81 ] for JPA transaction org.springframework.orm.jpa.JpaTransactionManager:355 - Exposing JPA transaction as JDBC transaction [org.springframewo rk.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@ 9f5742] org.springframework.orm.jpa.JpaTransactionManager:752 - Initiating transaction commit org.springframework.orm.jpa.JpaTransactionManager:462 - Committing JPA transaction on EntityManager [ org.hibernate.ejb.EntityManagerImpl@221f81 ] org.springframework.orm.jpa.JpaTransactionManager:548 - Closing JPA EntityManager [ org.hibernate.ejb.EntityManagerImpl@221f81 ] after transaction org.springframework.orm.jpa.EntityManagerFactoryUtils:329 - Closing JPA EntityManager
The following is the log that I get while making multiple HTTP requests:
org.hibernate.util.JDBCExceptionReporter:357 - SQL Error: 1213, SQLState: 40001 org.hibernate.util.JDBCExceptionReporter:454 - Deadlock found when trying to get lock; try restarting transaction org.hibernate.event.def.AbstractFlushingEventListener:532 - Could not synchronize database state with session org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:105) at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365) at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137) at org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:54) at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:467) at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754) at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723) at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:375) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:120) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) at $Proxy66.create(Unknown Source) at biz.cytrus.overlord.v2.web.action.task.LogAction.createLogEntry(LogAction.java:84) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:592) at net.sourceforge.stripes.controller.DispatcherHelper$6.intercept(DispatcherHelper.java:442) at net.sourceforge.stripes.controller.ExecutionContext.proceed(ExecutionContext.java:158) at net.sourceforge.stripes.controller.BeforeAfterMethodInterceptor.intercept(BeforeAfterMethodInterceptor.java:113) at net.sourceforge.stripes.controller.ExecutionContext.proceed(ExecutionContext.java:155) at net.sourceforge.stripes.controller.ExecutionContext.wrap(ExecutionContext.java:74) at net.sourceforge.stripes.controller.DispatcherHelper.invokeEventHandler(DispatcherHelper.java:440) at net.sourceforge.stripes.controller.DispatcherServlet.invokeEventHandler(DispatcherServlet.java:278) at net.sourceforge.stripes.controller.DispatcherServlet.service(DispatcherServlet.java:160) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at net.sourceforge.stripes.controller.StripesFilter.doFilter(StripesFilter.java:247) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.netbeans.modules.web.monitor.server.MonitorFilter.doFilter(MonitorFilter.java:390) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583) at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454) at java.lang.Thread.run(Thread.java:595) Caused by: java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:657) at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723) at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) ... 48 more org.springframework.orm.jpa.JpaTransactionManager:893 - Initiating transaction rollback after commit exception org.springframework.dao.CannotAcquireLockException: Could not execute JDBC batch update; SQL [update application_instances set application_id=?, create_date=?, for_ongoing_task=?, last_log_id=?, last_notified_date=?, name=?, param_string=?, application_status_id=?, status_date=? where id=?]; nested exception is org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update at org.springframework.orm.hibernate3.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:633) at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:97) at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:471) at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754) at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723) at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:375) at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:120) at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202) at $Proxy66.create(Unknown Source) at biz.cytrus.overlord.v2.web.action.task.LogAction.createLogEntry(LogAction.java:84) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:592) at net.sourceforge.stripes.controller.DispatcherHelper$6.intercept(DispatcherHelper.java:442) at net.sourceforge.stripes.controller.ExecutionContext.proceed(ExecutionContext.java:158) at net.sourceforge.stripes.controller.BeforeAfterMethodInterceptor.intercept(BeforeAfterMethodInterceptor.java:113) at net.sourceforge.stripes.controller.ExecutionContext.proceed(ExecutionContext.java:155) at net.sourceforge.stripes.controller.ExecutionContext.wrap(ExecutionContext.java:74) at net.sourceforge.stripes.controller.DispatcherHelper.invokeEventHandler(DispatcherHelper.java:440) at net.sourceforge.stripes.controller.DispatcherServlet.invokeEventHandler(DispatcherServlet.java:278) at net.sourceforge.stripes.controller.DispatcherServlet.service(DispatcherServlet.java:160) at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at net.sourceforge.stripes.controller.StripesFilter.doFilter(StripesFilter.java:247) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.netbeans.modules.web.monitor.server.MonitorFilter.doFilter(MonitorFilter.java:390) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293) at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:849) at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583) at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:454) at java.lang.Thread.run(Thread.java:595) Caused by: org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:105) at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66) at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:275) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:266) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:168) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:321) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:50) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1027) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:365) at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:137) at org.hibernate.ejb.TransactionImpl.commit(TransactionImpl.java:54) at org.springframework.orm.jpa.JpaTransactionManager.doCommit(JpaTransactionManager.java:467) ... 39 more Caused by: java.sql.BatchUpdateException: Deadlock found when trying to get lock; try restarting transaction at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:657) at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723) at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70) at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268) ... 48 more org.springframework.orm.jpa.JpaTransactionManager:488 - Rolling back JPA transaction on EntityManager [ org.hibernate.ejb.EntityManagerImpl@7ca9bd ] org.springframework.orm.jpa.JpaTransactionManager:548 - Closing JPA EntityManager [ org.hibernate.ejb.EntityManagerImpl@7ca9bd ] after transaction org.springframework.orm.jpa.EntityManagerFactoryUtils:329 - Closing JPA EntityManager
While trying to solve this problem, I tried to set the isolation level in the transaction annotation, but this does not lead to activity in the database:
org.springframework.orm.jpa.JpaTransactionManager:365 - Creating new transaction with name [biz.cytrus.overlord.v2.core.ExecutionLogAPI.create]: PROPAGATION_REQUIRED,ISOLATION_REPEATABLE_READ; '' org.springframework.orm.jpa.JpaTransactionManager:323 - Opened new EntityManager [ org.hibernate.ejb.EntityManagerImpl@adddd6 ] for JPA transaction org.springframework.orm.jpa.EntityManagerFactoryUtils:329 - Closing JPA EntityManager
I would really appreciate any help in solving this problem.
Here's the code snippet in the method marked with @Transactional annotation:
Task task = ongoingTaskAPI.findById(taskId); ExecutionLog executionLog = new ExecutionLog(); executionLog.setStatusDate(new Date()); executionLog.setStatus(status); executionLog.setApplicationInstance(task.getApplicationInstance()); executionLog.getApplicationInstance().setLastLog(executionLog); em.persist(executionLog);
The relevant parts of the beans object are as follows:
public class ExecutionLog implements Serializable { private static final long serialVersionUID = 1L; @Id @GeneratedValue(strategy=GenerationType.IDENTITY) private Integer id; @ManyToOne @JoinColumn(name="application_instance_id") private ApplicationInstance applicationInstance;
public class ApplicationInstance implements Serializable { private static final long serialVersionUID = 1L; @Id @GeneratedValue(strategy=GenerationType.IDENTITY) private Integer id; @OneToOne @JoinColumn(name="last_log_id", nullable = true) private ExecutionLog lastLog;
One-to-one relationships exist at any point; a specific log entry can only be associated with a specific application instance record.
So basically, I am doing the creation of log entries and then updating the instance of the application, so that it is associated with the last relevant log entry. This is done in a single transactional method, but a failure occurs when the application instance record is updated. However, this works great on a single call, but not on simultaneous calls.
Hope this adds more clarity to my question.