[jboss-user] [JBossCache] - Re: Read Locks not released broken between 1.4.1.beta and 1.
youngm
do-not-reply at jboss.com
Mon Jan 29 12:02:59 EST 2007
It happens consistently with 1.4.1.GA and never happenned with 1.4.1.beta. Here is a log with both Hibernate and JBossCache on trace. Below this I've included a log of hibernate and jbossCache on trace with everything the same except using 1.4.1.beta instead of 1.4.1.GA.
I would think it was something wrong with how I was setting up my transaction lookups between hibernate, spring, and JBossCache except it appears to work perfectly with 1.4.1.beta and to create the problem I simply have to swap out the jar.
I wish I could provide a unit test but it would be quite the task bundling all these frameworks and and the integration of them into a unit test. I could provide a war for you if that would help To duplicate you would just have to start the server.
Here are the logs.
JBossCache 1.4.1.GA
| 09:46:51,609 DEBUG SessionImpl: opened session at timestamp: 11700892115
| 09:46:51,609 DEBUG JDBCContext: TransactionFactory reported no active transaction; Synchronization not registered
| 09:46:51,609 DEBUG AbstractEntityManagerImpl: Looking for a JTA transaction to join
| 09:46:51,625 DEBUG JDBCContext: successfully registered Synchronization
| 09:46:51,625 DEBUG AbstractEntityManagerImpl: Adding flush() and close() synchronization
| 09:46:51,671 DEBUG QueryPlanCache: unable to locate HQL query plan in cache; generating (select e from org.lds.stack.petstore.model.ApplicationProperty e)
| 09:46:51,671 DEBUG QueryTranslatorImpl: parse() - HQL: select e from org.lds.stack.petstore.model.ApplicationProperty e
| 09:46:51,671 DEBUG AST: --- HQL AST ---
| \-[QUERY] 'query'
| \-[SELECT_FROM] 'SELECT_FROM'
| +-[FROM] 'from'
| | \-[RANGE] 'RANGE'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[DOT] '.'
| | | | | +-[DOT] '.'
| | | | | | +-[DOT] '.'
| | | | | | | +-[IDENT] 'org'
| | | | | | | \-[IDENT] 'lds'
| | | | | | \-[IDENT] 'stack'
| | | | | \-[IDENT] 'petstore'
| | | | \-[IDENT] 'model'
| | | \-[IDENT] 'ApplicationProperty'
| | \-[ALIAS] 'e'
| \-[SELECT] 'select'
| \-[IDENT] 'e'
|
| 09:46:51,703 DEBUG ErrorCounter: throwQueryException() : no errors
| 09:46:51,703 DEBUG HqlSqlBaseWalker: select << begin [level=1, statement=select]
| 09:46:51,703 DEBUG FromElement: FromClause{level=1} : org.lds.stack.petstore.model.ApplicationProperty (e) -> applicatio0_
| 09:46:51,703 DEBUG FromReferenceNode: Resolved : e -> applicatio0_.name
| 09:46:51,703 DEBUG HqlSqlBaseWalker: select : finishing up [level=1, statement=select]
| 09:46:51,703 DEBUG HqlSqlWalker: processQuery() : ( SELECT ( {select clause} applicatio0_.name ) ( FromClause{level=1} APP_PROPERTIES applicatio0_ ) )
| 09:46:51,703 DEBUG JoinProcessor: Using FROM fragment [APP_PROPERTIES applicatio0_]
| 09:46:51,703 DEBUG HqlSqlBaseWalker: select >> end [level=1, statement=select]
| 09:46:51,703 DEBUG AST: --- SQL AST ---
| \-[SELECT] QueryNode: 'SELECT' querySpaces (APP_PROPERTIES)
| +-[SELECT_CLAUSE] SelectClause: '{select clause}'
| | +-[ALIAS_REF] IdentNode: 'applicatio0_.name as name0_' {alias=e, className=org.lds.stack.petstore.model.ApplicationProperty, tableAlias=applicatio0_}
| | \-[SQL_TOKEN] SqlFragment: 'applicatio0_.prop_value as prop2_0_'
| \-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[e], fromElementByTableAlias=[applicatio0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: 'APP_PROPERTIES applicatio0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=e,role=null,tableName=APP_PROPERTIES,tableAlias=applicatio0_,origin=null,colums={,className=org.lds.stack.petstore.model.ApplicationProperty}}
|
| 09:46:51,703 DEBUG ErrorCounter: throwQueryException() : no errors
| 09:46:51,703 DEBUG QueryTranslatorImpl: HQL: select e from org.lds.stack.petstore.model.ApplicationProperty e
| 09:46:51,703 DEBUG QueryTranslatorImpl: SQL: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_
| 09:46:51,703 DEBUG ErrorCounter: throwQueryException() : no errors
| 09:46:51,703 DEBUG HQLQueryPlan: HQL param location recognition took 0 mills (select e from org.lds.stack.petstore.model.ApplicationProperty e)
| 09:46:51,703 DEBUG QueryPlanCache: located HQL query plan in cache (select e from org.lds.stack.petstore.model.ApplicationProperty e)
| 09:46:51,703 DEBUG HQLQueryPlan: find: select e from org.lds.stack.petstore.model.ApplicationProperty e
| 09:46:51,703 DEBUG QueryParameters: named parameters: {}
| 09:46:51,718 DEBUG StandardQueryCache: checking cached query results in region: org.hibernate.cache.StandardQueryCache
| 09:46:51,718 DEBUG TxInterceptor: (null) call on method [_get; id:26(/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}, item, true)]
| 09:46:51,718 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _get; id:26(/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}, item, true)
| 09:46:51,718 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {} for owner Thread[main,5,main]
| 09:46:51,718 DEBUG Node: acquiring RL: fqn=/, caller=Thread[main,5,main], lock=<unlocked>
| 09:46:51,718 DEBUG Node: acquired RL: fqn=/, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
| 09:46:51,734 DEBUG PessimisticLockInterceptor: failed to find or create child org of node /
| 09:46:51,734 DEBUG CallInterceptor: Invoking method _get; id:26(/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}, item, true) on cache.
| 09:46:51,734 DEBUG TreeCache: _get("/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}", item, "true")
| 09:46:51,734 DEBUG EvictionInterceptor: Invoking EvictionInterceptor
| 09:46:51,734 DEBUG EvictionInterceptor: Updating node/element events with no tx
| 09:46:51,734 DEBUG EvictionInterceptor: No event added. Element does not exist
| 09:46:51,734 DEBUG EvictionInterceptor: No node modifications
| 09:46:51,734 DEBUG EvictionInterceptor: Finished invoking EvictionInterceptor
| 09:46:51,734 DEBUG UnlockInterceptor: Attempting to release locks on current thread. Lock table is {Thread[main,5,main]=[read owners=[Thread[main,5,main]]]}
| 09:46:51,734 DEBUG UnlockInterceptor: releasing lock for /: read owners=[Thread[main,5,main]]
| 09:46:51,734 DEBUG StandardQueryCache: query results were not found in cache
| 09:46:51,734 DEBUG AbstractBatcher: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 09:46:51,734 DEBUG ConnectionManager: opening JDBC connection
| 09:46:51,734 DEBUG SQL:
| /* select
| e
| from
| org.lds.stack.petstore.model.ApplicationProperty e */ select
| applicatio0_.name as name0_,
| applicatio0_.prop_value as prop2_0_
| from
| APP_PROPERTIES applicatio0_
| Hibernate:
| /* select
| e
| from
| org.lds.stack.petstore.model.ApplicationProperty e */ select
| applicatio0_.name as name0_,
| applicatio0_.prop_value as prop2_0_
| from
| APP_PROPERTIES applicatio0_
| 09:46:51,734 DEBUG AbstractBatcher: preparing statement
| 09:46:51,765 DEBUG AbstractBatcher: about to open ResultSet (open ResultSets: 0, globally: 0)
| 09:46:51,765 DEBUG Loader: processing result set
| 09:46:51,765 DEBUG Loader: result set row: 0
| 09:46:51,765 DEBUG StringType: returning 'ldap.url' as column: name0_
| 09:46:51,781 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:46:51,781 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:46:51,781 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:46:51,781 DEBUG StringType: returning 'ldap://10.51.95.193' as column: prop2_0_
| 09:46:51,781 DEBUG Loader: result set row: 1
| 09:46:51,781 DEBUG StringType: returning 'ldap.manager.dn' as column: name0_
| 09:46:51,781 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:46:51,781 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:46:51,781 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:46:51,781 DEBUG StringType: returning 'cn=hansenbk,ou=People,o=WH' as column: prop2_0_
| 09:46:51,781 DEBUG Loader: result set row: 2
| 09:46:51,781 DEBUG StringType: returning 'ldap.manager.password' as column: name0_
| 09:46:51,781 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:46:51,781 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:46:51,781 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:46:51,781 DEBUG StringType: returning 'password' as column: prop2_0_
| 09:46:51,781 DEBUG Loader: result set row: 3
| 09:46:51,781 DEBUG StringType: returning 'smtp.host.name' as column: name0_
| 09:46:51,781 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#smtp.host.name]
| 09:46:51,781 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#smtp.host.name]
| 09:46:51,781 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#smtp.host.name]
| 09:46:51,781 DEBUG StringType: returning 'smtp-relay.wh.ldsglobal.net' as column: prop2_0_
| 09:46:51,796 DEBUG Loader: done processing result set (4 rows)
| 09:46:51,796 DEBUG AbstractBatcher: about to close ResultSet (open ResultSets: 1, globally: 1)
| 09:46:51,796 DEBUG AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 09:46:51,796 DEBUG AbstractBatcher: closing statement
| 09:46:51,796 DEBUG ConnectionManager: aggressively releasing JDBC connection
| 09:46:51,796 DEBUG ConnectionManager: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 09:46:51,796 DEBUG Loader: total objects hydrated: 4
| 09:46:51,796 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:46:51,796 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:46:51,812 DEBUG TxInterceptor: (null) call on method [_get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, true)]
| 09:46:51,812 DEBUG TxInterceptor: local transaction exists - registering global tx if not present for Thread[main,5,main]
| 09:46:51,812 DEBUG TxInterceptor: Associated gtx in txTable is null
| 09:46:51,812 DEBUG TreeCache: created new GTX: GlobalTransaction:<null>:1, local TX=bb14:38:0:01ddc3011eba1aaba6...d93001:
| 09:46:51,812 DEBUG TxInterceptor: Registering sync handler for tx bb14:38:0:01ddc3011eba1aaba6...d93001:, gtx GlobalTransaction:<null>:1
| 09:46:51,812 DEBUG TxInterceptor: registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:1, tx=bb14:38:0:01ddc3011eba1aaba6...d93001:))
| 09:46:51,812 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, true)
| 09:46:51,812 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url for owner GlobalTransaction:<null>:1
| 09:46:51,875 DEBUG Node: acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=<unlocked>
| 09:46:51,875 DEBUG Node: acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,875 DEBUG PessimisticLockInterceptor: failed to find or create child org of node /
| 09:46:51,875 DEBUG CallInterceptor: Invoking method _get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, true) on cache.
| 09:46:51,875 DEBUG TreeCache: _get("/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url", item, "true")
| 09:46:51,875 DEBUG EvictionInterceptor: Invoking EvictionInterceptor
| 09:46:51,875 DEBUG EvictionInterceptor: Updating node/element events with no tx
| 09:46:51,875 DEBUG EvictionInterceptor: No event added. Element does not exist
| 09:46:51,875 DEBUG EvictionInterceptor: No node modifications
| 09:46:51,875 DEBUG EvictionInterceptor: Finished invoking EvictionInterceptor
| 09:46:51,875 DEBUG TransactionalCache: caching: org.lds.stack.petstore.model.ApplicationProperty#ldap.url
| 09:46:51,875 DEBUG TxInterceptor: (null) call on method [_put; id:4(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=ldap://10.51.95.193, _version=null, _lazyPropertiesUnfetched=true}, true, 0)]
| 09:46:51,875 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _put; id:4(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=ldap://10.51.95.193, _version=null, _lazyPropertiesUnfetched=true}, true, 0)
| 09:46:51,875 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url for owner Thread[main,5,main]
| 09:46:51,875 DEBUG Node: acquiring WL: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,875 ERROR IdentityLock: write lock for / could not be acquired after 0 ms. Locks: Read lock owners: [GlobalTransaction:<null>:1]
| Write lock owner: null
| (caller=Thread[main,5,main], lock info: read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
| 09:46:51,875 DEBUG Node: failure acquiring lock: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
| 09:46:51,875 DEBUG UnlockInterceptor: Attempting to release locks on current thread. Lock table is {}
| 09:46:51,875 INFO TxInterceptor: There was a problem handling this request
| org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
| at org.jboss.cache.Node.acquire(Node.java:500)
| at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:342)
| at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:287)
| at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:172)
| at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
| at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:32)
| at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
| at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:364)
| at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
| at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
| at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:157)
| at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5710)
| at org.jboss.cache.TreeCache.putFailFast(TreeCache.java:3747)
| at org.hibernate.cache.TreeCache.put(TreeCache.java:74)
| at org.hibernate.cache.TransactionalCache.put(TransactionalCache.java:58)
| at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:156)
| at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:842)
| at org.hibernate.loader.Loader.doQuery(Loader.java:717)
| at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
| at org.hibernate.loader.Loader.doList(Loader.java:2211)
| at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2127)
| at org.hibernate.loader.Loader.list(Loader.java:2087)
| at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:375)
| at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
| at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
| at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
| at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
| at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:64)
| at org.lds.stack.serviceproxy.jpa.hibernate.FindAllFindExecutor.executeQuery(FindAllFindExecutor.java:31)
| at org.lds.stack.serviceproxy.jpa.hibernate.EntityFindExecutor.executeQuery(EntityFindExecutor.java:15)
| at org.lds.stack.serviceproxy.jpa.FindInterceptor$1.doInJpa(FindInterceptor.java:43)
| at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:191)
| at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:154)
| at org.lds.stack.serviceproxy.jpa.FindInterceptor.invoke(FindInterceptor.java:39)
| at org.lds.stack.serviceproxy.ServiceProxyCglibInterceptor.intercept(ServiceProxyCglibInterceptor.java:48)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.findAllProperties(<generated>)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService.entrySet(AbstractApplicationPropertyService.java:194)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.CGLIB$entrySet$11(<generated>)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c$$FastClassByCGLIB$$299f1a43.invoke(<generated>)
| at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:187)
| at org.lds.stack.serviceproxy.ServiceProxyCglibInterceptor.intercept(ServiceProxyCglibInterceptor.java:43)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.entrySet(<generated>)
| at java.util.AbstractMap.size(AbstractMap.java:68)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.CGLIB$size$25(<generated>)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c$$FastClassByCGLIB$$299f1a43.invoke(<generated>)
| at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:187)
| at org.lds.stack.serviceproxy.ServiceProxyCglibInterceptor.intercept(ServiceProxyCglibInterceptor.java:43)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.size(<generated>)
| at $java.util.AbstractMap$$FastClassByCGLIB$$6ee8901a.invoke(<generated>)
| at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:163)
| at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:675)
| at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
| at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
| at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
| at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:616)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$46274020.size(<generated>)
| at org.springframework.beans.TypeConverterDelegate.convertToTypedMap(TypeConverterDelegate.java:363)
| at org.springframework.beans.TypeConverterDelegate.convertIfNecessary(TypeConverterDelegate.java:205)
| at org.springframework.beans.TypeConverterDelegate.convertIfNecessary(TypeConverterDelegate.java:139)
| at org.springframework.beans.BeanWrapperImpl.setPropertyValue(BeanWrapperImpl.java:772)
| at org.springframework.beans.BeanWrapperImpl.setPropertyValue(BeanWrapperImpl.java:606)
| at org.springframework.beans.AbstractPropertyAccessor.setPropertyValue(AbstractPropertyAccessor.java:49)
| at org.springframework.beans.AbstractPropertyAccessor.setPropertyValues(AbstractPropertyAccessor.java:74)
| at org.springframework.beans.AbstractPropertyAccessor.setPropertyValues(AbstractPropertyAccessor.java:57)
| at org.springframework.beans.factory.support.AbstractBeanFactory.applyPropertyValues(AbstractBeanFactory.java:840)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1026)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:809)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
| at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:250)
| at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:141)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:247)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:161)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:245)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:124)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveManagedMap(BeanDefinitionValueResolver.java:298)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:136)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1019)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:809)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
| at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:250)
| at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:141)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:247)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:161)
| at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:273)
| at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:346)
| at org.springframework.web.context.support.AbstractRefreshableWebApplicationContext.refresh(AbstractRefreshableWebApplicationContext.java:156)
| at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
| at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
| at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
| at java.lang.reflect.Method.invoke(Method.java:585)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1160)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1122)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1085)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:429)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveInnerBeanDefinition(BeanDefinitionValueResolver.java:197)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:107)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1019)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:809)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
| at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:250)
| at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:141)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:247)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:161)
| at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:642)
| at org.springframework.beans.factory.access.SingletonBeanFactoryLocator.useBeanFactory(SingletonBeanFactoryLocator.java:393)
| at org.lds.stack.spring.context.WebContextSingletonBeanFactoryLocator.useBeanFactory(WebContextSingletonBeanFactoryLocator.java:38)
| at org.lds.stack.spring.context.BootstrapContextLoader.createWebApplicationContext(BootstrapContextLoader.java:29)
| at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:184)
| at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:49)
| at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3763)
| at org.apache.catalina.core.StandardContext.start(StandardContext.java:4211)
| at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1013)
| at org.apache.catalina.core.StandardHost.start(StandardHost.java:718)
| at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1013)
| at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:442)
| at org.apache.catalina.core.StandardService.start(StandardService.java:450)
| at org.apache.catalina.core.StandardServer.start(StandardServer.java:709)
| at org.apache.catalina.startup.Catalina.start(Catalina.java:551)
| at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
| at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
| at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
| at java.lang.reflect.Method.invoke(Method.java:585)
| at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:294)
| at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:432)
| Caused by: org.jboss.cache.lock.TimeoutException: write lock for / could not be acquired after 0 ms. Locks: Read lock owners: [GlobalTransaction:<null>:1]
| Write lock owner: null
| (caller=Thread[main,5,main], lock info: read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
| at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:206)
| at org.jboss.cache.Node.acquireWriteLock(Node.java:529)
| at org.jboss.cache.Node.acquire(Node.java:476)
| ... 123 more
| 09:46:51,875 DEBUG TreeCache: ignoring write lock acquisition failure
| 09:46:51,875 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:46:51,875 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:46:51,875 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:46:51,875 DEBUG TxInterceptor: (null) call on method [_get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn, item, true)]
| 09:46:51,875 DEBUG TxInterceptor: local transaction exists - registering global tx if not present for Thread[main,5,main]
| 09:46:51,875 DEBUG TxInterceptor: Associated gtx in txTable is GlobalTransaction:<null>:1
| 09:46:51,875 DEBUG TxInterceptor: Transaction bb14:38:0:01ddc3011eba1aaba6...d93001: is already registered.
| 09:46:51,875 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn, item, true)
| 09:46:51,875 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn for owner GlobalTransaction:<null>:1
| 09:46:51,875 DEBUG Node: acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,875 DEBUG IdentityLock: acquireReadLock(): caller GlobalTransaction:<null>:1 already owns lock for /
| 09:46:51,875 DEBUG Node: acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,875 DEBUG PessimisticLockInterceptor: failed to find or create child org of node /
| 09:46:51,875 DEBUG CallInterceptor: Invoking method _get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn, item, true) on cache.
| 09:46:51,875 DEBUG TreeCache: _get("/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn", item, "true")
| 09:46:51,875 DEBUG EvictionInterceptor: Invoking EvictionInterceptor
| 09:46:51,875 DEBUG EvictionInterceptor: Updating node/element events with no tx
| 09:46:51,875 DEBUG EvictionInterceptor: No event added. Element does not exist
| 09:46:51,875 DEBUG EvictionInterceptor: No node modifications
| 09:46:51,875 DEBUG EvictionInterceptor: Finished invoking EvictionInterceptor
| 09:46:51,875 DEBUG TransactionalCache: caching: org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn
| 09:46:51,875 DEBUG TxInterceptor: (null) call on method [_put; id:4(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=cn=hansenbk,ou=People,o=WH, _version=null, _lazyPropertiesUnfetched=true}, true, 0)]
| 09:46:51,875 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _put; id:4(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=cn=hansenbk,ou=People,o=WH, _version=null, _lazyPropertiesUnfetched=true}, true, 0)
| 09:46:51,875 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn for owner Thread[main,5,main]
| 09:46:51,875 DEBUG Node: acquiring WL: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,875 ERROR IdentityLock: write lock for / could not be acquired after 0 ms. Locks: Read lock owners: [GlobalTransaction:<null>:1]
| Write lock owner: null
| (caller=Thread[main,5,main], lock info: read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
| 09:46:51,875 DEBUG Node: failure acquiring lock: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
| 09:46:51,875 DEBUG UnlockInterceptor: Attempting to release locks on current thread. Lock table is {}
| 09:46:51,875 INFO TxInterceptor: There was a problem handling this request
| org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
| at org.jboss.cache.Node.acquire(Node.java:500)
| at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:342)
| at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:287)
| at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:172)
| at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
| at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:32)
| at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
| at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:364)
| at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:160)
| at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
| at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:157)
| at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5710)
| at org.jboss.cache.TreeCache.putFailFast(TreeCache.java:3747)
| at org.hibernate.cache.TreeCache.put(TreeCache.java:74)
| at org.hibernate.cache.TransactionalCache.put(TransactionalCache.java:58)
| at org.hibernate.engine.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:156)
| at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:842)
| at org.hibernate.loader.Loader.doQuery(Loader.java:717)
| at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
| at org.hibernate.loader.Loader.doList(Loader.java:2211)
| at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2127)
| at org.hibernate.loader.Loader.list(Loader.java:2087)
| at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:375)
| at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
| at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
| at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
| at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
| at org.hibernate.ejb.QueryImpl.getResultList(QueryImpl.java:64)
| at org.lds.stack.serviceproxy.jpa.hibernate.FindAllFindExecutor.executeQuery(FindAllFindExecutor.java:31)
| at org.lds.stack.serviceproxy.jpa.hibernate.EntityFindExecutor.executeQuery(EntityFindExecutor.java:15)
| at org.lds.stack.serviceproxy.jpa.FindInterceptor$1.doInJpa(FindInterceptor.java:43)
| at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:191)
| at org.springframework.orm.jpa.JpaTemplate.execute(JpaTemplate.java:154)
| at org.lds.stack.serviceproxy.jpa.FindInterceptor.invoke(FindInterceptor.java:39)
| at org.lds.stack.serviceproxy.ServiceProxyCglibInterceptor.intercept(ServiceProxyCglibInterceptor.java:48)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.findAllProperties(<generated>)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService.entrySet(AbstractApplicationPropertyService.java:194)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.CGLIB$entrySet$11(<generated>)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c$$FastClassByCGLIB$$299f1a43.invoke(<generated>)
| at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:187)
| at org.lds.stack.serviceproxy.ServiceProxyCglibInterceptor.intercept(ServiceProxyCglibInterceptor.java:43)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.entrySet(<generated>)
| at java.util.AbstractMap.size(AbstractMap.java:68)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.CGLIB$size$25(<generated>)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c$$FastClassByCGLIB$$299f1a43.invoke(<generated>)
| at net.sf.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:187)
| at org.lds.stack.serviceproxy.ServiceProxyCglibInterceptor.intercept(ServiceProxyCglibInterceptor.java:43)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$7beb109c.size(<generated>)
| at $java.util.AbstractMap$$FastClassByCGLIB$$6ee8901a.invoke(<generated>)
| at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:163)
| at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:675)
| at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:154)
| at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:107)
| at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:176)
| at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:616)
| at org.lds.stack.petstore.service.AbstractApplicationPropertyService$$EnhancerByCGLIB$$46274020.size(<generated>)
| at org.springframework.beans.TypeConverterDelegate.convertToTypedMap(TypeConverterDelegate.java:363)
| at org.springframework.beans.TypeConverterDelegate.convertIfNecessary(TypeConverterDelegate.java:205)
| at org.springframework.beans.TypeConverterDelegate.convertIfNecessary(TypeConverterDelegate.java:139)
| at org.springframework.beans.BeanWrapperImpl.setPropertyValue(BeanWrapperImpl.java:772)
| at org.springframework.beans.BeanWrapperImpl.setPropertyValue(BeanWrapperImpl.java:606)
| at org.springframework.beans.AbstractPropertyAccessor.setPropertyValue(AbstractPropertyAccessor.java:49)
| at org.springframework.beans.AbstractPropertyAccessor.setPropertyValues(AbstractPropertyAccessor.java:74)
| at org.springframework.beans.AbstractPropertyAccessor.setPropertyValues(AbstractPropertyAccessor.java:57)
| at org.springframework.beans.factory.support.AbstractBeanFactory.applyPropertyValues(AbstractBeanFactory.java:840)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1026)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:809)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
| at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:250)
| at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:141)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:247)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:161)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveReference(BeanDefinitionValueResolver.java:245)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:124)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveManagedMap(BeanDefinitionValueResolver.java:298)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:136)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1019)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:809)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
| at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:250)
| at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:141)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:247)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:161)
| at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:273)
| at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:346)
| at org.springframework.web.context.support.AbstractRefreshableWebApplicationContext.refresh(AbstractRefreshableWebApplicationContext.java:156)
| at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
| at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
| at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
| at java.lang.reflect.Method.invoke(Method.java:585)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeCustomInitMethod(AbstractAutowireCapableBeanFactory.java:1160)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.invokeInitMethods(AbstractAutowireCapableBeanFactory.java:1122)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1085)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:429)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveInnerBeanDefinition(BeanDefinitionValueResolver.java:197)
| at org.springframework.beans.factory.support.BeanDefinitionValueResolver.resolveValueIfNecessary(BeanDefinitionValueResolver.java:107)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyPropertyValues(AbstractAutowireCapableBeanFactory.java:1019)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:809)
| at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:425)
| at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:250)
| at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:141)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:247)
| at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:161)
| at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:642)
| at org.springframework.beans.factory.access.SingletonBeanFactoryLocator.useBeanFactory(SingletonBeanFactoryLocator.java:393)
| at org.lds.stack.spring.context.WebContextSingletonBeanFactoryLocator.useBeanFactory(WebContextSingletonBeanFactoryLocator.java:38)
| at org.lds.stack.spring.context.BootstrapContextLoader.createWebApplicationContext(BootstrapContextLoader.java:29)
| at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:184)
| at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:49)
| at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:3763)
| at org.apache.catalina.core.StandardContext.start(StandardContext.java:4211)
| at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1013)
| at org.apache.catalina.core.StandardHost.start(StandardHost.java:718)
| at org.apache.catalina.core.ContainerBase.start(ContainerBase.java:1013)
| at org.apache.catalina.core.StandardEngine.start(StandardEngine.java:442)
| at org.apache.catalina.core.StandardService.start(StandardService.java:450)
| at org.apache.catalina.core.StandardServer.start(StandardServer.java:709)
| at org.apache.catalina.startup.Catalina.start(Catalina.java:551)
| at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
| at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
| at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
| at java.lang.reflect.Method.invoke(Method.java:585)
| at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:294)
| at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:432)
| Caused by: org.jboss.cache.lock.TimeoutException: write lock for / could not be acquired after 0 ms. Locks: Read lock owners: [GlobalTransaction:<null>:1]
| Write lock owner: null
| (caller=Thread[main,5,main], lock info: read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
| at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:206)
| at org.jboss.cache.Node.acquireWriteLock(Node.java:529)
| at org.jboss.cache.Node.acquire(Node.java:476)
| ... 123 more
| 09:46:51,890 DEBUG TreeCache: ignoring write lock acquisition failure
| 09:46:51,890 DEBUG TwoPhaseLoad: done materializing entity [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:46:51,890 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:46:51,890 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:46:51,890 DEBUG TxInterceptor: (null) call on method [_get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password, item, true)]
| 09:46:51,890 DEBUG TxInterceptor: local transaction exists - registering global tx if not present for Thread[main,5,main]
| 09:46:51,890 DEBUG TxInterceptor: Associated gtx in txTable is GlobalTransaction:<null>:1
| 09:46:51,890 DEBUG TxInterceptor: Transaction bb14:38:0:01ddc3011eba1aaba6...d93001: is already registered.
| 09:46:51,890 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password, item, true)
| 09:46:51,890 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password for owner GlobalTransaction:<null>:1
| 09:46:51,890 DEBUG Node: acquiring RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,890 DEBUG IdentityLock: acquireReadLock(): caller GlobalTransaction:<null>:1 already owns lock for /
| 09:46:51,890 DEBUG Node: acquired RL: fqn=/, caller=GlobalTransaction:<null>:1, lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,890 DEBUG PessimisticLockInterceptor: failed to find or create child org of node /
| 09:46:51,890 DEBUG CallInterceptor: Invoking method _get; id:26(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password, item, true) on cache.
| 09:46:51,890 DEBUG TreeCache: _get("/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password", item, "true")
| 09:46:51,890 DEBUG EvictionInterceptor: Invoking EvictionInterceptor
| 09:46:51,890 DEBUG EvictionInterceptor: Updating node/element events with no tx
| 09:46:51,890 DEBUG EvictionInterceptor: No event added. Element does not exist
| 09:46:51,890 DEBUG EvictionInterceptor: No node modifications
| 09:46:51,890 DEBUG EvictionInterceptor: Finished invoking EvictionInterceptor
| 09:46:51,890 DEBUG TransactionalCache: caching: org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password
| 09:46:51,890 DEBUG TxInterceptor: (null) call on method [_put; id:4(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=password, _version=null, _lazyPropertiesUnfetched=true}, true, 0)]
| 09:46:51,890 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _put; id:4(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=password, _version=null, _lazyPropertiesUnfetched=true}, true, 0)
| 09:46:51,890 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password for owner Thread[main,5,main]
| 09:46:51,890 DEBUG Node: acquiring WL: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1]
| 09:46:51,890 ERROR IdentityLock: write lock for / could not be acquired after 0 ms. Locks: Read lock owners: [GlobalTransaction:<null>:1]
| Write lock owner: null
| (caller=Thread[main,5,main], lock info: read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0))
| 09:46:51,890 DEBUG Node: failure acquiring lock: fqn=/, caller=Thread[main,5,main], lock=read owners=[GlobalTransaction:<null>:1] (activeReaders=1, activeWriter=null, waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
| 09:46:51,890 DEBUG UnlockInterceptor: Attempting to release locks on current thread. Lock table is {}
| 09:46:51,890 INFO TxInterceptor: There was a problem handling this request
|
JBossCache 1.4.1.beta
| 09:55:31,593 DEBUG SessionImpl: opened session at timestamp: 11700897315
| 09:55:31,593 DEBUG JDBCContext: TransactionFactory reported no active transaction; Synchronization not registered
| 09:55:31,593 DEBUG AbstractEntityManagerImpl: Looking for a JTA transaction to join
| 09:55:31,593 DEBUG JDBCContext: successfully registered Synchronization
| 09:55:31,593 DEBUG AbstractEntityManagerImpl: Adding flush() and close() synchronization
| 09:55:31,640 DEBUG QueryPlanCache: unable to locate HQL query plan in cache; generating (select e from org.lds.stack.petstore.model.ApplicationProperty e)
| 09:55:31,640 DEBUG QueryTranslatorImpl: parse() - HQL: select e from org.lds.stack.petstore.model.ApplicationProperty e
| 09:55:31,640 DEBUG AST: --- HQL AST ---
| \-[QUERY] 'query'
| \-[SELECT_FROM] 'SELECT_FROM'
| +-[FROM] 'from'
| | \-[RANGE] 'RANGE'
| | +-[DOT] '.'
| | | +-[DOT] '.'
| | | | +-[DOT] '.'
| | | | | +-[DOT] '.'
| | | | | | +-[DOT] '.'
| | | | | | | +-[IDENT] 'org'
| | | | | | | \-[IDENT] 'lds'
| | | | | | \-[IDENT] 'stack'
| | | | | \-[IDENT] 'petstore'
| | | | \-[IDENT] 'model'
| | | \-[IDENT] 'ApplicationProperty'
| | \-[ALIAS] 'e'
| \-[SELECT] 'select'
| \-[IDENT] 'e'
|
| 09:55:31,640 DEBUG ErrorCounter: throwQueryException() : no errors
| 09:55:31,640 DEBUG HqlSqlBaseWalker: select << begin [level=1, statement=select]
| 09:55:31,640 DEBUG FromElement: FromClause{level=1} : org.lds.stack.petstore.model.ApplicationProperty (e) -> applicatio0_
| 09:55:31,640 DEBUG FromReferenceNode: Resolved : e -> applicatio0_.name
| 09:55:31,640 DEBUG HqlSqlBaseWalker: select : finishing up [level=1, statement=select]
| 09:55:31,640 DEBUG HqlSqlWalker: processQuery() : ( SELECT ( {select clause} applicatio0_.name ) ( FromClause{level=1} APP_PROPERTIES applicatio0_ ) )
| 09:55:31,640 DEBUG JoinProcessor: Using FROM fragment [APP_PROPERTIES applicatio0_]
| 09:55:31,640 DEBUG HqlSqlBaseWalker: select >> end [level=1, statement=select]
| 09:55:31,640 DEBUG AST: --- SQL AST ---
| \-[SELECT] QueryNode: 'SELECT' querySpaces (APP_PROPERTIES)
| +-[SELECT_CLAUSE] SelectClause: '{select clause}'
| | +-[ALIAS_REF] IdentNode: 'applicatio0_.name as name0_' {alias=e, className=org.lds.stack.petstore.model.ApplicationProperty, tableAlias=applicatio0_}
| | \-[SQL_TOKEN] SqlFragment: 'applicatio0_.prop_value as prop2_0_'
| \-[FROM] FromClause: 'from' FromClause{level=1, fromElementCounter=1, fromElements=1, fromElementByClassAlias=[e], fromElementByTableAlias=[applicatio0_], fromElementsByPath=[], collectionJoinFromElementsByPath=[], impliedElements=[]}
| \-[FROM_FRAGMENT] FromElement: 'APP_PROPERTIES applicatio0_' FromElement{explicit,not a collection join,not a fetch join,fetch non-lazy properties,classAlias=e,role=null,tableName=APP_PROPERTIES,tableAlias=applicatio0_,origin=null,colums={,className=org.lds.stack.petstore.model.ApplicationProperty}}
|
| 09:55:31,640 DEBUG ErrorCounter: throwQueryException() : no errors
| 09:55:31,640 DEBUG QueryTranslatorImpl: HQL: select e from org.lds.stack.petstore.model.ApplicationProperty e
| 09:55:31,640 DEBUG QueryTranslatorImpl: SQL: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_
| 09:55:31,640 DEBUG ErrorCounter: throwQueryException() : no errors
| 09:55:31,640 DEBUG HQLQueryPlan: HQL param location recognition took 0 mills (select e from org.lds.stack.petstore.model.ApplicationProperty e)
| 09:55:31,640 DEBUG QueryPlanCache: located HQL query plan in cache (select e from org.lds.stack.petstore.model.ApplicationProperty e)
| 09:55:31,640 DEBUG HQLQueryPlan: find: select e from org.lds.stack.petstore.model.ApplicationProperty e
| 09:55:31,640 DEBUG QueryParameters: named parameters: {}
| 09:55:31,656 DEBUG StandardQueryCache: checking cached query results in region: org.hibernate.cache.StandardQueryCache
| 09:55:31,656 DEBUG TxInterceptor: (null) call on method [_get(/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}, item, true)]
| 09:55:31,656 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _get(/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}, item, true)
| 09:55:31,656 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {} for owner Thread[main,5,main]
| 09:55:31,656 DEBUG PessimisticLockInterceptor: failed to find or create child org of node /
| 09:55:31,656 DEBUG CallInterceptor: Invoking method _get(/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}, item, true) on cache.
| 09:55:31,656 DEBUG TreeCache: _get("/org/hibernate/cache/StandardQueryCache/sql: select applicatio0_.name as name0_, applicatio0_.prop_value as prop2_0_ from APP_PROPERTIES applicatio0_; parameters: ; named parameters: {}", item, "true")
| 09:55:31,656 DEBUG EvictionInterceptor: Invoking EvictionInterceptor
| 09:55:31,656 DEBUG EvictionInterceptor: Updating node/element events with no tx
| 09:55:31,656 DEBUG EvictionInterceptor: No event added. Element does not exist
| 09:55:31,656 DEBUG EvictionInterceptor: No node modifications
| 09:55:31,656 DEBUG EvictionInterceptor: Finished invoking EvictionInterceptor
| 09:55:31,656 DEBUG UnlockInterceptor: Attempting to release locks on current thread. Lock table is {}
| 09:55:31,656 DEBUG StandardQueryCache: query results were not found in cache
| 09:55:31,656 DEBUG AbstractBatcher: about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
| 09:55:31,656 DEBUG ConnectionManager: opening JDBC connection
| 09:55:31,656 DEBUG SQL:
| /* select
| e
| from
| org.lds.stack.petstore.model.ApplicationProperty e */ select
| applicatio0_.name as name0_,
| applicatio0_.prop_value as prop2_0_
| from
| APP_PROPERTIES applicatio0_
| Hibernate:
| /* select
| e
| from
| org.lds.stack.petstore.model.ApplicationProperty e */ select
| applicatio0_.name as name0_,
| applicatio0_.prop_value as prop2_0_
| from
| APP_PROPERTIES applicatio0_
| 09:55:31,656 DEBUG AbstractBatcher: preparing statement
| 09:55:31,687 DEBUG AbstractBatcher: about to open ResultSet (open ResultSets: 0, globally: 0)
| 09:55:31,687 DEBUG Loader: processing result set
| 09:55:31,687 DEBUG Loader: result set row: 0
| 09:55:31,687 DEBUG StringType: returning 'ldap.url' as column: name0_
| 09:55:31,687 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:55:31,687 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:55:31,703 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:55:31,703 DEBUG StringType: returning 'ldap://10.51.95.193' as column: prop2_0_
| 09:55:31,703 DEBUG Loader: result set row: 1
| 09:55:31,703 DEBUG StringType: returning 'ldap.manager.dn' as column: name0_
| 09:55:31,703 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:55:31,703 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:55:31,703 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.dn]
| 09:55:31,703 DEBUG StringType: returning 'cn=hansenbk,ou=People,o=WH' as column: prop2_0_
| 09:55:31,703 DEBUG Loader: result set row: 2
| 09:55:31,703 DEBUG StringType: returning 'ldap.manager.password' as column: name0_
| 09:55:31,703 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:55:31,703 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:55:31,703 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#ldap.manager.password]
| 09:55:31,703 DEBUG StringType: returning 'password' as column: prop2_0_
| 09:55:31,703 DEBUG Loader: result set row: 3
| 09:55:31,703 DEBUG StringType: returning 'smtp.host.name' as column: name0_
| 09:55:31,703 DEBUG Loader: result row: EntityKey[org.lds.stack.petstore.model.ApplicationProperty#smtp.host.name]
| 09:55:31,703 DEBUG Loader: Initializing object from ResultSet: [org.lds.stack.petstore.model.ApplicationProperty#smtp.host.name]
| 09:55:31,703 DEBUG AbstractEntityPersister: Hydrating entity: [org.lds.stack.petstore.model.ApplicationProperty#smtp.host.name]
| 09:55:31,703 DEBUG StringType: returning 'smtp-relay.wh.ldsglobal.net' as column: prop2_0_
| 09:55:31,703 DEBUG Loader: done processing result set (4 rows)
| 09:55:31,703 DEBUG AbstractBatcher: about to close ResultSet (open ResultSets: 1, globally: 1)
| 09:55:31,703 DEBUG AbstractBatcher: about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
| 09:55:31,718 DEBUG AbstractBatcher: closing statement
| 09:55:31,718 DEBUG ConnectionManager: aggressively releasing JDBC connection
| 09:55:31,718 DEBUG ConnectionManager: releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
| 09:55:31,718 DEBUG Loader: total objects hydrated: 4
| 09:55:31,718 DEBUG TwoPhaseLoad: resolving associations for [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:55:31,718 DEBUG TwoPhaseLoad: adding entity to second-level cache: [org.lds.stack.petstore.model.ApplicationProperty#ldap.url]
| 09:55:31,718 DEBUG TxInterceptor: (null) call on method [_get(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, true)]
| 09:55:31,718 DEBUG TxInterceptor: local transaction exists - registering global tx if not present for Thread[main,5,main]
| 09:55:31,718 DEBUG TxInterceptor: Associated gtx in txTable is null
| 09:55:31,718 DEBUG TreeCache: created new GTX: GlobalTransaction:<null>:1, local TX=bb14:38:0:01e39ddc3f61455084...967001:
| 09:55:31,718 DEBUG TxInterceptor: Registering sync handler for tx bb14:38:0:01e39ddc3f61455084...967001:, gtx GlobalTransaction:<null>:1
| 09:55:31,718 DEBUG TxInterceptor: registering for TX completion: SynchronizationHandler(TxInterceptor.LocalSynchronizationHandler(gtx=GlobalTransaction:<null>:1, tx=bb14:38:0:01e39ddc3f61455084...967001:))
| 09:55:31,718 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _get(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, true)
| 09:55:31,718 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url for owner GlobalTransaction:<null>:1
| 09:55:31,718 DEBUG PessimisticLockInterceptor: failed to find or create child org of node /
| 09:55:31,718 DEBUG CallInterceptor: Invoking method _get(/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, true) on cache.
| 09:55:31,718 DEBUG TreeCache: _get("/org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url", item, "true")
| 09:55:31,718 DEBUG EvictionInterceptor: Invoking EvictionInterceptor
| 09:55:31,718 DEBUG EvictionInterceptor: Updating node/element events with no tx
| 09:55:31,718 DEBUG EvictionInterceptor: No event added. Element does not exist
| 09:55:31,718 DEBUG EvictionInterceptor: No node modifications
| 09:55:31,718 DEBUG EvictionInterceptor: Finished invoking EvictionInterceptor
| 09:55:31,718 DEBUG TransactionalCache: caching: org.lds.stack.petstore.model.ApplicationProperty#ldap.url
| 09:55:31,718 DEBUG TxInterceptor: (null) call on method [_put(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=ldap://10.51.95.193, _version=null, _lazyPropertiesUnfetched=true}, true, 0)]
| 09:55:31,718 DEBUG PessimisticLockInterceptor: PessimisticLockInterceptor invoked for method _put(null, /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url, item, {_subclass=org.lds.stack.petstore.model.ApplicationProperty, value=ldap://10.51.95.193, _version=null, _lazyPropertiesUnfetched=true}, true, 0)
| 09:55:31,718 DEBUG PessimisticLockInterceptor: Attempting to lock node /org/lds/stack/petstore/model/ApplicationProperty/org.lds.stack.petstore.model.ApplicationProperty#ldap.url for owner Thread[main,5,main]
| 09:55:31,718 DEBUG Node: created child: fqn=/org
| 09:55:31,734 DEBUG Node: acquiring RL: fqn=/org, caller=Thread[main,5,main], lock=<unlocked>
| 09:55:31,734 DEBUG Node: acquired RL: fqn=/org, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
| 09:55:31,734 DEBUG Node: created child: fqn=/org/lds
| 09:55:31,734 DEBUG Node: acquiring RL: fqn=/org/lds, caller=Thread[main,5,main], lock=<unlocked>
| 09:55:31,734 DEBUG Node: acquired RL: fqn=/org/lds, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
| 09:55:31,734 DEBUG Node: created child: fqn=/org/lds/stack
| 09:55:31,734 DEBUG Node: acquiring RL: fqn=/org/lds/stack, caller=Thread[main,5,main], lock=<unlocked>
| 09:55:31,734 DEBUG Node: acquired RL: fqn=/org/lds/stack, caller=Thread[main,5,main], lock=read owners=[Thread[main,5,main]]
| 09:55:31,734 DEBUG Node: created child: fqn=/org/lds/stack/petstore
| 09:55:31,734 DEBUG Node: acquiring RL: fqn=/org/lds/stack/p
View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4007896#4007896
Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4007896
More information about the jboss-user
mailing list