glassfish
  1. glassfish
  2. GLASSFISH-18942

ejb-timer pool kills scheduled tasks when its thread is associated with transaction marked for rollback

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 3.1.2_b23, 3.1.2, 3.1.2.2
    • Fix Version/s: 4.1
    • Component/s: ejb_container
    • Labels:
      None
    • Environment:

      Windows Server 2008R2, JDK 1.7u5, Oracle 11g, standalone instance, Transaction and EJB monitoring set to HIGH

      Description

      When a call to com.sun.ejb.containers.TimerBean fails likely due to EclipseLink error (unfortunately I fail to find any primary cause for this), the executing thread will remain associated with transaction in state Status.MARKED_FOR_ROLLBACK. After that every task that gets executed in this thread will fail with following stacktrace:

      [#|2012-07-23T13:51:30.016+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|javax.ejb.TransactionRolledbackLocalException: Client's transaction aborted
      	at com.sun.ejb.containers.BaseContainer.useClientTx(BaseContainer.java:4722)
      	at com.sun.ejb.containers.BaseContainer.preInvokeTx(BaseContainer.java:4601)
      	at com.sun.ejb.containers.BaseContainer.preInvoke(BaseContainer.java:1914)
      	at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:212)
      	at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:88)
      	at $Proxy525.findTimer(Unknown Source)
      	at com.sun.ejb.containers.EJBTimerService.getValidTimerFromDB(EJBTimerService.java:2044)
      	at com.sun.ejb.containers.EJBTimerService.checkForTimerValidity(EJBTimerService.java:2033)
      	at com.sun.ejb.containers.EJBTimerService.deliverTimeout(EJBTimerService.java:1792)
      	at com.sun.ejb.containers.EJBTimerService.access$100(EJBTimerService.java:108)
      	at com.sun.ejb.containers.EJBTimerService$TaskExpiredWork.run(EJBTimerService.java:2646)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
      	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
      	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
      	at java.lang.Thread.run(Thread.java:722)
      

      As a result, the scheduled task is expunged and is no longer executed. After restarting the instance things work again (as expunging from the database failed due to same exception). The situation was verified in debugger: At BaseContainer.java:4722, the clientTx were always the same, as well as Thread ID. The container should likely roll back the transaction in this scenario.

      Excerpt from server log of the offending thread:

      [#|2012-07-23T13:51:30.016+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|EJB5184: A system exception occurred during an invocation on EJB TimerBean, method: public 
      com.sun.ejb.containers.TimerState com.sun.ejb.containers.TimerBean.findTimer(com.sun.ejb.containers.TimerPrimaryKey)|#]
      
      [#|2012-07-23T13:51:30.016+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|javax.ejb.TransactionRolledbackLocalException: Client's transaction aborted
      
      [#|2012-07-23T13:51:30.016+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|EJB5184: A system exception occurred during an invocation on EJB TimerBean, method: public void 
      com.sun.ejb.containers.TimerBean.remove(com.sun.ejb.containers.TimerPrimaryKey)|#]
      [#|2012-07-23T13:51:30.016+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|javax.ejb.TransactionRolledbackLocalException: Client's transaction aborted
      [#|2012-07-23T13:51:30.016+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|EJB5118: Failure removing timer bean [3@@1342689087527@@main@@main]|#]
      [#|2012-07-23T13:51:30.016+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|javax.ejb.EJBTransactionRolledbackException
      [#|2012-07-23T13:55:00.000+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|EJB5184:A system exception occurred during an invocation on EJB TimerBean, method: public
      com.sun.ejb.containers.TimerState com.sun.ejb.containers.TimerBean.findTimer(com.sun.ejb.containers.TimerPrimaryKey)|#]
      [#|2012-07-23T13:55:00.000+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|javax.ejb.TransactionRolledbackLocalException: Client's transaction aborted
      [#|2012-07-23T13:55:00.000+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|EJB5184:A system exception occurred during an invocation on EJB TimerBean, method: public void 
      com.sun.ejb.containers.TimerBean.remove(com.sun.ejb.containers.TimerPrimaryKey)|#]
      [#|2012-07-23T13:55:00.000+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|javax.ejb.TransactionRolledbackLocalException: Client's transaction aborted
      [#|2012-07-23T13:55:00.000+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|EJB5118:Failure removing timer bean [1@@1342689087527@@main@@main]|#]
      [#|2012-07-23T13:55:00.000+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|javax.ejb.EJBTransactionRolledbackException
      [#|2012-07-23T14:03:13.014+0200|WARNING|glassfish3.1.2|javax.enterprise.system.container.ejb.com.sun.ejb.containers|_ThreadID=618;
      _ThreadName=Thread-2;|EJB5184:A system exception occurred during an invocation on EJB TimerBean, method: public 
      com.sun.ejb.containers.TimerState com.sun.ejb.containers.TimerBean.findTimer(com.sun.ejb.containers.TimerPrimaryKey)|#]
      

        Activity

        Hide
        marina vatkina added a comment -

        rollback will do the cleanup. the problem was with an incomplete transaction.

        Show
        marina vatkina added a comment - rollback will do the cleanup. the problem was with an incomplete transaction.
        Hide
        Ed Bratt added a comment -

        Please consider as candidate for 4.0.1

        Show
        Ed Bratt added a comment - Please consider as candidate for 4.0.1
        Hide
        alebor added a comment -

        We need this patch also for GF 3.1.2.2. When is this available?

        Show
        alebor added a comment - We need this patch also for GF 3.1.2.2. When is this available?
        Hide
        gteichrow added a comment -

        Alebor: we are having this issue currently (GF 3.1.2.2 Build5/Centos/Postgres). Is there a subsequent build that you aware of that has this fixed? Or a patched jar?

        thx for any comments.!

        Show
        gteichrow added a comment - Alebor: we are having this issue currently (GF 3.1.2.2 Build5/Centos/Postgres). Is there a subsequent build that you aware of that has this fixed? Or a patched jar? thx for any comments.!
        Hide
        alebor added a comment - - edited

        gteichrow: As fas as I know there is no patch for this on GF 3.1.2.2. In my case the problem was related to JMS message redelivery (poison messages) and wrong transactions. Poison messages are JMS delivery deadlocks caused by continuous redelivery of a Message to JMS Queue/Topiq. By not re-throwing runtime exceptions in MDBs, JMS will acknowledge the message and no redelivery will happen. We did not want re-deliveries because it can cause JMS deadlock when something really goes bad during high traffic. Maybe this helps?

        Show
        alebor added a comment - - edited gteichrow: As fas as I know there is no patch for this on GF 3.1.2.2. In my case the problem was related to JMS message redelivery (poison messages) and wrong transactions. Poison messages are JMS delivery deadlocks caused by continuous redelivery of a Message to JMS Queue/Topiq. By not re-throwing runtime exceptions in MDBs, JMS will acknowledge the message and no redelivery will happen. We did not want re-deliveries because it can cause JMS deadlock when something really goes bad during high traffic. Maybe this helps?

          People

          • Assignee:
            Srini
            Reporter:
            pdudits
          • Votes:
            2 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: