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

greenbean do-not-reply at jboss.com
Wed Mar 11 11:49:24 EDT 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/"><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 at 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 at 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 at 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 at 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#4217027

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




More information about the jboss-user mailing list