10 Replies Latest reply on Mar 29, 2007 11:21 AM by Manik Surtani

    Exception thrown when calling remove during after-completion

    Rob Worsnop Newbie

      JBoss Cache version: 1.4.1.SP2

      I have been having some problems using Hibernate with JBoss Cache in optimistic locking mode. During the after-completion phase of the transaction, Hibernate will, in certain circumstances, call TreeCache.remove.

      This causes problems because JBoss Cache sees that the transaction is committing. A CacheException is thrown, with a "Must be in a valid transaction" message.

      The code below replicates what Hibernate does:

      public static void main(String[] args) throws Exception {
       TreeCache tree = new TreeCache();
       tree.setTransactionManagerLookup(new DummyTransactionManagerLookup());
       tree.setCacheMode(TreeCache.LOCAL);
       tree.setNodeLockingScheme("optimistic");
       tree.startService(); // kick start tree cache
       TransactionManager txManager = DummyTransactionManager.getInstance();
      
       try {
       txManager.begin();
       txManager.getTransaction().registerSynchronization(remover(tree));
       tree.put(fqn("custard"), "item", 45);
       txManager.commit();
       }
       catch(Throwable ex) {
       ex.printStackTrace();
       try { txManager.rollback(); } catch(Throwable t) {}
       } finally{
       tree.stopService();
       }
       }
      
       private static Synchronization remover(final TreeCache tree) {
       return new Synchronization(){
      
       public void afterCompletion(int status) {
       try {
       tree.remove(fqn("custard"), option(false));
       } catch (CacheException e) {
       System.err.println("Bad things happened when I tried to remove custard");
       e.printStackTrace();
       }
       }
       public void beforeCompletion() {
       }
      
       };
       }
      
       private static Fqn fqn(String s){
       return Fqn.fromString(s);
       }
      
       private static Option option(boolean failSilently){
       Option option = new Option();
       option.setFailSilently( failSilently );
       option.setDataVersion(new DataVersion(){
      
       public boolean newerThan(DataVersion arg0) {
       return false;
       }} );
       return option;
       }


      It causes this exception:
      Bad things happened when I tried to remove custard
      org.jboss.cache.CacheException: Must be in a valid transaction _remove; id:5(null, /custard, true)
       at org.jboss.cache.interceptors.OptimisticNodeInterceptor.invoke(OptimisticNodeInterceptor.java:66)
       at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
       at org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor.invoke(OptimisticCreateIfNotExistsInterceptor.java:69)
       at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
       at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:84)
       at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
       at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:126)
       at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
       at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:365)
       at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
       at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
       at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:183)
       at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5776)
       at org.jboss.cache.TreeCache.remove(TreeCache.java:3855)
       at org.jboss.cache.TreeCache.remove(TreeCache.java:3438)
       at com.medq.test.TestTreeCacheNotInTransaction$1.afterCompletion(TestTreeCacheNotInTransaction.java:47)
       at org.jboss.cache.transaction.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:270)
       at org.jboss.cache.transaction.DummyTransaction.commit(DummyTransaction.java:64)
       at org.jboss.cache.transaction.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:61)
       at com.medq.test.TestTreeCacheNotInTransaction.main(TestTreeCacheNotInTransaction.java:32)
      


      Is this expected behaviour for JBoss Cache? If so I will raise the issue on the Hibernate forum.

        • 1. Re: Exception thrown when calling remove during after-comple
          Rob Worsnop Newbie

          By the way, in case it helps, here is the Hibernate code that does the same thing:

          SessionFactory factory = new AnnotationConfiguration().configure().buildSessionFactory();
           TransactionManager txManager = DummyTransactionManager.getInstance();
           txManager.begin();
           Session session = factory.getCurrentSession();
           session.createQuery("update C c set c.id = 1").executeUpdate();
           txManager.commit(); // kaboom!!


          • 2. Re: Exception thrown when calling remove during after-comple
            Manik Surtani Master

            This may be related to http://jira.jboss.com/jira/browse/JBCACHE-1007 - by the time you are in afterCompletion(), any code called should not happen inside of that transaction since the transaction has, by definition, completed.

            I need to check what the expected behaviour should be in this case according to the JTA specs though.

            • 3. Re: Exception thrown when calling remove during after-comple
              Manik Surtani Master

              I would say this is a Hibernate issue. The bit in afterCompletion() is concerning, since the tx is no longer valid by then.

              Bringing this up on the Hibernate devs mail list.

              • 4. Re: Exception thrown when calling remove during after-comple
                Brian Stansberry Master

                Hibernate makes legitimate calls into the cache during afterCompletion(). See http://www.jboss.com/index.html?module=bb&op=viewtopic&t=102202
                and related JIRA http://jira.jboss.com/jira/browse/JBCACHE-982.

                There's this bit in TxInterceptor.setTransactionInContext() that may be relevant:

                ctx.setTransaction( tx );//tx == null || !isValid(tx) ? null : tx); // make sure the tx is valid, otherwise set as null - see JBCACHE-785
                 if (ctx.getTransaction() == null) ctx.setGlobalTransaction(null); // nullify gtx as well


                Not sure how the commented out bit was meant to work or why it's commented, but if it were executed before the ctx.setTransaction( tx ); call, it would have the effect of treating Hibernate's afterCompletion() call as occuring outside the tx scope, which AFAICT is Hibernate's intent.

                Hmm... that might screw up the if test in invoke() that immediately follows this call. Not sure; out of my depth here. :-)

                • 5. Re: Exception thrown when calling remove during after-comple
                  Manik Surtani Master

                   


                  ... it would have the effect of treating Hibernate's afterCompletion() call as occuring outside the tx scope, which AFAICT is Hibernate's intent.


                  Yes, this is why I sent a mail to the hibernate dev mail list to clarify the intention here. If it is to run outside the current tx, this should be done explicitly. Just nullifying the tx (as per the code snippet commented out) leads to other errors (when using optimistic locking, for example - guarded by the test in invoke()).

                  I was speaking with Kevin Conner about this earlier as well, and doing a cleanup like this in aftercompletion may lead to deadlocks too, if for example, the synchronizations haven't had a chance to release locks yet and a call to remove() blocks.

                  I think the Hibernate usage here is incorrect as it assumes that the cache is not transactional. Perfectly acceptable for their other cache impls, but not very good for JBoss Cache. This remove() should not happen in the afterCompletion() block but in a finally{} block after the tx commits/rolls back.





                  • 6. Re: Exception thrown when calling remove during after-comple
                    Steve Ebersole Apprentice


                    I sometimes get this issue when I use JBC. Of course the original stack trace would be completely useless, so instead here is some random stack trace based on some pseudo-code I wrote based on my assumptions about the code...

                    ;)

                    More than likely you are not using the transactional access/concurrency strategy (the stack trace would show this). If you are using transactional as your strategy and still get this issue, then that would be an issue.

                    Either way, we need the stack trace; really they are useful.

                    Hint: we like stack traces ;)

                    • 7. Re: Exception thrown when calling remove during after-comple
                      Steve Ebersole Apprentice

                      aww, it ate my sarcasm tags :( stupid forum software :)

                      • 8. Re: Exception thrown when calling remove during after-comple
                        Rob Worsnop Newbie

                         

                        "steve.ebersole@jboss.com" wrote:
                        I sometimes get this issue when I use JBC. Of course the original stack trace would be completely useless, so instead here is some random stack trace based on some pseudo-code I wrote based on my assumptions about the code...
                        </sarcasm>


                        Steve,
                        I didn't include the Hibernate stack trace because I was asking a question in the JBoss Cache forum, not the Hibernate forum.

                        Anyway, hope this helps:

                        org.hibernate.cache.CacheException: org.jboss.cache.CacheException: Must be in a valid transaction _remove; id:5(null, /com/medq/test/C, true)
                         at org.hibernate.cache.OptimisticTreeCache.clear(OptimisticTreeCache.java:169)
                         at org.hibernate.cache.TransactionalCache.clear(TransactionalCache.java:124)
                         at org.hibernate.impl.SessionFactoryImpl.evictEntity(SessionFactoryImpl.java:832)
                         at org.hibernate.action.BulkOperationCleanupAction.evictEntityRegions(BulkOperationCleanupAction.java:132)
                         at org.hibernate.action.BulkOperationCleanupAction.afterTransactionCompletion(BulkOperationCleanupAction.java:111)
                         at org.hibernate.engine.ActionQueue.afterTransactionCompletion(ActionQueue.java:170)
                         at org.hibernate.impl.SessionImpl.afterTransactionCompletion(SessionImpl.java:424)
                         at org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:225)
                         at org.hibernate.transaction.CacheSynchronization.afterCompletion(CacheSynchronization.java:85)
                         at org.jboss.cache.transaction.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:270)
                         at org.jboss.cache.transaction.DummyTransaction.commit(DummyTransaction.java:64)
                         at org.jboss.cache.transaction.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:61)
                         at com.medq.test.TestHibernate.main(TestHibernate.java:24)
                        Caused by: org.jboss.cache.CacheException: Must be in a valid transaction _remove; id:5(null, /com/medq/test/C, true)
                         at org.jboss.cache.interceptors.OptimisticNodeInterceptor.invoke(OptimisticNodeInterceptor.java:66)
                         at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
                         at org.jboss.cache.interceptors.EvictionInterceptor.invoke(EvictionInterceptor.java:88)
                         at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
                         at org.jboss.cache.interceptors.OptimisticCreateIfNotExistsInterceptor.invoke(OptimisticCreateIfNotExistsInterceptor.java:69)
                         at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
                         at org.jboss.cache.interceptors.OptimisticValidatorInterceptor.invoke(OptimisticValidatorInterceptor.java:84)
                         at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
                         at org.jboss.cache.interceptors.OptimisticLockingInterceptor.invoke(OptimisticLockingInterceptor.java:126)
                         at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
                         at org.jboss.cache.interceptors.OptimisticReplicationInterceptor.invoke(OptimisticReplicationInterceptor.java:147)
                         at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
                         at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:365)
                         at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
                         at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
                         at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:183)
                         at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5776)
                         at org.jboss.cache.TreeCache.remove(TreeCache.java:3855)
                         at org.jboss.cache.TreeCache.remove(TreeCache.java:3438)
                         at org.hibernate.cache.OptimisticTreeCache.clear(OptimisticTreeCache.java:166)
                         ... 12 more