6 Replies Latest reply on Mar 17, 2009 11:38 AM by Brian Stansberry

    Unable To Acquire Lock

    Kevin Urciolo Newbie

      I am having trouble with JBossCache as a second level cache for Hibernate. Everything seems to work except for delete operations. When deletes occur I get an "Unable to acquire lock" error.

      Do you know what could cause this?

      I am using:

      jbosscache-core-3.0.2.GA
      hibernate-distribution-3.3.1.GA

      I have treecache.xml config:

      <?xml version="1.0" encoding="UTF-8"?>
      <jbosscache xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns="urn:jboss:jbosscache-core:config:3.0">
       <transaction transactionManagerLookupClass="org.jboss.cache.transaction.JBossTransactionManagerLookup"/>
      </jbosscache>
      


      Hibernate Configuration:
      <props>
       <prop key="hibernate.dialect">org.hibernate.dialect.Oracle10gDialect</prop>
       <prop key="hibernate.show_sql">false</prop>
       <prop key="hibernate.cache.use_second_level_cache">true</prop>
       <prop key="hibernate.cache.use_query_cache">true</prop>
       <prop key="hibernate.connection.isolation">3</prop>
       <prop key="hibernate.current_session_context_class">jta</prop>
       <prop key="hibernate.transaction.factory_class">
       org.hibernate.transaction.JTATransactionFactory
       </prop>
       <prop key="hibernate.transaction.manager_lookup_class">
       org.hibernate.transaction.JBossTransactionManagerLookup
       </prop>
       <prop key="hibernate.jdbc.use_get_generated_keys">true</prop>
       <prop key="hibernate.cache.region.factory_class">org.hibernate.cache.jbc2.SharedJBossCacheRegionFactory</prop>
       <prop key="hibernate.cache.region.jbc2.query.localonly">true</prop>
       <prop key="hibernate.cache.region.jbc2.cfg.shared">/opt/jboss/server/nafis/conf/treecache.xml</prop>
       </props>
      


      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) Caused by: org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/TS/org/hibe
      rnate/cache/UpdateTimestampsCache/INFO] after [10000] milliseconds for requestor [Thread[http-0.0.0.0-8080-16,5,jboss]]! Lock held by [GlobalTransaction:<null>:4]
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.mvcc.MVCCNodeHelper.acquireLock(MVCCNodeHelper.java:170) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.mvcc.MVCCNodeHelper.wrapNodeForWriting(MVCCNodeHelper.java:226)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.MVCCLockingInterceptor.handlePutKeyValueCommand(MVCCLockingInterceptor.java:101)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.base.PrePostProcessingCommandInterceptor.visitPutKeyValueCommand(PrePostProcessingCommandInterceptor.java:88)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:65)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.TxInterceptor.attachGtxAndPassUpChain(TxInterceptor.java:284)
      2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.TxInterceptor.handleDefault(TxInterceptor.java:271) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:65
      ) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:
      100) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterc
      eptor.java:116) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInter
      ceptor.java:119) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:
      100) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16) at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterc
      eptor.java:116) 2009-03-10 19:14:02,240 ERROR [STDERR] (http-0.0.0.0-8080-16)
      


        • 1. Re: Unable To Acquire Lock
          Nathan Messer Newbie

          Have you tried turning on the following log4j logging to see what's happening with the transactions?

          org.jboss.cache.interceptors.TxInterceptor=TRACE
          (in our properties file that turns into
          log4j.logger.org.jboss.cache.interceptors.TxInterceptor=TRACE, JBossAppender)

          3.0.2 did have a bug that under certain circumstances the transaction could be rolled back, but not all the locks removed, which would lead to this problem. This was fixed in 3.0.3.

          However it could be as simple as GlobalTransaction::4 has modified the node, and hasn't committed yet. Looking at the TxInterceptor logs should tell you when the transaction commits or rolls back.

          -Note: I'm not connected with JBossCache development, just a user, and I haven't used JBossCache with Hibernate.

          • 2. Re: Unable To Acquire Lock
            Kevin Urciolo Newbie

            Here is TRACE level logging of Hibernate and JBossCache. I do not see the problem...

            2009-03-11 15:43:06,054 DEBUG [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) opened session at timestamp: 5065876218077184
            2009-03-11 15:43:06,057 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:06,057 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:06,057 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) find: select count(centralTransaction) from CentralTransaction centralTransaction where status = ?
            2009-03-11 15:43:06,057 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) parameters: [7]
            2009-03-11 15:43:06,057 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) named parameters: {}
            2009-03-11 15:43:06,057 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:06,057 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) opening JDBC connection
            2009-03-11 15:43:06,057 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-19) select count(centraltra0_.ID) as col_0_0_ from CENTRAL_TRANSACTIONS centraltra0_ where centraltra0_.STATUS=?
            2009-03-11 15:43:06,057 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) preparing statement
            2009-03-11 15:43:06,057 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-19) binding '7' to parameter: 1
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-03-11 15:43:06,058 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) processing result set
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result set row: 0
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result row:
            2009-03-11 15:43:06,058 TRACE [org.hibernate.type.LongType] (http-0.0.0.0-8080-19) returning '0' as column: col_0_0_
            2009-03-11 15:43:06,058 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) done processing result set (1 rows)
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:06,058 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) closing statement
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.engine.StatefulPersistenceContext] (http-0.0.0.0-8080-19) initializing non-lazy collections
            2009-03-11 15:43:06,058 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-19) after autocommit
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:06,058 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) after transaction completion
            2009-03-11 15:43:06,058 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) closing session
            2009-03-11 15:43:06,058 TRACE [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) performing cleanup
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:06,058 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-19) after transaction completion
            2009-03-11 15:43:06,058 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:06,058 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) after transaction completion
            2009-03-11 15:43:11,054 DEBUG [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) opened session at timestamp: 5065876238557184
            2009-03-11 15:43:11,054 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-22) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:11,054 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-22) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:11,054 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-22) find: select count(centralTransaction) from CentralTransaction centralTransaction where status = ?
            2009-03-11 15:43:11,054 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-22) parameters: [7]
            2009-03-11 15:43:11,054 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-22) named parameters: {}
            2009-03-11 15:43:11,054 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:11,054 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) opening JDBC connection
            2009-03-11 15:43:11,054 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-22) select count(centraltra0_.ID) as col_0_0_ from CENTRAL_TRANSACTIONS centraltra0_ where centraltra0_.STATUS=?
            2009-03-11 15:43:11,054 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) preparing statement
            2009-03-11 15:43:11,054 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-22) binding '7' to parameter: 1
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-03-11 15:43:11,055 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) processing result set
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) result set row: 0
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) result row:
            2009-03-11 15:43:11,055 TRACE [org.hibernate.type.LongType] (http-0.0.0.0-8080-22) returning '0' as column: col_0_0_
            2009-03-11 15:43:11,055 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) done processing result set (1 rows)
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:11,055 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) closing statement
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.engine.StatefulPersistenceContext] (http-0.0.0.0-8080-22) initializing non-lazy collections
            2009-03-11 15:43:11,055 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-22) after autocommit
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:11,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) after transaction completion
            2009-03-11 15:43:11,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) closing session
            2009-03-11 15:43:11,055 TRACE [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) performing cleanup
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:11,055 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-22) after transaction completion
            2009-03-11 15:43:11,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:11,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) after transaction completion
            2009-03-11 15:43:16,054 DEBUG [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) opened session at timestamp: 5065876259037184
            2009-03-11 15:43:16,054 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:16,054 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:16,054 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) find: select count(centralTransaction) from CentralTransaction centralTransaction where status = ?
            2009-03-11 15:43:16,054 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) parameters: [7]
            2009-03-11 15:43:16,054 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) named parameters: {}
            2009-03-11 15:43:16,054 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:16,054 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) opening JDBC connection
            2009-03-11 15:43:16,054 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-19) select count(centraltra0_.ID) as col_0_0_ from CENTRAL_TRANSACTIONS centraltra0_ where centraltra0_.STATUS=?
            2009-03-11 15:43:16,054 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) preparing statement
            2009-03-11 15:43:16,054 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-19) binding '7' to parameter: 1
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-03-11 15:43:16,055 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) processing result set
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result set row: 0
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result row:
            2009-03-11 15:43:16,055 TRACE [org.hibernate.type.LongType] (http-0.0.0.0-8080-19) returning '0' as column: col_0_0_
            2009-03-11 15:43:16,055 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) done processing result set (1 rows)
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:16,055 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) closing statement
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.engine.StatefulPersistenceContext] (http-0.0.0.0-8080-19) initializing non-lazy collections
            2009-03-11 15:43:16,055 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-19) after autocommit
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:16,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) after transaction completion
            2009-03-11 15:43:16,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) closing session
            2009-03-11 15:43:16,055 TRACE [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) performing cleanup
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:16,055 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-19) after transaction completion
            2009-03-11 15:43:16,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:16,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) after transaction completion
            2009-03-11 15:43:21,054 DEBUG [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) opened session at timestamp: 5065876279517184
            2009-03-11 15:43:21,054 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-22) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:21,054 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-22) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:21,054 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-22) find: select count(centralTransaction) from CentralTransaction centralTransaction where status = ?
            2009-03-11 15:43:21,054 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-22) parameters: [7]
            2009-03-11 15:43:21,054 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-22) named parameters: {}
            2009-03-11 15:43:21,054 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:21,054 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) opening JDBC connection
            2009-03-11 15:43:21,054 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-22) select count(centraltra0_.ID) as col_0_0_ from CENTRAL_TRANSACTIONS centraltra0_ where centraltra0_.STATUS=?
            2009-03-11 15:43:21,054 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) preparing statement
            2009-03-11 15:43:21,054 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-22) binding '7' to parameter: 1
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-03-11 15:43:21,055 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) processing result set
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) result set row: 0
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) result row:
            2009-03-11 15:43:21,055 TRACE [org.hibernate.type.LongType] (http-0.0.0.0-8080-22) returning '0' as column: col_0_0_
            2009-03-11 15:43:21,055 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-22) done processing result set (1 rows)
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:21,055 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-22) closing statement
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.engine.StatefulPersistenceContext] (http-0.0.0.0-8080-22) initializing non-lazy collections
            2009-03-11 15:43:21,055 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-22) after autocommit
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:21,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) after transaction completion
            2009-03-11 15:43:21,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) closing session
            2009-03-11 15:43:21,055 TRACE [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) performing cleanup
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:21,055 TRACE [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-22) after transaction completion
            2009-03-11 15:43:21,055 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-22) transaction completed on session with on_close connection release mode; be sure to close the session to release JDBC resources!
            2009-03-11 15:43:21,055 TRACE [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-22) after transaction completion
            2009-03-11 15:43:22,454 INFO [org.apache.cxf.interceptor.LoggingInInterceptor] (http-0.0.0.0-8080-19) Inbound Message
            ----------------------------
            Encoding: UTF-8
            Headers: {cache-control=[no-cache], content-type=[text/xml; charset=UTF-8], connection=[Keep-Alive], host=[csnwas22:8080], transfer-encoding=[chunked], SOAPAction=["urn:permanentlyDeleteEntities"], user-agent=[Java/1.6.0_04], Accept=, pragma=[no-cache]}
            Messages:
            Message:
            
            Payload: <soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Body><permanentlyDeleteEntitiesRequest xmlns="http://collections.ident1.ngc.com"><requestHeader><uId>def</uId><bureauCode>abc</bureauCode><bureauNSN>123</bureauNSN></requestHeader><sispKeys>CO10080025865J</sispKeys></permanentlyDeleteEntitiesRequest></soap:Body></soap:Envelope>
            --------------------------------------
            2009-03-11 15:43:22,549 DEBUG [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) opened session at timestamp: 5065876285628416
            2009-03-11 15:43:22,561 TRACE [org.hibernate.transaction.JTATransactionFactory] (http-0.0.0.0-8080-19) Attempting to locate UserTransaction via JNDI [UserTransaction]
            2009-03-11 15:43:22,562 TRACE [org.hibernate.transaction.JTATransactionFactory] (http-0.0.0.0-8080-19) Obtained UserTransaction
            2009-03-11 15:43:22,574 DEBUG [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-19) successfully registered Synchronization
            2009-03-11 15:43:22,581 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) unable to locate HQL query plan in cache; generating (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:22,581 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] (http-0.0.0.0-8080-19) parse() - HQL: select count(centralTransaction) from com.ngc.ident1.common.CentralTransaction centralTransaction where status = ?
            2009-03-11 15:43:22,582 DEBUG [org.hibernate.hql.ast.AST] (http-0.0.0.0-8080-19) --- HQL AST ---
             \-[QUERY] 'query'
             +-[SELECT_FROM] 'SELECT_FROM'
             | +-[FROM] 'from'
             | | \-[RANGE] 'RANGE'
             | | +-[DOT] '.'
             | | | +-[DOT] '.'
             | | | | +-[DOT] '.'
             | | | | | +-[DOT] '.'
             | | | | | | +-[IDENT] 'com'
             | | | | | | \-[IDENT] 'ngc'
             | | | | | \-[IDENT] 'ident1'
             | | | | \-[IDENT] 'common'
             | | | \-[IDENT] 'CentralTransaction'
             | | \-[ALIAS] 'centralTransaction'
             | \-[SELECT] 'select'
             | \-[COUNT] 'count'
             | \-[IDENT] 'centralTransaction'
             \-[WHERE] 'where'
             \-[EQ] '='
             +-[IDENT] 'status'
             \-[PARAM] '?'
            
            2009-03-11 15:43:22,582 DEBUG [org.hibernate.hql.ast.ErrorCounter] (http-0.0.0.0-8080-19) throwQueryException() : no errors
            2009-03-11 15:43:22,582 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] (http-0.0.0.0-8080-19) select << begin [level=1, statement=select]
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.tree.FromElement] (http-0.0.0.0-8080-19) FromClause{level=1} : com.ngc.ident1.common.CentralTransaction (centralTransaction) -> centraltra0_
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] (http-0.0.0.0-8080-19) Resolved : centralTransaction -> centraltra0_.ID
            2009-03-11 15:43:22,583 TRACE [org.hibernate.hql.ast.HqlSqlWalker] (http-0.0.0.0-8080-19) attempting to resolve property [status] as a non-qualified ref
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] (http-0.0.0.0-8080-19) Resolved : {synthetic-alias} -> {synthetic-alias}
            2009-03-11 15:43:22,583 TRACE [org.hibernate.hql.ast.tree.FromElement] (http-0.0.0.0-8080-19) handling property dereference [com.ngc.ident1.common.CentralTransaction (centralTransaction) -> status (class)]
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.tree.DotNode] (http-0.0.0.0-8080-19) getDataType() : status -> org.hibernate.type.IntegerType@2dce4e
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] (http-0.0.0.0-8080-19) Resolved : {synthetic-alias}.status -> centraltra0_.STATUS
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] (http-0.0.0.0-8080-19) select : finishing up [level=1, statement=select]
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.HqlSqlWalker] (http-0.0.0.0-8080-19) processQuery() : ( SELECT ( {select clause} ( count centraltra0_.ID ) ) ( FromClause{level=1} CENTRAL_TRANSACTIONS centraltra0_ ) ( where ( = ( centraltra0_.STATUS {synthetic-alias} status ) ? ) ) )
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.util.JoinProcessor] (http-0.0.0.0-8080-19) Using FROM fragment [CENTRAL_TRANSACTIONS centraltra0_]
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] (http-0.0.0.0-8080-19) select >> end [level=1, statement=select]
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.AST] (http-0.0.0.0-8080-19) --- SQL AST ---
             \-[SELECT] QueryNode: 'SELECT' querySpaces (CENTRAL_TRANSACTIONS)
             +-[SELECT_CLAUSE] SelectClause: '{select clause}'
             | +-[COUNT] CountNode: 'count'
             | | \-[ALIAS_REF] IdentNode: 'centraltra0_.ID' {alias=centralTransaction, className=com.ngc.ident1.common.CentralTransaction, tableAlias=centraltra0_}
             | \-[SELECT_COLUMNS] SqlNode: ' as col_0_0_'
             +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[centralTransaction], fromElementByTableAlias=[centraltra0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
             | \-[FROM_FRAGMENT] FromElement: 'CENTRAL_TRANSACTIONS centraltra0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=centralTransaction,role=null,tableName=CENTRAL_TRANSACTIONS,tableAlias=centraltra0_,origin=null,colums={,className=com.ngc.ident1.common.CentralTransaction}}
             \-[WHERE] SqlNode: 'where'
             \-[EQ] BinaryLogicOperatorNode: '='
             +-[DOT] DotNode: 'centraltra0_.STATUS' {propertyName=status,dereferenceType=4,propertyPath=status,path={synthetic-alias}.status,tableAlias=centraltra0_,className=com.ngc.ident1.common.CentralTransaction,classAlias=centralTransaction}
             | +-[IDENT] IdentNode: '{synthetic-alias}' {originalText={synthetic-alias}}
             | \-[IDENT] IdentNode: 'status' {originalText=status}
             \-[PARAM] ParameterNode: '?' {ordinal=0, expectedType=org.hibernate.type.IntegerType@2dce4e}
            
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.ErrorCounter] (http-0.0.0.0-8080-19) throwQueryException() : no errors
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] (http-0.0.0.0-8080-19) HQL: select count(centralTransaction) from com.ngc.ident1.common.CentralTransaction centralTransaction where status = ?
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] (http-0.0.0.0-8080-19) SQL: select count(centraltra0_.ID) as col_0_0_ from CENTRAL_TRANSACTIONS centraltra0_ where centraltra0_.STATUS=?
            2009-03-11 15:43:22,583 DEBUG [org.hibernate.hql.ast.ErrorCounter] (http-0.0.0.0-8080-19) throwQueryException() : no errors
            2009-03-11 15:43:22,583 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) HQL param location recognition took 0 mills (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:22,584 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (select count(centralTransaction) from CentralTransaction centralTransaction where status = ?)
            2009-03-11 15:43:22,584 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) find: select count(centralTransaction) from CentralTransaction centralTransaction where status = ?
            2009-03-11 15:43:22,584 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) parameters: [7]
            2009-03-11 15:43:22,584 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) named parameters: {}
            2009-03-11 15:43:22,584 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:22,584 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) opening JDBC connection
            2009-03-11 15:43:22,672 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-19) select count(centraltra0_.ID) as col_0_0_ from CENTRAL_TRANSACTIONS centraltra0_ where centraltra0_.STATUS=?
            2009-03-11 15:43:22,672 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) preparing statement
            2009-03-11 15:43:22,672 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-19) binding '7' to parameter: 1
            2009-03-11 15:43:22,710 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-03-11 15:43:22,711 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) processing result set
            2009-03-11 15:43:22,711 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result set row: 0
            2009-03-11 15:43:22,711 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result row:
            2009-03-11 15:43:22,711 TRACE [org.hibernate.type.LongType] (http-0.0.0.0-8080-19) returning '0' as column: col_0_0_
            2009-03-11 15:43:22,711 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) done processing result set (1 rows)
            2009-03-11 15:43:22,711 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-03-11 15:43:22,711 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:22,711 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) closing statement
            2009-03-11 15:43:22,711 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) aggressively releasing JDBC connection
            2009-03-11 15:43:22,711 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:22,711 DEBUG [org.hibernate.engine.StatefulPersistenceContext] (http-0.0.0.0-8080-19) initializing non-lazy collections
            2009-03-11 15:43:22,717 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (from ApplicationProperty props where application = ? and component = ? and name = ? and priority = ?)
            2009-03-11 15:43:22,717 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (from ApplicationProperty props where application = ? and component = ? and name = ? and priority = ?)
            2009-03-11 15:43:22,718 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) find: from ApplicationProperty props where application = ? and component = ? and name = ? and priority = ?
            2009-03-11 15:43:22,718 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) parameters: [central, globalconfig, serverNumber, 1]
            2009-03-11 15:43:22,718 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) named parameters: {}
            2009-03-11 15:43:22,718 DEBUG [org.hibernate.cache.StandardQueryCache] (http-0.0.0.0-8080-19) checking cached query results in region: org.hibernate.cache.StandardQueryCache
            2009-03-11 15:43:22,737 DEBUG [org.hibernate.cache.StandardQueryCache] (http-0.0.0.0-8080-19) query results were not found in cache
            2009-03-11 15:43:22,737 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:22,737 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) opening JDBC connection
            2009-03-11 15:43:22,737 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-19) select applicatio0_.ID as ID85_, applicatio0_.VALUE as VALUE85_, applicatio0_.APPLICATION as APPLICAT3_85_, applicatio0_.CREATION_DATE as CREATION4_85_, applicatio0_.LAST_MODIFIED_DATE as LAST5_85_, applicatio0_.NAME as NAME85_, applicatio0_.STATUS as STATUS85_, applicatio0_.PRIORITY as PRIORITY85_, applicatio0_.COMPONENT as COMPONENT85_ from APPLICATION_PROPERTIES applicatio0_ where applicatio0_.APPLICATION=? and applicatio0_.COMPONENT=? and applicatio0_.NAME=? and applicatio0_.PRIORITY=?
            2009-03-11 15:43:22,737 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) preparing statement
            2009-03-11 15:43:22,737 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) binding 'central' to parameter: 1
            2009-03-11 15:43:22,737 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) binding 'globalconfig' to parameter: 2
            2009-03-11 15:43:22,737 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) binding 'serverNumber' to parameter: 3
            2009-03-11 15:43:22,737 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-19) binding '1' to parameter: 4
            2009-03-11 15:43:22,739 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-03-11 15:43:22,741 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) processing result set
            2009-03-11 15:43:22,741 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result set row: 0
            2009-03-11 15:43:22,741 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-19) returning '7533' as column: ID85_
            2009-03-11 15:43:22,741 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result row: EntityKey[com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,741 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) Initializing object from ResultSet: [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,741 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] (http-0.0.0.0-8080-19) Hydrating entity: [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,741 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) returning '2' as column: VALUE85_
            2009-03-11 15:43:22,741 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) returning 'central' as column: APPLICAT3_85_
            2009-03-11 15:43:22,741 TRACE [org.hibernate.type.TimestampType] (http-0.0.0.0-8080-19) returning '2009-03-09 21:03:29' as column: CREATION4_85_
            2009-03-11 15:43:22,742 TRACE [org.hibernate.type.TimestampType] (http-0.0.0.0-8080-19) returning '2009-03-09 21:03:29' as column: LAST5_85_
            2009-03-11 15:43:22,742 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) returning 'serverNumber' as column: NAME85_
            2009-03-11 15:43:22,742 TRACE [org.hibernate.type.CharacterType] (http-0.0.0.0-8080-19) returning 'A' as column: STATUS85_
            2009-03-11 15:43:22,742 TRACE [org.hibernate.type.IntegerType] (http-0.0.0.0-8080-19) returning '1' as column: PRIORITY85_
            2009-03-11 15:43:22,742 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) returning 'globalconfig' as column: COMPONENT85_
            2009-03-11 15:43:22,742 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) done processing result set (1 rows)
            2009-03-11 15:43:22,742 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-03-11 15:43:22,742 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:22,742 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) closing statement
            2009-03-11 15:43:22,742 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) aggressively releasing JDBC connection
            2009-03-11 15:43:22,742 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:22,742 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) total objects hydrated: 1
            2009-03-11 15:43:22,742 DEBUG [org.hibernate.engine.TwoPhaseLoad] (http-0.0.0.0-8080-19) resolving associations for [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,742 DEBUG [org.hibernate.engine.TwoPhaseLoad] (http-0.0.0.0-8080-19) adding entity to second-level cache: [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,742 DEBUG [org.hibernate.cache.NonstrictReadWriteCache] (http-0.0.0.0-8080-19) Caching: com.ngc.ident1.common.properties.ApplicationProperty#7533
            2009-03-11 15:43:22,752 DEBUG [org.hibernate.engine.TwoPhaseLoad] (http-0.0.0.0-8080-19) done materializing entity [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,752 DEBUG [org.hibernate.engine.StatefulPersistenceContext] (http-0.0.0.0-8080-19) initializing non-lazy collections
            2009-03-11 15:43:22,753 DEBUG [org.hibernate.cache.StandardQueryCache] (http-0.0.0.0-8080-19) caching query results in region: org.hibernate.cache.StandardQueryCache; timestamp=5065876285628416
            2009-03-11 15:43:22,877 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (from ApplicationProperty props where application = ? and component = ? and name = ? and priority = ?)
            2009-03-11 15:43:22,877 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache (from ApplicationProperty props where application = ? and component = ? and name = ? and priority = ?)
            2009-03-11 15:43:22,877 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) flushing session
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) processing flush-time cascades
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) dirty checking collections
            2009-03-11 15:43:22,877 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) Flushing entities and processing referenced collections
            2009-03-11 15:43:22,877 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) Processing unreferenced collections
            2009-03-11 15:43:22,877 TRACE [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) Scheduling collection removes/(re)creates/updates
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) Flushed: 0 insertions, 0 updates, 0 deletions to 1 objects
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-19) Flushed: 0 (re)creations, 0 updates, 0 removals to 0 collections
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.pretty.Printer] (http-0.0.0.0-8080-19) listing entities:
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.pretty.Printer] (http-0.0.0.0-8080-19) com.ngc.ident1.common.properties.ApplicationProperty{id=7533, creationDate=2009-03-09 21:03:29, application=central, component=globalconfig, status=A, priority=1, name=serverNumber, value=2, lastModifiedDate=2009-03-09 21:03:29}
            2009-03-11 15:43:22,877 TRACE [org.hibernate.event.def.DefaultAutoFlushEventListener] (http-0.0.0.0-8080-19) Dont need to execute flush
            2009-03-11 15:43:22,877 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) find: from ApplicationProperty props where application = ? and component = ? and name = ? and priority = ?
            2009-03-11 15:43:22,877 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) parameters: [central, globalconfig, serverNumber, 1]
            2009-03-11 15:43:22,877 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) named parameters: {}
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.cache.StandardQueryCache] (http-0.0.0.0-8080-19) checking cached query results in region: org.hibernate.cache.StandardQueryCache
            2009-03-11 15:43:22,877 DEBUG [org.hibernate.cache.StandardQueryCache] (http-0.0.0.0-8080-19) Checking query spaces for up-to-dateness: [APPLICATION_PROPERTIES]
            2009-03-11 15:43:22,898 DEBUG [org.hibernate.cache.StandardQueryCache] (http-0.0.0.0-8080-19) returning cached query results
            2009-03-11 15:43:22,905 TRACE [org.hibernate.event.def.DefaultLoadEventListener] (http-0.0.0.0-8080-19) loading entity: [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,906 TRACE [org.hibernate.event.def.DefaultLoadEventListener] (http-0.0.0.0-8080-19) attempting to resolve: [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,906 TRACE [org.hibernate.event.def.DefaultLoadEventListener] (http-0.0.0.0-8080-19) resolved object in session cache: [com.ngc.ident1.common.properties.ApplicationProperty#7533]
            2009-03-11 15:43:22,916 INFO [com.ngc.ident1.repository.webservice.siscola.CollectionServiceImplWrapper] (http-0.0.0.0-8080-19) NSN: 250920000055; Received permanentlyDeleteEntities request
            2009-03-11 15:43:23,261 TRACE [org.hibernate.event.def.DefaultSaveOrUpdateEventListener] (http-0.0.0.0-8080-19) saving transient instance
            2009-03-11 15:43:23,261 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:23,261 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) opening JDBC connection
            2009-03-11 15:43:23,261 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-19) select nextval ('CENTRAL_TRANSACTIONS_SEQ')
            2009-03-11 15:43:23,261 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) preparing statement
            2009-03-11 15:43:23,261 DEBUG [org.hibernate.id.SequenceGenerator] (http-0.0.0.0-8080-19) Sequence identifier generated: 56
            2009-03-11 15:43:23,261 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:23,261 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) closing statement
            2009-03-11 15:43:23,262 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) aggressively releasing JDBC connection
            2009-03-11 15:43:23,262 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:23,262 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] (http-0.0.0.0-8080-19) generated identifier: 56, using strategy: org.hibernate.id.SequenceGenerator
            2009-03-11 15:43:23,262 TRACE [org.hibernate.event.def.AbstractSaveEventListener] (http-0.0.0.0-8080-19) saving [com.ngc.ident1.common.CentralTransaction#56]
            2009-03-11 15:43:23,262 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) processing cascade ACTION_SAVE_UPDATE for: com.ngc.ident1.common.CentralTransaction
            2009-03-11 15:43:23,262 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) done processing cascade ACTION_SAVE_UPDATE for: com.ngc.ident1.common.CentralTransaction
            2009-03-11 15:43:23,287 TRACE [org.hibernate.event.def.WrapVisitor] (http-0.0.0.0-8080-19) Wrapped collection in role: com.ngc.ident1.common.CentralTransaction.markRepositoryReqInfos
            2009-03-11 15:43:23,287 TRACE [org.hibernate.event.def.WrapVisitor] (http-0.0.0.0-8080-19) Wrapped collection in role: com.ngc.ident1.common.CentralTransaction.printRepositoryReqInfos
            2009-03-11 15:43:23,287 TRACE [org.hibernate.event.def.WrapVisitor] (http-0.0.0.0-8080-19) Wrapped collection in role: com.ngc.ident1.common.CentralTransaction.roamingLoginInfos
            2009-03-11 15:43:23,287 TRACE [org.hibernate.event.def.WrapVisitor] (http-0.0.0.0-8080-19) Wrapped collection in role: com.ngc.ident1.common.CentralTransaction.caseStatusInfos
            2009-03-11 15:43:23,307 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) processing cascade ACTION_SAVE_UPDATE for: com.ngc.ident1.common.CentralTransaction
            2009-03-11 15:43:23,307 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.markRepositoryReqInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) done cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.markRepositoryReqInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.printRepositoryReqInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) done cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.printRepositoryReqInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.roamingLoginInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) done cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.roamingLoginInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.caseStatusInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) done cascade ACTION_SAVE_UPDATE for collection: com.ngc.ident1.common.CentralTransaction.caseStatusInfos
            2009-03-11 15:43:23,308 TRACE [org.hibernate.engine.Cascade] (http-0.0.0.0-8080-19) done processing cascade ACTION_SAVE_UPDATE for: com.ngc.ident1.common.CentralTransaction
            2009-03-11 15:43:23,321 DEBUG [org.hibernate.impl.SessionImpl] (http-0.0.0.0-8080-19) opened session at timestamp: 12367862033
            2009-03-11 15:43:23,321 TRACE [org.hibernate.transaction.JTATransactionFactory] (http-0.0.0.0-8080-19) Attempting to locate UserTransaction via JNDI [UserTransaction]
            2009-03-11 15:43:23,321 TRACE [org.hibernate.transaction.JTATransactionFactory] (http-0.0.0.0-8080-19) Obtained UserTransaction
            2009-03-11 15:43:23,321 DEBUG [org.hibernate.jdbc.JDBCContext] (http-0.0.0.0-8080-19) successfully registered Synchronization
            2009-03-11 15:43:23,321 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) unable to locate HQL query plan in cache; generating ( from CdbSispKeys c where c.sispKey = ?)
            2009-03-11 15:43:23,322 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] (http-0.0.0.0-8080-19) parse() - HQL: from com.ngc.ident1.cdb.CdbSispKeys c where c.sispKey = ?
            2009-03-11 15:43:23,348 DEBUG [org.hibernate.hql.ast.AST] (http-0.0.0.0-8080-19) --- HQL AST ---
             \-[QUERY] 'query'
             +-[SELECT_FROM] 'SELECT_FROM'
             | \-[FROM] 'from'
             | \-[RANGE] 'RANGE'
             | +-[DOT] '.'
             | | +-[DOT] '.'
             | | | +-[DOT] '.'
             | | | | +-[DOT] '.'
             | | | | | +-[IDENT] 'com'
             | | | | | \-[IDENT] 'ngc'
             | | | | \-[IDENT] 'ident1'
             | | | \-[IDENT] 'cdb'
             | | \-[IDENT] 'CdbSispKeys'
             | \-[ALIAS] 'c'
             \-[WHERE] 'where'
             \-[EQ] '='
             +-[DOT] '.'
             | +-[IDENT] 'c'
             | \-[IDENT] 'sispKey'
             \-[PARAM] '?'
            
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.ErrorCounter] (http-0.0.0.0-8080-19) throwQueryException() : no errors
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] (http-0.0.0.0-8080-19) select << begin [level=1, statement=select]
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.tree.FromElement] (http-0.0.0.0-8080-19) FromClause{level=1} : com.ngc.ident1.cdb.CdbSispKeys (c) -> cdbsispkey0_
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] (http-0.0.0.0-8080-19) Resolved : c -> cdbsispkey0_.SISP_NUM
            2009-03-11 15:43:23,349 TRACE [org.hibernate.hql.ast.tree.FromElement] (http-0.0.0.0-8080-19) handling property dereference [com.ngc.ident1.cdb.CdbSispKeys (c) -> sispKey (class)]
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.tree.DotNode] (http-0.0.0.0-8080-19) getDataType() : sispKey -> org.hibernate.type.StringType@168f248
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] (http-0.0.0.0-8080-19) Resolved : c.sispKey -> cdbsispkey0_.SISP_KEY
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] (http-0.0.0.0-8080-19) select : finishing up [level=1, statement=select]
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.HqlSqlWalker] (http-0.0.0.0-8080-19) processQuery() : ( SELECT ( FromClause{level=1} IDENT1.CDB_SISP_KEYS cdbsispkey0_ ) ( where ( = ( cdbsispkey0_.SISP_KEY cdbsispkey0_.SISP_NUM sispKey ) ? ) ) )
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.HqlSqlWalker] (http-0.0.0.0-8080-19) Derived SELECT clause created.
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.ast.util.JoinProcessor] (http-0.0.0.0-8080-19) Using FROM fragment [IDENT1.CDB_SISP_KEYS cdbsispkey0_]
            2009-03-11 15:43:23,349 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] (http-0.0.0.0-8080-19) select >> end [level=1, statement=select]
            2009-03-11 15:43:23,350 DEBUG [org.hibernate.hql.ast.AST] (http-0.0.0.0-8080-19) --- SQL AST ---
             \-[SELECT] QueryNode: 'SELECT' querySpaces (IDENT1.CDB_SISP_KEYS)
             +-[SELECT_CLAUSE] SelectClause: '{derived select clause}'
             | +-[SELECT_EXPR] SelectExpressionImpl: 'cdbsispkey0_.SISP_NUM as SISP1_525_' {FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=c,role=null,tableName=IDENT1.CDB_SISP_KEYS,tableAlias=cdbsispkey0_,origin=null,colums={,className=com.ngc.ident1.cdb.CdbSispKeys}}}
             | \-[SQL_TOKEN] SqlFragment: 'cdbsispkey0_.ID as ID525_, cdbsispkey0_.SISP_KEY as SISP3_525_, cdbsispkey0_.INCLUDE_FLAG as INCLUDE4_525_, cdbsispkey0_.PRIMARY as PRIMARY525_, cdbsispkey0_.MODIFIED_TIME as MODIFIED6_525_, cdbsispkey0_.DATA_FLAG as DATA7_525_, cdbsispkey0_.ENTITY_TYPE as ENTITY8_525_, cdbsispkey0_.rowid as rowid_'
             +-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[c], fromElementByTableAlias=[cdbsispkey0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
             | \-[FROM_FRAGMENT] FromElement: 'IDENT1.CDB_SISP_KEYS cdbsispkey0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=c,role=null,tableName=IDENT1.CDB_SISP_KEYS,tableAlias=cdbsispkey0_,origin=null,colums={,className=com.ngc.ident1.cdb.CdbSispKeys}}
             \-[WHERE] SqlNode: 'where'
             \-[EQ] BinaryLogicOperatorNode: '='
             +-[DOT] DotNode: 'cdbsispkey0_.SISP_KEY' {propertyName=sispKey,dereferenceType=4,propertyPath=sispKey,path=c.sispKey,tableAlias=cdbsispkey0_,className=com.ngc.ident1.cdb.CdbSispKeys,classAlias=c}
             | +-[ALIAS_REF] IdentNode: 'cdbsispkey0_.SISP_NUM' {alias=c, className=com.ngc.ident1.cdb.CdbSispKeys, tableAlias=cdbsispkey0_}
             | \-[IDENT] IdentNode: 'sispKey' {originalText=sispKey}
             \-[PARAM] ParameterNode: '?' {ordinal=0, expectedType=org.hibernate.type.StringType@168f248}
            
            2009-03-11 15:43:23,350 DEBUG [org.hibernate.hql.ast.ErrorCounter] (http-0.0.0.0-8080-19) throwQueryException() : no errors
            2009-03-11 15:43:23,350 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] (http-0.0.0.0-8080-19) HQL: from com.ngc.ident1.cdb.CdbSispKeys c where c.sispKey = ?
            2009-03-11 15:43:23,350 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] (http-0.0.0.0-8080-19) SQL: select cdbsispkey0_.SISP_NUM as SISP1_525_, cdbsispkey0_.ID as ID525_, cdbsispkey0_.SISP_KEY as SISP3_525_, cdbsispkey0_.INCLUDE_FLAG as INCLUDE4_525_, cdbsispkey0_.PRIMARY as PRIMARY525_, cdbsispkey0_.MODIFIED_TIME as MODIFIED6_525_, cdbsispkey0_.DATA_FLAG as DATA7_525_, cdbsispkey0_.ENTITY_TYPE as ENTITY8_525_, cdbsispkey0_.rowid as rowid_ from IDENT1.CDB_SISP_KEYS cdbsispkey0_ where cdbsispkey0_.SISP_KEY=?
            2009-03-11 15:43:23,350 DEBUG [org.hibernate.hql.ast.ErrorCounter] (http-0.0.0.0-8080-19) throwQueryException() : no errors
            2009-03-11 15:43:23,350 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) HQL param location recognition took 0 mills ( from CdbSispKeys c where c.sispKey = ?)
            2009-03-11 15:43:23,350 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) located HQL query plan in cache ( from CdbSispKeys c where c.sispKey = ?)
            2009-03-11 15:43:23,350 TRACE [org.hibernate.engine.query.HQLQueryPlan] (http-0.0.0.0-8080-19) find: from CdbSispKeys c where c.sispKey = ?
            2009-03-11 15:43:23,350 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) parameters: [CO10080025865J]
            2009-03-11 15:43:23,350 TRACE [org.hibernate.engine.QueryParameters] (http-0.0.0.0-8080-19) named parameters: {}
            2009-03-11 15:43:23,350 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
            2009-03-11 15:43:23,350 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) opening JDBC connection
            2009-03-11 15:43:23,421 DEBUG [org.hibernate.SQL] (http-0.0.0.0-8080-19) select cdbsispkey0_.SISP_NUM as SISP1_525_, cdbsispkey0_.ID as ID525_, cdbsispkey0_.SISP_KEY as SISP3_525_, cdbsispkey0_.INCLUDE_FLAG as INCLUDE4_525_, cdbsispkey0_.PRIMARY as PRIMARY525_, cdbsispkey0_.MODIFIED_TIME as MODIFIED6_525_, cdbsispkey0_.DATA_FLAG as DATA7_525_, cdbsispkey0_.ENTITY_TYPE as ENTITY8_525_, cdbsispkey0_.rowid as rowid_ from IDENT1.CDB_SISP_KEYS cdbsispkey0_ where cdbsispkey0_.SISP_KEY=?
            2009-03-11 15:43:23,421 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) preparing statement
            2009-03-11 15:43:23,569 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) binding 'CO10080025865J' to parameter: 1
            2009-03-11 15:43:23,626 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to open ResultSet (open ResultSets: 0, globally: 0)
            2009-03-11 15:43:23,626 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) processing result set
            2009-03-11 15:43:23,626 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result set row: 0
            2009-03-11 15:43:23,626 TRACE [org.hibernate.type.LongType] (http-0.0.0.0-8080-19) returning '539' as column: SISP1_525_
            2009-03-11 15:43:23,626 DEBUG [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) result row: EntityKey[com.ngc.ident1.cdb.CdbSispKeys#539]
            2009-03-11 15:43:23,626 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) Initializing object from ResultSet: [com.ngc.ident1.cdb.CdbSispKeys#539]
            2009-03-11 15:43:23,626 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] (http-0.0.0.0-8080-19) Hydrating entity: [com.ngc.ident1.cdb.CdbSispKeys#539]
            2009-03-11 15:43:23,626 TRACE [org.hibernate.type.LongType] (http-0.0.0.0-8080-19) returning '519' as column: ID525_
            2009-03-11 15:43:23,626 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) returning 'CO10080025865J' as column: SISP3_525_
            2009-03-11 15:43:23,626 TRACE [org.hibernate.type.CharacterType] (http-0.0.0.0-8080-19) returning '1' as column: INCLUDE4_525_
            2009-03-11 15:43:23,626 TRACE [org.hibernate.type.CharacterType] (http-0.0.0.0-8080-19) returning 'Y' as column: PRIMARY525_
            2009-03-11 15:43:23,628 TRACE [org.hibernate.type.CalendarType] (http-0.0.0.0-8080-19) returning '2008-09-30 22:40:53' as column: MODIFIED6_525_
            2009-03-11 15:43:23,628 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) returning null as column: DATA7_525_
            2009-03-11 15:43:23,628 TRACE [org.hibernate.type.StringType] (http-0.0.0.0-8080-19) returning null as column: ENTITY8_525_
            2009-03-11 15:43:23,628 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) done processing result set (1 rows)
            2009-03-11 15:43:23,628 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close ResultSet (open ResultSets: 1, globally: 1)
            2009-03-11 15:43:23,628 DEBUG [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
            2009-03-11 15:43:23,628 TRACE [org.hibernate.jdbc.AbstractBatcher] (http-0.0.0.0-8080-19) closing statement
            2009-03-11 15:43:23,628 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) aggressively releasing JDBC connection
            2009-03-11 15:43:23,628 DEBUG [org.hibernate.jdbc.ConnectionManager] (http-0.0.0.0-8080-19) releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
            2009-03-11 15:43:23,628 TRACE [org.hibernate.loader.Loader] (http-0.0.0.0-8080-19) total objects hydrated: 1
            2009-03-11 15:43:23,628 DEBUG [org.hibernate.engine.TwoPhaseLoad] (http-0.0.0.0-8080-19) resolving associations for [com.ngc.ident1.cdb.CdbSispKeys#539]
            2009-03-11 15:43:23,628 TRACE [org.hibernate.event.def.DefaultLoadEventListener] (http-0.0.0.0-8080-19) loading entity: [com.ngc.ident1.cdb.CdbIdentifiers#519]
            2009-03-11 15:43:23,628 TRACE [org.hibernate.event.def.DefaultLoadEventListener] (http-0.0.0.0-8080-19) creating new proxy for entity
            2009-03-11 15:43:23,646 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbTpEditHists#539]
            2009-03-11 15:43:23,646 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbPalmSagems#539]
            2009-03-11 15:43:23,646 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbKbmPartitionses#539]
            2009-03-11 15:43:23,646 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbUnsMarkNorms#539]
            2009-03-11 15:43:23,646 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbTpSagemDatas#539]
            2009-03-11 15:43:23,646 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbTpImageInfos#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbIdentifiersCollections#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkCrimeRefs#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbFingerprintInfos#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkSagems#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbSubjectPlainDatas#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkSubjDatas#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkImageInfos#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbPalmEditHists#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkCases#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkHistories#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkCrimes#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbOtherImageses#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkNoteses#539]
            2009-03-11 15:43:23,647 TRACE [org.hibernate.engine.loading.LoadContexts] (http-0.0.0.0-8080-19) creating collection wrapper:[com.ngc.ident1.cdb.CdbSispKeys.cdbMarkPlaces#539]
            2009-03-11 15:43:23,647 DEBUG [org.hibernate.engine.TwoPhaseLoad] (http-0.0.0.0-8080-19) adding entity to second-level cache: [com.ngc.ident1.cdb.CdbSispKeys#539]
            2009-03-11 15:43:23,647 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-19) Testing if invocations are allowed.
            2009-03-11 15:43:23,647 TRACE [org.jboss.cache.mvcc.MVCCNodeHelper] (http-0.0.0.0-8080-19) Node /com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539 is not in context, fetching from container.
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) Invoked with command PutForExternalReadCommand{fqn=/com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539, dataVersion=null, globalTransaction=null, key=item, value=CacheEntry(com.ngc.ident1.cdb.CdbSispKeys)[519,CO10080025865J,1,Y,java.util.GregorianCalendar[time=1222814453000,areFieldsSet=true,areAllFieldsSet=true,lenient=true,zone=sun.util.calendar.ZoneInfo[id="GMT",offset=0,dstSavings=0,useDaylight=false,transitions=0,lastRule=null],firstDayOfWeek=1,minimalDaysInFirstWeek=1,ERA=1,YEAR=2008,MONTH=8,WEEK_OF_YEAR=40,WEEK_OF_MONTH=5,DAY_OF_MONTH=30,DAY_OF_YEAR=274,DAY_OF_WEEK=3,DAY_OF_WEEK_IN_MONTH=5,AM_PM=1,HOUR=10,HOUR_OF_DAY=22,MINUTE=40,SECOND=53,MILLISECOND=0,ZONE_OFFSET=0,DST_OFFSET=0],null,null,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539]} and InvocationContext [InvocationContext{transaction=null, globalTransaction=null, transactionContext=null, optionOverrides=Option{failSilently=true, cacheModeLocal=false, dataVersion=null, suppressLocking=false, lockAcquisitionTimeout=-1, forceDataGravitation=false, skipDataGravitation=false, forceAsynchronous=true, forceSynchronous=false}, originLocal=true}]
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) Setting up transactional context.
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) Setting tx as TransactionImpl:XidImpl[FormatId=257, GlobalId=csnwas22/51, BranchQual=, localId=51] and gtx as null
            2009-03-11 15:43:23,660 DEBUG [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) FAIL_SILENTLY Option is present - suspending any ongoing transaction.
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) Setting up transactional context.
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) Setting tx as null and gtx as null
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) Suspending transaction TransactionImpl:XidImpl[FormatId=257, GlobalId=csnwas22/51, BranchQual=, localId=51]
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.lock.MVCCLockManager] (http-0.0.0.0-8080-19) Attempting to lock /com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.mvcc.MVCCNodeFactory] (http-0.0.0.0-8080-19) Created new child with fqn [/com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539]
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-19) Perform('null', '/com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539', k='item', v='CacheEntry(com.ngc.ident1.cdb.CdbSispKeys)[519,CO10080025865J,1,Y,java.util.GregorianCalendar[time=1222814453000,areFieldsSet=true,areAllFieldsSet=true,lenient=true,zone=sun.util.calendar.ZoneInfo[id="GMT",offset=0,dstSavings=0,useDaylight=false,transitions=0,lastRule=null],firstDayOfWeek=1,minimalDaysInFirstWeek=1,ERA=1,YEAR=2008,MONTH=8,WEEK_OF_YEAR=40,WEEK_OF_MONTH=5,DAY_OF_MONTH=30,DAY_OF_YEAR=274,DAY_OF_WEEK=3,DAY_OF_WEEK_IN_MONTH=5,AM_PM=1,HOUR=10,HOUR_OF_DAY=22,MINUTE=40,SECOND=53,MILLISECOND=0,ZONE_OFFSET=0,DST_OFFSET=0],null,null,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539,539]')
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-19) Old value is null, dataLoaded=false
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.mvcc.ReadCommittedNode] (http-0.0.0.0-8080-19) Updating node [/com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539]. deleted=false valid=true changed=true created=true
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.MVCCLockingInterceptor] (http-0.0.0.0-8080-19) Releasing lock on [/com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539] for owner Thread[http-0.0.0.0-8080-19,5,jboss]
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.lock.MVCCLockManager] (http-0.0.0.0-8080-19) Attempting to unlock /com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#539
            2009-03-11 15:43:23,660 TRACE [org.jboss.cache.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-19) Resetting invocation-scope options
            2009-03-11 15:43:23,660 DEBUG [org.hibernate.engine.TwoPhaseLoad] (http-0.0.0.0-8080-19) done materializing entity [com.ngc.ident1.cdb.CdbSispKeys#539]
            2009-03-11 15:43:23,660 DEBUG [org.hibernate.engine.StatefulPersistenceContext] (http-0.0.0.0-8080-19) initializing non-lazy collections
            2009-03-11 15:43:23,661 TRACE [org.hibernate.engine.query.QueryPlanCache] (http-0.0.0.0-8080-19) unable to locate HQL query plan in cache; generating ( from CdbSispKeys c where c.cdbIdentifiers.id = ?)
            2009-03-11 15:43:23,662 DEBUG [org.hibernate.hql.ast.QueryTranslatorImpl] (http-0.0.0.0-8080-19) parse() - HQL: from com.ngc.ident1.cdb.CdbSispKeys c where c.cdbIdentifiers.id = ?
            2009-03-11 15:43:23,664 DEBUG [org.hibernate.hql.ast.AST] (http-0.0.0.0-8080-19) --- HQL AST ---
             \-[QUERY] 'query'
             +-[SELECT_FROM] 'SELECT_FROM'
             | \-[FROM] 'from'
             | \-[RANGE] 'RANGE'
             | +-[DOT] '.'
             | | +-[DOT] '.'
             | | | +-[DOT] '.'
             | | | | +-[DOT] '.'
             | | | | | +-[IDENT] 'com'
             | | | | | \-[IDENT] 'ngc'
             | | | | \-[IDENT] 'ident1'
             | | | \-[IDENT] 'cdb'
             | | \-[IDENT] 'CdbSispKeys'
             | \-[ALIAS] 'c'
             \-[WHERE] 'where'
             \-[EQ] '='
             +-[DOT] '.'
             | +-[DOT] '.'
             | | +-[IDENT] 'c'
             | | \-[IDENT] 'cdbIdentifiers'
             | \-[IDENT] 'id'
             \-[PARAM] '?'
            
            2009-03-11 15:43:23,664 DEBUG [org.hibernate.hql.ast.ErrorCounter] (http-0.0.0.0-8080-19) throwQueryException() : no errors
            2009-03-11 15:43:23,664 DEBUG [org.hibernate.hql.antlr.HqlSqlBaseWalker] (http-0.0.0.0-8080-19) select << begin [level=1, statement=select]
            2009-03-11 15:43:23,664 DEBUG [org.hibernate.hql.ast.tree.FromElement] (http-0.0.0.0-8080-19) FromClause{level=1} : com.ngc.ident1.cdb.CdbSispKeys (c) -> cdbsispkey0_
            2009-03-11 15:43:23,664 DEBUG [org.hibernate.hql.ast.tree.FromReferenceNode] (http-0.0.0.0-8080-19) Resolved : c -> cdbsispkey0_.SISP_NUM
            2009-03-11 15:43:23,664 TRACE [org.hibernate.hql.ast.tree.FromElement] (http-0.0.0.0-8080-19) handling property dereference [com.ngc.ident1.cdb.CdbSispKeys (c) -> cdbIdentifiers (class)]
            2009-03-11 15:43:23,664 DEBUG [org.hibernate.hql.ast.tree.DotNode] (http-0.0.0.0-8080-19) getDataType() : cdbIdentifiers -> org.hibernate.type.ManyToOneType(com.ngc.ident1.cdb.CdbIdentifiers)
            2009-03-11 15:43:23,664 DEBUG [org.hibernate.hql.ast.tree.DotNode] (http-0.0.0.0-8080-19) dereferenceShortcut() : property id in com.ngc.ident1.cdb.CdbSispKeys does not require a join.
            200
            
            


            • 3. Re: Unable To Acquire Lock
              Kevin Urciolo Newbie

              Sorry... the log seems to be too big to just paste in to the text field.

              • 4. Re: Unable To Acquire Lock
                Kevin Urciolo Newbie

                Here is just the JBossCache TRACE Logging...

                2009-03-11 16:32:05,056 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,056 DEBUG [org.jboss.cache.invocation.CacheInvocationDelegate] (http-0.0.0.0-8080-24) putForExternalRead() called with Fqn /com/ngc/ident1/cdb/CdbSispKeys/ENTITY/com.ngc.ident1.cdb.CdbSispKeys#538 and this node already exists. This method is hence a no op.
                2009-03-11 16:32:05,066 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,237 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,237 DEBUG [org.jboss.cache.invocation.CacheInvocationDelegate] (http-0.0.0.0-8080-24) putForExternalRead() called with Fqn /com/ngc/ident1/cdb/CdbCollections/ENTITY/com.ngc.ident1.cdb.CdbCollections#-1 and this node already exists. This method is hence a no op.
                2009-03-11 16:32:05,276 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,276 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_EDIT_HIST', k='item', v='12367891852')
                2009-03-11 16:32:05,276 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,276 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_EDIT_HIST, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,284 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,285 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,285 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_PALM_SAGEM', k='item', v='12367891852')
                2009-03-11 16:32:05,285 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,285 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_PALM_SAGEM, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,285 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,285 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_KBM_PARTITIONS', k='item', v='12367891852')
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_KBM_PARTITIONS, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_UNS_MARK_NORM', k='item', v='12367891852')
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_UNS_MARK_NORM, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,286 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,287 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,287 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_SAGEM_DATA', k='item', v='12367891852')
                2009-03-11 16:32:05,287 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,287 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_SAGEM_DATA, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,287 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,287 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE_INFO', k='item', v='12367891852')
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE_INFO, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_IDENTIFIERS_COLLECTION', k='item', v='12367891852')
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_IDENTIFIERS_COLLECTION, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,288 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,289 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,289 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_CRIME_REF', k='item', v='12367891852')
                2009-03-11 16:32:05,289 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,289 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_CRIME_REF, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,289 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,289 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_FINGERPRINT_INFO', k='item', v='12367891852')
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_FINGERPRINT_INFO, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_SAGEM', k='item', v='12367891852')
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_SAGEM, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,290 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_PLAIN_DATA', k='item', v='12367891852')
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_PLAIN_DATA, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_SUBJ_DATA', k='item', v='12367891852')
                2009-03-11 16:32:05,291 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,292 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_SUBJ_DATA, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,292 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,292 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,292 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_IMAGE_INFO', k='item', v='12367891852')
                2009-03-11 16:32:05,292 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,292 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_IMAGE_INFO, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,292 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_PALM_EDIT_HIST', k='item', v='12367891852')
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_PALM_EDIT_HIST, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_CASE', k='item', v='12367891852')
                2009-03-11 16:32:05,293 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,294 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_CASE, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,294 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,294 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,294 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_HISTORY', k='item', v='12367891852')
                2009-03-11 16:32:05,294 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,294 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_HISTORY, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,294 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_CRIME', k='item', v='12367891852')
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_CRIME, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_IMAGES', k='item', v='12367891852')
                2009-03-11 16:32:05,295 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,296 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_IMAGES, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,296 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,296 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,296 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_NOTES', k='item', v='12367891852')
                2009-03-11 16:32:05,296 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,296 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_NOTES, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,296 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_PLACE', k='item', v='12367891852')
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890560, dataLoaded=false
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_MARK_PLACE, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891852')
                2009-03-11 16:32:05,297 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890661, dataLoaded=false
                2009-03-11 16:32:05,298 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,298 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,298 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,298 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST', k='item', v='12367891852')
                2009-03-11 16:32:05,298 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890661, dataLoaded=false
                2009-03-11 16:32:05,298 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,298 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE', k='item', v='12367891852')
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890661, dataLoaded=false
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO', k='item', v='12367891852')
                2009-03-11 16:32:05,299 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890661, dataLoaded=false
                2009-03-11 16:32:05,300 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891852}}
                2009-03-11 16:32:05,300 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,310 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,310 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_ARREST', k='item', v='12367891853')
                2009-03-11 16:32:05,310 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891058, dataLoaded=false
                2009-03-11 16:32:05,310 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_ARREST, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,310 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,311 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,311 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_ALERT_FLAGS', k='item', v='12367891853')
                2009-03-11 16:32:05,311 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890660, dataLoaded=false
                2009-03-11 16:32:05,311 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_ALERT_FLAGS, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,311 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_PASSPORT_INFO', k='item', v='12367891853')
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890660, dataLoaded=false
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_PASSPORT_INFO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SISP_KEYS', k='item', v='12367891853')
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890660, dataLoaded=false
                2009-03-11 16:32:05,312 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SISP_KEYS, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,313 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,313 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,313 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CRIME', k='item', v='12367891853')
                2009-03-11 16:32:05,313 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890660, dataLoaded=false
                2009-03-11 16:32:05,313 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CRIME, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,313 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_PLACE', k='item', v='12367891853')
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890660, dataLoaded=false
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_PLACE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367890660, dataLoaded=false
                2009-03-11 16:32:05,314 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,315 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,315 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,315 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,315 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,315 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,315 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,315 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,316 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,317 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,317 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,317 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,317 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,317 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,317 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,317 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,318 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,319 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,319 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,319 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,319 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,319 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,319 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,320 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,321 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,321 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,321 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,321 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,321 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,321 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,322 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,323 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,323 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,323 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE', k='item', v='12367891853')
                2009-03-11 16:32:05,323 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,323 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_TP_IMAGE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,323 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,324 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,324 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                2009-03-11 16:32:05,324 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891852, dataLoaded=false
                2009-03-11 16:32:05,324 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,324 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,324 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,324 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) perform(GlobalTransaction:<192.45.195.127:7802>:2, /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3427)
                2009-03-11 16:32:05,333 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) node /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3427 not found
                2009-03-11 16:32:05,333 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,333 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                2009-03-11 16:32:05,333 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,334 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,334 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,334 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,334 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) perform(GlobalTransaction:<192.45.195.127:7802>:2, /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3415)
                2009-03-11 16:32:05,334 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) node /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3415 not found
                2009-03-11 16:32:05,334 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,334 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) perform(GlobalTransaction:<192.45.195.127:7802>:2, /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3429)
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) node /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3429 not found
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,335 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) perform(GlobalTransaction:<192.45.195.127:7802>:2, /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3434)
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) node /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3434 not found
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,336 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) perform(GlobalTransaction:<192.45.195.127:7802>:2, /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3419)
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) node /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3419 not found
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (http-0.0.0.0-8080-24) Old value is 12367891853, dataLoaded=false
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.marshall.CacheMarshaller300] (http-0.0.0.0-8080-24) Done serializing object: ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}}
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (http-0.0.0.0-8080-24) real_dests=[192.45.194.35:7800, 192.45.194.35:7801, 192.45.194.35:7802, 192.45.194.36:7800, 192.45.194.36:7801, 192.45.194.36:7802, 192.45.194.37:7800, 192.45.194.37:7801, 192.45.194.37:7802, 192.45.194.38:7800, 192.45.194.38:7801, 192.45.194.38:7802, 192.45.195.127:7800, 192.45.195.127:7801]
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,337 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) perform(GlobalTransaction:<192.45.195.127:7802>:2, /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3423)
                2009-03-11 16:32:05,338 TRACE [org.jboss.cache.commands.write.RemoveNodeCommand] (http-0.0.0.0-8080-24) node /com/ngc/ident1/cdb/CdbOtherDemo/ENTITY/com.ngc.ident1.cdb.CdbOtherDemo#3423 not found
                2009-03-11 16:32:05,338 TRACE [org.jboss.cache.factories.ComponentRegistry] (http-0.0.0.0-8080-24) Testing if invocations are allowed.
                2009-03-11 16:32:05,338 TRACE [org.jboss.cache.commands.write.PutKeyValu


                • 5. Re: Unable To Acquire Lock
                  Kevin Urciolo Newbie

                  2009-03-11 16:32:05,422 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,422 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7801) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,422 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7801) Testing if invocations are allowed.
                  2009-03-11 16:32:05,422 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7801) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,422 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,422 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,422 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7801) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7801) Testing if invocations are allowed.
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7801) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7801) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7801) Testing if invocations are allowed.
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7801) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,423 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7801) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7801) Testing if invocations are allowed.
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7801) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST', k='item', v='12367891853')
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Old value is 12367891852, dataLoaded=false
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7801) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7801) Testing if invocations are allowed.
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7801) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE', k='item', v='12367891853')
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Old value is 12367891852, dataLoaded=false
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7801) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7801) Testing if invocations are allowed.
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7801) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7801) Old value is 12367891852, dataLoaded=false
                  2009-03-11 16:32:05,424 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7801) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,455 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,456 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,457 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,457 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,457 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,457 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,457 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,457 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,457 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,471 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,471 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,471 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,471 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,471 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,471 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,471 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891853, dataLoaded=false
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_OTHER_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST', k='item', v='12367891853')
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891852, dataLoaded=false
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_NIST, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE', k='item', v='12367891853')
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891852, dataLoaded=false
                  2009-03-11 16:32:05,472 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_CASE, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:05,473 TRACE [org.jboss.cache.factories.ComponentRegistry] (Incoming-1,192.45.195.127:7800) Testing if invocations are allowed.
                  2009-03-11 16:32:05,473 TRACE [org.jboss.cache.commands.remote.ReplicateCommand] (Incoming-1,192.45.195.127:7800) Invoking command PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}, with originLocal flag set to false.
                  2009-03-11 16:32:05,473 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Perform('null', '/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO', k='item', v='12367891853')
                  2009-03-11 16:32:05,473 TRACE [org.jboss.cache.commands.write.PutKeyValueCommand] (Incoming-1,192.45.195.127:7800) Old value is 12367891852, dataLoaded=false
                  2009-03-11 16:32:05,473 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-1,192.45.195.127:7800) Command : ReplicateCommand{cmds=PutKeyValueCommand{fqn=/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_AFR_DEMO, dataVersion=null, globalTransaction=null, key=item, value=12367891853}} executed, result is: null
                  2009-03-11 16:32:15,398 ERROR [org.hibernate.event.def.AbstractFlushingEventListener] (http-0.0.0.0-8080-24) Could not synchronize database state with session
                  org.hibernate.cache.CacheException: org.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_ARREST] after [10000] milliseconds for requestor [Thread[http-0.0.0.0-8080-24,5,jboss]]! Lock held by [GlobalTransaction:<192.45.195.127:7802>:2]
                  at org.hibernate.cache.jbc2.timestamp.TimestampsRegionImpl.put(TimestampsRegionImpl.java:130)
                  at org.hibernate.cache.UpdateTimestampsCache.preinvalidate(UpdateTimestampsCache.java:70)
                  at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:275)
                  at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:263)
                  at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:172)
                  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.springframework.orm.hibernate3.SpringSessionSynchronization.beforeCommit(SpringSessionSynchronization.java:135)
                  at org.springframework.transaction.support.TransactionSynchronizationUtils.triggerBeforeCommit(TransactionSynchronizationUtils.java:72)
                  at org.springframework.transaction.support.AbstractPlatformTransactionManager.triggerBeforeCommit(AbstractPlatformTransactionManager.java:905)
                  at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:715)
                  at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
                  at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
                  at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
                  at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
                  at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:635)
                  at com.ngc.ident1.repository.webservice.siscola.CollectionServiceImplWrapper$$EnhancerByCGLIB$$1c8d4f84.permanentlyDeleteEntities()
                  at com.ngc.ident1.repository.webservice.siscola.CollectionServicePortTypeImpl.permanentlyDeleteEntities(CollectionServicePortTypeImpl.java:445)
                  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:597)
                  at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:165)
                  at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:82)
                  at org.apache.cxf.jaxws.JAXWSMethodInvoker.invoke(JAXWSMethodInvoker.java:54)
                  at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:68)
                  at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:56)
                  at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37)
                  at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:92)
                  at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:226)
                  at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:89)
                  at org.apache.cxf.transport.servlet.ServletDestination.invoke(ServletDestination.java:99)
                  at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:305)
                  at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:175)
                  at org.apache.cxf.transport.servlet.AbstractCXFServlet.invoke(AbstractCXFServlet.java:163)
                  at org.apache.cxf.transport.servlet.AbstractCXFServlet.doPost(AbstractCXFServlet.java:141)
                  at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
                  at javax.servlet.http.HttpServlet.service(HttpServlet.java:810)
                  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
                  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
                  at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
                  at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
                  at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
                  at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
                  at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
                  at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:175)
                  at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:74)
                  at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
                  at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
                  at org.jboss.web.tomcat.tc5.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:156)
                  at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
                  at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
                  at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
                  at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
                  at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
                  at org.apache.tomcat.util.net.MasterSlaveWorkerThread.run(MasterSlaveWorkerThread.java:112)
                  at java.lang.Thread.run(Thread.java:619)
                  Caused by: org.hibernate.cache.CacheException: org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_ARREST] after [10000] milliseconds for requestor [Thread[http-0.0.0.0-8080-24,5,jboss]]! Lock held by [GlobalTransaction:<192.45.195.127:7802>:2]
                  at org.hibernate.cache.jbc2.util.CacheHelper.put(CacheHelper.java:214)
                  at org.hibernate.cache.jbc2.timestamp.TimestampsRegionImpl.put(TimestampsRegionImpl.java:128)
                  ... 57 more
                  Caused by: org.jboss.cache.lock.TimeoutException: Unable to acquire lock on Fqn [/TS/org/hibernate/cache/UpdateTimestampsCache/IDENT1.CDB_SUBJECT_ARREST] after [10000] milliseconds for requestor [Thread[http-0.0.0.0-8080-24,5,jboss]]! Lock held by [GlobalTransaction:<192.45.195.127:7802>:2]
                  at org.jboss.cache.mvcc.MVCCNodeHelper.acquireLock(MVCCNodeHelper.java:159)
                  at org.jboss.cache.mvcc.MVCCNodeHelper.wrapNodeForWriting(MVCCNodeHelper.java:212)
                  at org.jboss.cache.interceptors.MVCCLockingInterceptor.handlePutKeyValueCommand(MVCCLockingInterceptor.java:101)
                  at org.jboss.cache.interceptors.base.PrePostProcessingCommandInterceptor.visitPutKeyValueCommand(PrePostProcessingCommandInterceptor.java:88)
                  at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
                  at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
                  at org.jboss.cache.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:150)
                  at org.jboss.cache.interceptors.ReplicationInterceptor.visitPutKeyValueCommand(ReplicationInterceptor.java:107)
                  at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
                  at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
                  at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
                  at org.jboss.cache.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:65)
                  at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
                  at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
                  at org.jboss.cache.interceptors.TxInterceptor.attachGtxAndPassUpChain(TxInterceptor.java:261)
                  at org.jboss.cache.interceptors.TxInterceptor.handleDefault(TxInterceptor.java:250)
                  at org.jboss.cache.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:65)
                  at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
                  at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
                  at org.jboss.cache.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:108)
                  at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
                  at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
                  at org.jboss.cache.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:178)
                  at org.jboss.cache.interceptors.InvocationContextInterceptor.visitPutKeyValueCommand(InvocationContextInterceptor.java:82)
                  at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:100)
                  at org.jboss.cache.interceptors.InterceptorChain.invoke(InterceptorChain.java:287)
                  at org.jboss.cache.invocation.CacheInvocationDelegate.put(CacheInvocationDelegate.java:473)
                  at org.hibernate.cache.jbc2.util.CacheHelper.put(CacheHelper.java:212)
                  ... 58 more

                  • 6. Re: Unable To Acquire Lock
                    Brian Stansberry Master

                    Who is node 192.45.195.127:7802? Is that the node you got this log from or another node?