6 Replies Latest reply on Mar 17, 2009 11:38 AM by brian.stansberry

Unable To Acquire Lock

greenbean Mar 10, 2009 3:57 PM

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

nathanmesser Mar 11, 2009 10:13 AM (in response to greenbean)

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.
Actions

2. Re: Unable To Acquire Lock

greenbean Mar 11, 2009 11:49 AM (in response to greenbean)

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

greenbean Mar 11, 2009 11:51 AM (in response to greenbean)

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

4. Re: Unable To Acquire Lock

greenbean Mar 11, 2009 12:35 PM (in response to greenbean)

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

greenbean Mar 11, 2009 12:37 PM (in response to greenbean)

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
Actions
6. Re: Unable To Acquire Lock

brian.stansberry Mar 17, 2009 11:38 AM (in response to greenbean)

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

Go to original post