[jboss-user] [JBoss Cache: Core Edition] - Re: Endless loop trying to obtain lock in 1.4.1.SP9
BradleyDouglas
do-not-reply at jboss.com
Mon Aug 25 19:42:12 EDT 2008
Thanks for replying - but I've got two things to clear up.
Firstly, is there a way to tell which version of the cache is being used? The reason I ask is that I've upgraded out app & jboss app server to use the core cahce version 2.2.1 and still appear to have the same problem with it endlessly looping trying to lock a node that is already locked by the user.
I've attached the new logs below, and would really appreciate some help, as I've had to disable 2nd level cacheing in hibernate as this is taking our production environment off the air when it goes awry. The first logs are a grep for "ReconciliationBatch#2" showing the life of the node that is being locked when things go bad. The second is a snippet of all the jboss.cache logs around where the endless loop starts.
Please - any help or hints about how resolve this would be really appreciated, and if more details are needed I'm happy to provide them.
Thanks,
anonymous wrote :
| 2008-08-25 16:12:34,953 TRACE [org.hibernate.event.def.DefaultFlushEntityEventListener] Updating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,015 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Updating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,015 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Dehydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,015 DEBUG [org.hibernate.cache.TransactionalCache] updating: com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [_put; id:3(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,Mon Aug 25 16:12:33 EST 2008,3,Mon Aug 25 16:12:33 EST 2008,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true)]
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _put; id:3(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,Mon Aug 25 16:12:33 EST 2008,3,Mon Aug 25 16:12:33 EST 2008,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true)
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner GlobalTransaction::10
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.Node] created child: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::10, lock=
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::10, lock=write owner=GlobalTransaction::10
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking method _put; id:3(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,Mon Aug 25 16:12:33 EST 2008,3,Mon Aug 25 16:12:33 EST 2008,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true) on cache.
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.TreeCache] _put(GlobalTransaction::10, "/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2", item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,Mon Aug 25 16:12:33 EST 2008,3,Mon Aug 25 16:12:33 EST 2008,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv])
| 2008-08-25 16:12:35,015 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 event=3 diff=1] to region at /_default_/
| 2008-08-25 16:12:35,125 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:35,171 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::10, lock=write owner=GlobalTransaction::10
| 2008-08-25 16:12:35,171 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock(): caller already owns lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 (caller=GlobalTransaction::10)
| 2008-08-25 16:12:35,171 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::10, lock=write owner=GlobalTransaction::10
| 2008-08-25 16:12:35,531 DEBUG [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding element /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for a node that doesn't exist yet. Process as an add.
| 2008-08-25 16:12:35,531 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] Adding node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 with 1 elements to eviction queue
| 2008-08-25 16:12:35,531 TRACE [org.jboss.cache.eviction.BaseEvictionAlgorithm] /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 added successfully to eviction queue
| 2008-08-25 16:12:35,531 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::10, lock=write owner=GlobalTransaction::10
| 2008-08-25 16:12:35,531 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock(): caller already owns lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 (caller=GlobalTransaction::10)
| 2008-08-25 16:12:35,531 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::10, lock=write owner=GlobalTransaction::10
| 2008-08-25 16:12:35,718 TRACE [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,718 TRACE [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,718 TRACE [org.hibernate.event.def.DefaultLoadEventListener] object not resolved in any cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,718 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Fetching entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,718 DEBUG [org.hibernate.loader.Loader] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8765], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8766], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8767], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,734 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:35,828 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:35,828 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:35,828 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:35,828 TRACE [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,828 TRACE [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,828 TRACE [org.hibernate.event.def.DefaultLoadEventListener] object not resolved in any cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,828 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Fetching entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,828 DEBUG [org.hibernate.loader.Loader] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,843 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8765], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,843 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,843 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,843 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8766], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,843 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8767], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,843 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:35,843 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:40,406 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method prepare; id:10(GlobalTransaction::10, [_put; id:3(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,Mon Aug 25 16:12:33 EST 2008,3,Mon Aug 25 16:12:33 EST 2008,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/TransactionMapping, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchDataMatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationSummary, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Transaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/User, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroupTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Menu, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentStatus, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserRole, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationErrorData, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserSecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CardType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Module, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Organisation, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/DomainRestriction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Domain, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/OrganisationSynonym, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CurrencyDescription, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/i18n/entity/Message, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/ModuleTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchData, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/TransactionMapping, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchDataMatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationSummary, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Transaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/User, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroupTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Menu, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentStatus, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserRole, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationErrorData, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserSecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CardType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Module, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Organisation, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/DomainRestriction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Domain, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/OrganisationSynonym, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CurrencyDescription, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/i18n/entity/Message, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/ModuleTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchData, true)], null, false)
| 2008-08-25 16:12:40,406 TRACE [org.jboss.cache.interceptors.CallInterceptor] Suppressing invocation of method prepare; id:10(GlobalTransaction::10, [_put; id:3(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,Mon Aug 25 16:12:33 EST 2008,3,Mon Aug 25 16:12:33 EST 2008,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/TransactionMapping, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchDataMatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationSummary, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Transaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/User, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroupTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Menu, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentStatus, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserRole, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationErrorData, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserSecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CardType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Module, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Organisation, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/DomainRestriction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Domain, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/OrganisationSynonym, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CurrencyDescription, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/i18n/entity/Message, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/ModuleTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchData, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/TransactionMapping, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchDataMatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationSummary, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Transaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/User, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroupTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/PeerOrgCode, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Menu, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentStatus, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserRole, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationErrorData, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/UserSecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CardType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Module, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/SecurityGroup, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Organisation, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/DomainRestriction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reservation/segment/entity/SegmentType, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/Domain, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/OrganisationSynonym, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/money/entity/CurrencyDescription, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/i18n/entity/Message, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/security/entity/ModuleTransaction, true), _remove; id:5(GlobalTransaction::10, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatchData, true)], null, false) on cache.
| 2008-08-25 16:12:40,468 TRACE [org.jboss.cache.TransactionEntry] releasing lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 (write owner=GlobalTransaction::10)
| 2008-08-25 16:12:41,312 TRACE [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,312 TRACE [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,312 TRACE [org.hibernate.event.def.DefaultLoadEventListener] object not resolved in any cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,312 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Fetching entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,312 DEBUG [org.hibernate.loader.Loader] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,312 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8765], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,312 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,312 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,328 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8766], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,328 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8767], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,328 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,328 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,328 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:41,359 TRACE [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 TRACE [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 TRACE [org.hibernate.event.def.DefaultLoadEventListener] object not resolved in any cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Fetching entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 DEBUG [org.hibernate.loader.Loader] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8765], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8766], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,359 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8767], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,375 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,375 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,484 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:41,500 TRACE [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 TRACE [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 TRACE [org.hibernate.event.def.DefaultLoadEventListener] object not resolved in any cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Fetching entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 DEBUG [org.hibernate.loader.Loader] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8765], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8766], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8767], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,500 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,625 TRACE [org.hibernate.engine.QueryParameters] named parameters: {batch=com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2}
| 2008-08-25 16:12:41,640 TRACE [org.hibernate.event.def.DefaultLoadEventListener] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,640 TRACE [org.hibernate.event.def.DefaultLoadEventListener] attempting to resolve: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,640 TRACE [org.hibernate.event.def.DefaultLoadEventListener] object not resolved in any cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,640 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Fetching entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,640 DEBUG [org.hibernate.loader.Loader] loading entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,656 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8765], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,656 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,656 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,656 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8766], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,656 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.security.entity.Organisation#3], EntityKey[com.synyati.spurwing.i18n.entity.Message#8767], null, null, EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:41,656 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:55,906 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:55,906 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:55,906 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:55,906 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:55,937 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [_get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true)]
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true)
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner GlobalTransaction::11
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking method _get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true) on cache.
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.TreeCache] _get("/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2", item, "true")
| 2008-08-25 16:12:55,937 DEBUG [org.hibernate.cache.TransactionalCache] caching: com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [_put; id:4(null, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,2008-08-25 16:12:33.0,3,2008-08-25 16:12:33.0,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true, 0)]
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _put; id:4(null, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,2008-08-25 16:12:33.0,3,2008-08-25 16:12:33.0,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true, 0)
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.Node] created child: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking method _put; id:4(null, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,2008-08-25 16:12:33.0,3,2008-08-25 16:12:33.0,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true, 0) on cache.
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.TreeCache] _put(null, "/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2", item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,2008-08-25 16:12:33.0,3,2008-08-25 16:12:33.0,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv])
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 event=3 diff=1] to region at /_default_/
| 2008-08-25 16:12:55,937 TRACE [org.jboss.cache.interceptors.UnlockInterceptor] releasing lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2: write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:12:55,937 DEBUG [org.hibernate.engine.TwoPhaseLoad] done materializing entity [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:13:15,093 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::12, lock=
| 2008-08-25 16:13:15,093 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::12, lock=write owner=GlobalTransaction::12
| 2008-08-25 16:13:15,140 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::12, lock=write owner=GlobalTransaction::12
| 2008-08-25 16:13:15,140 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock(): caller already owns lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 (caller=GlobalTransaction::12)
| 2008-08-25 16:13:15,140 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::12, lock=write owner=GlobalTransaction::12
| 2008-08-25 16:13:17,281 TRACE [org.jboss.cache.TransactionEntry] releasing lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 (write owner=GlobalTransaction::12)
| 2008-08-25 16:13:43,453 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::13, lock=
| 2008-08-25 16:13:43,453 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::13, lock=write owner=GlobalTransaction::13
| 2008-08-25 16:13:43,953 TRACE [org.jboss.cache.TransactionEntry] releasing lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 (write owner=GlobalTransaction::13)
| 2008-08-25 16:14:15,828 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 has been idle for 75344ms
| 2008-08-25 16:14:15,828 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 has been alive for 100297ms
| 2008-08-25 16:14:15,828 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 should not be evicted
| 2008-08-25 16:14:20,812 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 has been idle for 80328ms
| 2008-08-25 16:14:20,812 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 has been alive for 105281ms
| 2008-08-25 16:14:20,812 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 should not be evicted
| 2008-08-25 16:14:23,921 DEBUG [org.hibernate.loader.Loader] result row: EntityKey[com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:14:23,921 TRACE [org.hibernate.loader.Loader] Initializing object from ResultSet: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:14:23,921 TRACE [org.hibernate.persister.entity.AbstractEntityPersister] Hydrating entity: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:14:23,953 DEBUG [org.hibernate.engine.TwoPhaseLoad] resolving associations for [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:14:23,953 DEBUG [org.hibernate.engine.TwoPhaseLoad] adding entity to second-level cache: [com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [_get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true)]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true)
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner GlobalTransaction::14
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::14, lock=
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking method _get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true) on cache.
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.TreeCache] _get("/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2", item, "true")
| 2008-08-25 16:14:23,953 DEBUG [org.hibernate.cache.TransactionalCache] caching: com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [_put; id:4(null, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,2008-08-25 16:12:33.0,3,2008-08-25 16:12:33.0,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true, 0)]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _put; id:4(null, /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, CacheEntry(com.synyati.spurwing.reconciliation.entity.ReconciliationBatch)[1,true,2008-08-25 16:12:33.0,3,2008-08-25 16:12:33.0,3,CONTRIBUTED,2,3,2,null,0,null,BGD100_payer.csv], true, 0)
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::14], write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::14], write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.lock.IdentityLock] acquireWriteLock(): caller already owns lock for /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 (caller=Thread[http-127.0.0.1-8080-1,5,jboss])
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired WL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=Thread[http-127.0.0.1-8080-1,5,jboss], lock=read owners=[GlobalTransaction::14], write owner=Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner Thread[http-127.0.0.1-8080-1,5,jboss]
|
|
anonymous wrote :
| 2008-08-25 16:14:20,812 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 has been idle for 80328ms
| 2008-08-25 16:14:20,812 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 has been alive for 105281ms
| 2008-08-25 16:14:20,812 TRACE [org.jboss.cache.eviction.LRUAlgorithm] Node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 should not be evicted
| ...
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Invoking EvictionInterceptor
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Updating node/element events with no tx
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.eviction.RegionManager] getRegion(): user-specified region not found: / will use the global default region
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.eviction.RegionManager] getRegion(): user-specified region not found: / will use the global default region
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Adding event EvictedEN[fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#3 event=2 diff=0] to region at /_default_/
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished updating node
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.EvictionInterceptor] Finished invoking EvictionInterceptor
| 2008-08-25 16:14:23,953 DEBUG [org.hibernate.cache.TransactionalCache] item already cached: com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#3
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.TxInterceptor] (null) call on method [_get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true)]
| 2008-08-25 16:14:23,953 DEBUG [org.jboss.cache.interceptors.TxInterceptor] local transaction exists - registering global tx if not present for Thread[http-127.0.0.1-8080-1,5,jboss]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.TxInterceptor] Associated gtx in txTable is GlobalTransaction::14
| 2008-08-25 16:14:23,953 DEBUG [org.jboss.cache.interceptors.TxInterceptor] Transaction TransactionImple < ac, BasicAction: -3f57fe3d:1215:48b24c98:263 status: ActionStatus.RUNNING > is already registered.
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] PessimisticLockInterceptor invoked for method _get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true)
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.PessimisticLockInterceptor] Attempting to lock node /spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2 for owner GlobalTransaction::14
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquiring RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::14, lock=
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.Node] acquired RL: fqn=/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, caller=GlobalTransaction::14, lock=read owners=[GlobalTransaction::14]
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.CallInterceptor] Invoking method _get; id:26(/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2, item, true) on cache.
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.TreeCache] _get("/spurwing_ear,spurwing-ejb_jar,SpurwingEM/com/synyati/spurwing/reconciliation/entity/ReconciliationBatch/com.synyati.spurwing.reconciliation.entity.ReconciliationBatch#2", item, "true")
| 2008-08-25 16:14:23,953 TRACE [org.jboss.cache.interceptors.EvictionInterceptor
View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4172442#4172442
Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4172442
More information about the jboss-user
mailing list