[JBoss Cache: Core Edition] - Re: Unable To Acquire Lock - jboss-user

Wednesday, 11 March 2009

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/"><s...
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

View the original post :
http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4217027#...

Reply to the post :
http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&a...

2026

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

[JBoss Cache: Core Edition] - Re: Unable To Acquire Lock