Java/EJB/Hibernate事务同步防止Oracle死锁

【问题标题】：Java/EJB/Hibernate Transaction Synchronization to Prevent Oracle DeadlocksJava/EJB/Hibernate事务同步防止Oracle死锁
【发布时间】：2016-04-01 20:33:34
【问题描述】：

我有一个每 5 分钟运行一次的 Quartz 作业，我在 application.log 和 Oracle 跟踪日志中看到死锁错误。我正在寻求解决这些死锁错误，但我不确定它们是否由于锁定策略、事务隔离或 Quartz 并发相关问题而发生。请让我知道我的锁定策略可能有什么问题，我可能遗漏了什么，或者我应该采取什么步骤来解决这个问题。

我正在创建 TypedQuery，它将像这样锁定行：

TypedQuery<Order> ordersQuery = em.createQuery("SELECT o from Order o where o.orderDate <= :today and o.statusId = :statusId", Order.class);

并将 LockModeType 设置为：

ordersQuery.setLockMode(LockModeType.PESSIMISTIC_WRITE);

Quartz 作业在无状态会话 bean 中调用以下方法。它首先获取要处理的 orderIds（这是“更新”锁定发生的地方），然后使用这些 orderIds 调用initialOrders(List)。 在类或这些方法上都没有指定 TransactionAttributeTypes，所以它应该默认为 TransactionAttributeType.REQUIRED。

public int initiateOrders(List<Integer> orderIds) throws Exception {
    if (orderIds.size() == 0) {
      return 0;
    }

    List<Order> orders = orderDao.findByIds(orderIds);

    for (Order o : orders) {
      o.setProcessId(-1);
      boolean isSuccess;

      if (o.getOrderSummaryRequiredBy() != null && o.getOrderSummaryRequiredBy().equals("ACC")) {
        o.setRouteToDept(o.getRouteToEntity());
      }

      isSuccess = orderManager.startOrderProcess(o);
      invokeUpdateOrderTemplateActiveYN(o.getOrderId());
      if (!isSuccess) {
        log.error("Exception in startOrderProcess( " + o.getOrderId() + " )");
      }
    }

    return orders.size();
}

public List<Integer> getOrderIdsToProcess(int packetSize) {
    TypedQuery<Order> ordersQuery = entityManager
        .createQuery(
            "SELECT o from Order o where o.orderDate <= :today and o.statusId = :statusId and o.processId = :processId",
            Order.class);

    java.sql.Date today = new java.sql.Date(new Date().getTime());

    ordersQuery.setParameter("today", today);
    ordersQuery.setParameter("statusId", 1);
    ordersQuery.setParameter("processId", 0);
    ordersQuery.setMaxResults(packetSize);

    ordersQuery.setLockMode(LockModeType.PESSIMISTIC_WRITE);

    List<Order> orders = ordersQuery.getResultList();
    List<Integer> orderIds = new ArrayList<>();

    for (Order o : orders) {
      o.setProcessId(-1);
      orderIds.add(o.getOrderId());
    }

    return orderIds;
}

startOrderProcess(Order) 也位于具有默认事务属性类型的无状态 bean 中。它在 order 对象上设置一些值并调用 entityManager.merge(order);

invokeUpdateOrderTemplateActiveYN(Integer) 调用从 Order 中选择并更新不同表的存储过程。

应用程序日志（精简了一点并删除了 PII）：

15:31:42,969 DEBUG [org.hibernate.SQL] (myScheduler_Worker-10) select MY_SEQ.nextval from dual
15:31:42,979 DEBUG [org.hibernate.SQL] (myScheduler_Worker-10) select assignedus0_.ORDER_ID as ORDER_2_90_1_, from ASSIGNED_USERS assignedus0_ where assignedus0_.ORDER_ID=?
15:31:42,979 DEBUG [org.hibernate.SQL] (myScheduler_Worker-10) insert into ORDER_EVENT_LOG (ACTION, ... EVENT_LOG_ID) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)
15:31:42,979 DEBUG [org.hibernate.SQL] (myScheduler_Worker-10) update ORDER set ... where ORDER_ID=?
15:31:47,513 DEBUG [org.hibernate.SQL] (myScheduler_Worker-5) select user0_.USER_ID as USER_ID1_116_0_, user0_.ACTIVE_YN as ACTIVE_Y2_116_0_, ... from USER user0_ where user0_.USER_ID=?
15:31:47,533 DEBUG [org.hibernate.SQL] (myScheduler_Worker-5) select orderinf0_.ORDER_INFORMATION_ID as ORDER_1_88_0_, ... from ORDER_INFORMATION orderinf0_ where orderinf0_.ORDER_INFORMATION_ID=?
15:31:47,673 DEBUG [org.hibernate.SQL] (myScheduler_Worker-5) select orderinf0_.ORDER_INFO_CATEGORY_ID as ORDER_1_89_0_, ... from ORDER_INFORMATION_CATEGORY orderinf0_ where orderinf0_.ORDER_INFO_CATEGORY_ID=?
15:31:47,673 DEBUG [org.hibernate.SQL] (myScheduler_Worker-5) select user0_.USER_ID as USER_ID1_116_0_, user0_.ACTIVE_YN as ACTIVE_Y2_116_0_,... where user0_.USER_ID=?
15:31:48,151 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (myScheduler_Worker-2) SQL Error: 60, SQLState: 61000
15:31:48,151 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (myScheduler_Worker-2) ORA-00060: deadlock detected while waiting for resource

15:31:48,181 DEBUG [org.hibernate.SQL] (myScheduler_Worker-10) select orderdis0_.ORDER_ID as ORDER_4_90_1_, ... from ORDER_DISPATCH orderdis0_ where orderdis0_.ORDER_ID=?
15:31:48,181 ERROR [org.jboss.as.ejb3.invocation] (myScheduler_Worker-2) JBAS014134: EJB Invocation failed on component OrderManager for method public java.util.List com.business.model.order.OrderManager.getOrdersToProcess(int): javax.ejb.EJBException: javax.persistence.PessimisticLockException: could not obtain pessimistic lock
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInOurTx(CMTTxInterceptor.java:191) [jboss-as-ejb3-7.5.0.Final-redhat-21.jar:7.5.0.Final-redhat-21]
    ...
    at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee-7.5.0.Final-redhat-21.jar:7.5.0.Final-redhat-21]
    at com.business.model.order.OrderManager$$$view26.getOrdersToProcess(Unknown Source) [model-1.0.jar:]
    at com.business.workflow.jobs.OrderProcessor.execute(OrderProcessor.java:59) [workflow-jobs-1.0.jar:]
    at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [quartz-1.6.0.jar:1.6.0]
    at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529) [quartz-1.6.0.jar:1.6.0]
Caused by: javax.persistence.PessimisticLockException: could not obtain pessimistic lock
    at org.hibernate.ejb.AbstractEntityManagerImpl.wrapLockException(AbstractEntityManagerImpl.java:1449) [hibernate-entitymanager-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ...
    at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:277) [hibernate-entitymanager-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    at com.business.model.order.OrderManager.getOrdersToProcess(OrderManager.java:2655) [model-1.0.jar:]
    ... 27 more
Caused by: org.hibernate.dialect.lock.PessimisticEntityLockException: could not obtain pessimistic lock
    at org.hibernate.dialect.lock.PessimisticWriteSelectLockingStrategy.lock(PessimisticWriteSelectLockingStrategy.java:114) [hibernate-core-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ... 59 more
Caused by: org.hibernate.exception.LockAcquisitionException: could not extract ResultSet
    ...
    at org.hibernate.dialect.lock.PessimisticWriteSelectLockingStrategy.lock(PessimisticWriteSelectLockingStrategy.java:87) [hibernate-core-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ... 81 more
Caused by: java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:450) [ojdbc-7.jar:12.1.0.1.0]
    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:399) [ojdbc-7.jar:12.1.0.1.0]
    ...
    at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:462)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:79) [hibernate-core-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ... 82 more

15:31:48,191 INFO  [org.quartz.core.JobRunShell] (myScheduler_Worker-2) Job workflow.OrderProcessor threw a JobExecutionException: : org.quartz.JobExecutionException: javax.ejb.EJBException: javax.persistence.PessimisticLockException: could not obtain pessimistic lock [See nested exception: javax.ejb.EJBException: javax.persistence.PessimisticLockException: could not obtain pessimistic lock]
    at com.business.workflow.jobs.OrderProcessor.execute(OrderProcessor.java:66) [workflow-jobs-1.0.jar:]
    at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [quartz-1.6.0.jar:1.6.0]
    at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:529) [quartz-1.6.0.jar:1.6.0]
Caused by: javax.ejb.EJBException: javax.persistence.PessimisticLockException: could not obtain pessimistic lock
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInOurTx(CMTTxInterceptor.java:191) [jboss-as-ejb3-7.5.0.Final-redhat-21.jar:7.5.0.Final-redhat-21]
    ...
    at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee-7.5.0.Final-redhat-21.jar:7.5.0.Final-redhat-21]
    at com.business.model.order.OrderManager$$$view26.getOrdersToProcess(Unknown Source) [model-1.0.jar:]
    at com.business.workflow.jobs.OrderProcessor.execute(OrderProcessor.java:59) [workflow-jobs-1.0.jar:]
    ... 2 more
Caused by: javax.persistence.PessimisticLockException: could not obtain pessimistic lock
    at org.hibernate.ejb.AbstractEntityManagerImpl.wrapLockException(AbstractEntityManagerImpl.java:1449) [hibernate-entitymanager-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ...
    at com.business.model.order.OrderManager.getOrdersToProcess(OrderManager.java:2655) [model-1.0.jar:]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_79]
    ...
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:280) [jboss-as-ejb3-7.5.0.Final-redhat-21.jar:7.5.0.Final-redhat-21]
    ... 27 more
Caused by: org.hibernate.dialect.lock.PessimisticEntityLockException: could not obtain pessimistic lock
    at org.hibernate.dialect.lock.PessimisticWriteSelectLockingStrategy.lock(PessimisticWriteSelectLockingStrategy.java:114) [hibernate-core-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ...
    at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:268) [hibernate-entitymanager-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ... 59 more
Caused by: org.hibernate.exception.LockAcquisitionException: could not extract ResultSet
    at org.hibernate.dialect.Oracle8iDialect$2.convert(Oracle8iDialect.java:450) [hibernate-core-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ...
    at org.hibernate.dialect.lock.PessimisticWriteSelectLockingStrategy.lock(PessimisticWriteSelectLockingStrategy.java:87) [hibernate-core-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ... 81 more
Caused by: java.sql.SQLException: ORA-00060: deadlock detected while waiting for resource

    at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:450) [ojdbc-7.jar:12.1.0.1.0]
    ...
    at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:462)
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:79) [hibernate-core-4.2.18.Final-redhat-2.jar:4.2.18.Final-redhat-2]
    ... 82 more

Oracle 跟踪日志：

    =====================
PARSING IN CURSOR #4 len=87 dep=0 uid=29 oct=3 lid=29 tim=1416963939942628 hv=3017806794 ad='48e71488'
select ORDER_ID from ORDER where ORDER_ID =:1  for update
END OF STMT
PARSE #4:c=0,e=7,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1416963939942625
EXEC #4:c=0,e=43,p=0,cr=3,cu=1,mis=0,r=0,dep=0,og=4,tim=1416963939942708
FETCH #4:c=0,e=9,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=4,tim=1416963939942747
STAT #4 id=1 cnt=1 pid=0 pos=1 obj=0 op='FOR UPDATE  (cr=3 pr=0 pw=0 time=35 us)'
STAT #4 id=2 cnt=1 pid=1 pos=1 obj=82422 op='INDEX UNIQUE SCAN PK_ORDER (cr=3 pr=0 pw=0 time=12 us)'
=====================
PARSING IN CURSOR #3 len=87 dep=0 uid=29 oct=3 lid=29 tim=1416963939943362 hv=3017806794 ad='48e71488'
select ORDER_ID from ORDER where ORDER_ID =:1  for update
END OF STMT
PARSE #3:c=0,e=8,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=1416963939943359
*** 2015-12-24 15:31:45.629
DEADLOCK DETECTED ( ORA-00060 )
[Transaction Deadlock]
The following deadlock is not an ORACLE error. It is a
deadlock due to user error in the design of an application
or from issuing incorrect ad-hoc SQL. The following
information may aid in determining the deadlock:
Deadlock graph:
                       ---------Blocker(s)--------  ---------Waiter(s)---------
Resource Name          process session holds waits  process session holds waits
TX-00160021-002790fd        47    1799     X             51    1856           X
TX-00190009-0018cd94        51    1856     X             47    1799           X
session 1799: DID 0001-002F-0000004F    session 1856: DID 0001-0033-00000FCE
session 1856: DID 0001-0033-00000FCE    session 1799: DID 0001-002F-0000004F
Rows waited on:
Session 1856: obj - rowid = 000141F4 - AAAUH0ABVAAAdiXAAT
  (dictionary objn - 82420, file - 85, block - 120983, slot - 19)
Session 1799: obj - rowid = 000141F4 - AAAUH0ABVAAAdjJAAT
  (dictionary objn - 82420, file - 85, block - 121033, slot - 19)
Information on the OTHER waiting sessions:
Session 1856:
  pid=51 serial=19150 audsid=69033382 user: 29/ORAUSER
  O/S info: user: xxxx, term: unknown, ospid: 1234, machine: XXXX
            program: JDBC Thin Client
  application name: JDBC Thin Client, hash value=0
  Current SQL Statement:

update ORDER set ... where ORDER_ID=:75 
End of information on OTHER waiting sessions.
Current SQL statement for this session:
select ORDER_ID from ORDER where ORDER_ID =:1  for update
===================================================
PROCESS STATE
-------------
Process global information:
     process: 0x15e4ac4d0, call: 0x141bfe118, xact: 0x15b8275d0, curses: 0x15d202070, usrses: 0x15d202070
  ----------------------------------------
  SO: 0x15e4ac4d0, type: 2, owner: (nil), flag: INIT/-/-/0x00
  (process) Oracle pid=47, calls cur/top: 0x141bfe118/0x141bfe118, flag: (0) -
            int error: 0, call error: 0, sess error: 0, txn error 0
  (post info) last post received: 0 0 193
              last post received-location: kgskbwt: posting new actses to run
              last process to post me: 15e4a9d48 167 0
              last post sent: 0 0 193
              last post sent-location: kgskbwt: posting new actses to run
              last process posted by me: 15e4a8d78 202 0
    (latch info) wait_event=0 bits=0
    Process Group: DEFAULT, pseudo proc: 0x15e812e98
    O/S info: user: oracle, term: UNKNOWN, ospid: 12914
    OSD pid info: Unix process pid: 12914, image: oracleprod@pddevdb01
Dump of memory from 0x000000015E3B6870 to 0x000000015E3B6A78

环境： JBoss EAP 6、Oracle 10g、Hibernate 4.2、Quartz 1.6 和 EJB 3。

注意：目前不能选择升级 Oracle。数据库和应用程序事务隔离级别均未更改。

更新：在使用两台机器进行调试后，我们能够从“select...for update”查询中检索到相同的结果。给定事务 A 运行更新查询，事务 B 运行它的更新查询 before 事务 A 提交，它将等待 A 提交后返回结果，但一旦 A 提交，B 返回相同的结果A -- 即使 (processId) 上选择的值已被 A 更改（变为 -1）。如果 A 在 B 运行它的“更新”查询之前提交，这两个查询会得到不同的结果。

【问题讨论】：

  • 对我来说，发布的代码很好。唯一的疑问是 o.setProcessId(-1);调用 IDs getter。为什么？另外，如果第一个未完成，我将使主要的 Quartz 作业方法同步以排除运行第二个的情况。提供更多代码来显示交易的开始位置和方式。

标签： java oracle hibernate transactions deadlock


【解决方案1】：

这个问题可以在这个日志中可视化：

update ORDER set ... where ORDER_ID=:75 
End of information on OTHER waiting sessions.
Current SQL statement for this session:
select ORDER_ID from ORDER where ORDER_ID =:1  for update

您正在获取锁，但只是在 Quartz 事务结束时刷新和提交状态，这可能需要一些时间。

同时，所有这些记录都被锁定，没有其他事务可以选择或更新这些记录。

我认为你应该改变执行顺序如下：

  • 您保留select for update 逻辑来锁定您要处理的条目并将状态更新为IN_PROGRESS
  • 您尽快提交该事务以释放锁
  • 您在新事务中继续处理现在处于 IN_PROGRESS 的选定记录
  • 其他事务不会选择 IN_PROGRESS 记录，因此不会有两个并发事务处理相同的记录

【讨论】：

  • 代码已更改为使用用户事务（指定 @TransactionAttribute(TransactionAttributeType.NOT_SUPPORTED)。这应该暂停任何 Quartz 事务（如果它们存在于 Quartz 1.6.0 中）。目前，事务正在在将 processId 设置为 -1 后明确提交。请参阅问题中添加的“更新”部分。
猜你喜欢
  • 2015-06-13
  • 1970-01-01
  • 2019-08-14
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2013-05-22
  • 1970-01-01
  • 1970-01-01
相关资源
最近更新 更多
热门标签
Java Python linux javascript Mysql C# Docker 算法 前端 SpringBoot Redis Vue spring 设计模式 .net core .net kubernetes c++ 数据库 数据结构 大数据 js 机器学习 微服务 Android Go 程序员 面试 JVM ASP.net core 云原生 人工智能 后端 PHP git CSS golang k8s Nginx Django mybatis 深度学习 多线程 React 架构 devops 爬虫 云计算 Spring Boot LeetCode