[jboss-jira] [JBoss JIRA] Commented: (JBPORTAL-2017) Portal CMS corrupts/loses data

frontline frontline (JIRA) jira-events at lists.jboss.org
Sun May 18 15:24:22 EDT 2008 

    [ http://jira.jboss.com/jira/browse/JBPORTAL-2017?page=comments#action_12413147 ] 
            
frontline frontline commented on JBPORTAL-2017:
-----------------------------------------------

I got a few errors when I tried to do stuff concurrently, like creating a page in the CMS. I had two browsers open and quickly clicked "create" in both browser windows.
I didn't notice the database corruption but obviously there are some concurrency issues.

***
2008-05-18 21:37:02,489 ERROR [org.jboss.portal.cms.hibernate.state.JBossCachePersistenceManager] failed to write node state: af22c468-6d96-431e-b352-4a0f43c4a4e3
org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/wsp_node/af22c468-6d96-431e-b352-4a0f43c4a4e3, caller=GlobalTransaction:<null>:59, lock=write owner=GlobalTransaction:<null>:58 (activeReaders=0, activeWriter=Thread[http-127.0.0.1-8081-6,5,jboss], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
	at org.jboss.cache.Node.acquire(Node.java:500)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:379)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:307)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:181)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.CacheLoaderInterceptor.invoke(CacheLoaderInterceptor.java:212)
	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.CacheStoreInterceptor.invoke(CacheStoreInterceptor.java:135)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:365)
	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:138)
	at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5863)
	at org.jboss.cache.TreeCache.get(TreeCache.java:3627)
	at org.jboss.cache.TreeCache.get(TreeCache.java:3608)
	at org.jboss.cache.TreeCache.get(TreeCache.java:3595)
	at sun.reflect.GeneratedMethodAccessor269.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
	at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
	at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
	at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
	at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
	at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
	at $Proxy200.get(Unknown Source)
	at org.jboss.portal.cms.hibernate.state.JBossCachePersistenceManager.update(JBossCachePersistenceManager.java:694)
	at org.jboss.portal.cms.hibernate.state.JBossCachePersistenceManager.storeHB(JBossCachePersistenceManager.java:1436)
	at org.jboss.portal.cms.hibernate.state.JBossCachePersistenceManager.store(JBossCachePersistenceManager.java:1382)
	at org.apache.jackrabbit.core.state.SharedItemStateManager$Update.end(SharedItemStateManager.java:626)
	at org.apache.jackrabbit.core.state.XAItemStateManager.commit(XAItemStateManager.java:170)
	at org.apache.jackrabbit.core.TransactionContext.commit(TransactionContext.java:172)
	at org.apache.jackrabbit.core.XASessionImpl.commit(XASessionImpl.java:315)
	at org.jboss.portal.cms.impl.jcr.JCRCMS.execute(JCRCMS.java:642)
	at sun.reflect.GeneratedMethodAccessor294.invoke(Unknown Source)

***

java.lang.RuntimeException: org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/wsp_node/707e886b-3955-4c2c-b0c9-b7737fd9e3fa, caller=GlobalTransaction:<null>:58, lock=write owner=GlobalTransaction:<null>:57 (activeReaders=0, activeWriter=Thread[http-127.0.0.1-8081-1,5,jboss], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
	at org.jboss.portal.cms.hibernate.state.JBossCachePersistenceManager.exists(JBossCachePersistenceManager.java:517)
	at org.apache.jackrabbit.core.state.SharedItemStateManager.hasNonVirtualItemState(SharedItemStateManager.java:906)
	at org.apache.jackrabbit.core.state.SharedItemStateManager.hasItemState(SharedItemStateManager.java:271)
	at org.apache.jackrabbit.core.state.LocalItemStateManager.hasItemState(LocalItemStateManager.java:179)
	at org.apache.jackrabbit.core.state.XAItemStateManager.hasItemState(XAItemStateManager.java:261)
	at org.apache.jackrabbit.core.state.SessionItemStateManager.getItemState(SessionItemStateManager.java:161)
	at org.apache.jackrabbit.core.ItemManager.createItemInstance(ItemManager.java:461)
	at org.apache.jackrabbit.core.ItemManager.getItem(ItemManager.java:319)
	at org.apache.jackrabbit.core.PropertyImpl.getNode(PropertyImpl.java:656)
	at org.apache.jackrabbit.core.NodeImpl.getVersionHistory(NodeImpl.java:3148)
***
Caused by: org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/wsp_node/707e886b-3955-4c2c-b0c9-b7737fd9e3fa, caller=GlobalTransaction:<null>:58, lock=write owner=GlobalTransaction:<null>:57 (activeReaders=0, activeWriter=Thread[http-127.0.0.1-8081-1,5,jboss], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
	at org.jboss.cache.Node.acquire(Node.java:500)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:379)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:307)
	at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:181)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.CacheLoaderInterceptor.invoke(CacheLoaderInterceptor.java:212)
	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.CacheStoreInterceptor.invoke(CacheStoreInterceptor.java:135)
	at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:68)
	at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:365)
	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:138)
	at org.jboss.cache.TreeCache.invokeMethod(TreeCache.java:5863)
	at org.jboss.cache.TreeCache.get(TreeCache.java:3627)
	at org.jboss.cache.TreeCache.get(TreeCache.java:3608)
	at org.jboss.cache.TreeCache.get(TreeCache.java:3595)
	at sun.reflect.GeneratedMethodAccessor269.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
	at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
	at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
	at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
	at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
	at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
	at $Proxy200.get(Unknown Source)
	at org.jboss.portal.cms.hibernate.state.JBossCachePersistenceManager.exists(JBossCachePersistenceManager.java:478)
	... 290 more
Caused by: org.jboss.cache.lock.TimeoutException: read lock for /wsp_node/707e886b-3955-4c2c-b0c9-b7737fd9e3fa could not be acquired by GlobalTransaction:<null>:58 after 15000 ms. Locks: Read lock owners: []
Write lock owner: GlobalTransaction:<null>:57
, lock info: write owner=GlobalTransaction:<null>:57 (activeReaders=0, activeWriter=Thread[http-127.0.0.1-8081-1,5,jboss], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
	at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:262)
	at org.jboss.cache.Node.acquireReadLock(Node.java:512)
	at org.jboss.cache.Node.acquire(Node.java:474)
	... 319 more

> Portal CMS corrupts/loses data
> ------------------------------
>
>                 Key: JBPORTAL-2017
>                 URL: http://jira.jboss.com/jira/browse/JBPORTAL-2017
>             Project: JBoss Portal
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>          Components: Portal CMS
>    Affects Versions: 2.6.1 Final
>            Reporter: frontline frontline
>         Assigned To: Sohil Shah
>
> We have noticed that the CMS the portal uses loses data sometimes.
> This occurs on server boots because it appears that the cache is in a different state than the database.
> For example if I check the child folders for a given folder in the portal, the list may show different entries than the corresponding entry in the database table jbp_cms_wsp_node.
> I also checked the integrity of that table, and found many "orphaned" entries where the entry's parent didn't contain the given entry in its child list.
> I have not been able to reproduce this on a devel machine, but this happens fairly often on a quite busy production server (lots of cms creates and updates).
> Here is an example of the database integrity check for the jbp_cms_wsp_node table.
> "Parent children" is a list of the children the parent entry contains (name - id). If there is a "false" after the entry that means that the database does not contain an entry with the given node id.
> The other list "Found children" is a list of nodes from the database which have the given parent as their parent. As you can see this list is longer than the parent's child list. (The "4" after these entries is just the node state property)
> 14:55:00,062 INFO  [STDOUT] Items with parent: af22c468-6d96-431e-b352-4a0f43c4a4e3
> 14:55:00,062 INFO  [STDOUT] Parent found: af22c468-6d96-431e-b352-4a0f43c4a4e3
> 14:55:00,062 INFO  [STDOUT] Parent children
> 14:55:00,062 INFO  [STDOUT] {}Foopage1 - f756ea71-f2a4-4000-b0db-f95838221bba - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage2 - e0a1f7ab-1c31-4892-9fe5-cdeea0808280 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage3 - 9f23209d-e020-45de-8b9f-a61c98ff36c1 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage4 - 7ca11793-4d95-4b14-9e68-176553579dca - false
> 14:55:00,062 INFO  [STDOUT] {}Foopage5 - f1406d76-6f95-4228-b2ec-db910606ede2 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage6 - a52030a3-9621-4ce3-8d7c-cd7cb212e412 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage7 - e399361e-be98-4ce9-abff-14b57f39d9ae - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage8 - cbfc7e2e-c166-42a0-863b-16e053904eb5 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage9 - eb92997e-13b9-4038-8f71-fe8c28b82830 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage10 - 2b817c88-e0eb-4ea7-9f1f-22d41917de92 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage11 - dd0a9d82-231b-45e0-96e3-2c12a7d8bb9e - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage12 - 07902117-4a07-423f-8872-455f76febfec - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage13 - ca35324b-8efe-45e8-a88d-38d7f57330bb - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage14 - 57a10ce2-6c6f-4b8d-8e3b-ddb6bb03771c - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage15 - a310c49b-7378-403a-be5b-e368175d35a3 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage16 - 6e192970-6cb4-4425-88f4-6abe10fcdc0f - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage17 - 29ff2441-40fd-4dca-8b11-0b07d4a41222 - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage18 - 0a620ecd-fd91-4ef0-b81a-265e8f8b04ad - true
> 14:55:00,062 INFO  [STDOUT] {}Foopage19 - 48af1d55-20eb-411e-a84e-bd05a42a6c9b - true
> 14:55:00,062 INFO  [STDOUT] Found children
> 14:55:00,062 INFO  [STDOUT] Found: 34c90ce9-ff43-442e-8ca8-2096cad1fab2 - 4
> 14:55:00,062 INFO  [STDOUT] Found: f1406d76-6f95-4228-b2ec-db910606ede2 - 4
> 14:55:00,062 INFO  [STDOUT] Found: cbfc7e2e-c166-42a0-863b-16e053904eb5 - 4
> 14:55:00,062 INFO  [STDOUT] Found: a310c49b-7378-403a-be5b-e368175d35a3 - 4
> 14:55:00,062 INFO  [STDOUT] Found: c8fd9e02-2aa1-4278-bddd-2d9be0b2d6b0 - 4
> 14:55:00,062 INFO  [STDOUT] Found: 2b817c88-e0eb-4ea7-9f1f-22d41917de92 - 4
> 14:55:00,062 INFO  [STDOUT] Found: f756ea71-f2a4-4000-b0db-f95838221bba - 4
> 14:55:00,062 INFO  [STDOUT] Found: 57a10ce2-6c6f-4b8d-8e3b-ddb6bb03771c - 4
> 14:55:00,062 INFO  [STDOUT] Found: 29ff2441-40fd-4dca-8b11-0b07d4a41222 - 4
> 14:55:00,062 INFO  [STDOUT] Found: 3896b2bf-35e9-4c02-9333-c16347143c9d - 4
> 14:55:00,062 INFO  [STDOUT] Found: e399361e-be98-4ce9-abff-14b57f39d9ae - 4
> 14:55:00,062 INFO  [STDOUT] Found: e8d88a1b-d6c2-48e2-a028-0359d215dea9 - 4
> 14:55:00,062 INFO  [STDOUT] Found: a52030a3-9621-4ce3-8d7c-cd7cb212e412 - 4
> 14:55:00,062 INFO  [STDOUT] Found: 48af1d55-20eb-411e-a84e-bd05a42a6c9b - 4
> 14:55:00,078 INFO  [STDOUT] Found: d0868b64-051e-4b7e-ba11-cf078c63e7a5 - 4
> 14:55:00,078 INFO  [STDOUT] Found: 9a2ca829-eeb1-4e81-8e03-d1fc6953db81 - 4
> 14:55:00,078 INFO  [STDOUT] Found: eb92997e-13b9-4038-8f71-fe8c28b82830 - 4
> 14:55:00,078 INFO  [STDOUT] Found: e0a1f7ab-1c31-4892-9fe5-cdeea0808280 - 4
> 14:55:00,078 INFO  [STDOUT] Found: ef7eba81-1c18-4a0f-b905-ef8009939c9f - 4
> 14:55:00,078 INFO  [STDOUT] Found: c7a8ef0d-33f0-44c8-8c0b-fe206288c58d - 4
> 14:55:00,078 INFO  [STDOUT] Found: 728edcdd-fffb-4a53-8bb4-53d4fefebbc8 - 4
> 14:55:00,078 INFO  [STDOUT] Found: 37d8253a-c834-4444-b959-87a23629a424 - 4
> 14:55:00,078 INFO  [STDOUT] Found: 5b9ce6a6-8f12-4a1b-8973-c1efde831798 - 4
> 14:55:00,078 INFO  [STDOUT] Found: ca35324b-8efe-45e8-a88d-38d7f57330bb - 4
> 14:55:00,078 INFO  [STDOUT] Found: 9eea7729-0a7a-4828-9259-aec527fb3972 - 4
> 14:55:00,078 INFO  [STDOUT] Found: 08b7d192-16d6-42fd-aec0-38af242b3db6 - 4
> 14:55:00,078 INFO  [STDOUT] Found: 0a620ecd-fd91-4ef0-b81a-265e8f8b04ad - 4
> 14:55:00,078 INFO  [STDOUT] Found: 330f5753-b647-47a8-a4d9-f71a27824a01 - 4
> 14:55:00,078 INFO  [STDOUT] Found: 6e192970-6cb4-4425-88f4-6abe10fcdc0f - 4
> 14:55:00,078 INFO  [STDOUT] Found: 9f23209d-e020-45de-8b9f-a61c98ff36c1 - 4
> 14:55:00,078 INFO  [STDOUT] Found: dd0a9d82-231b-45e0-96e3-2c12a7d8bb9e - 4
> 14:55:00,078 INFO  [STDOUT] Found: 6575e15c-5ad6-4028-9a93-c647c29283af - 4
> 14:55:00,078 INFO  [STDOUT] Found: 059ab70a-f3f5-4fa2-ba2c-38779acc4eea - 4
> 14:55:00,078 INFO  [STDOUT] Found: 582096e8-c3de-4223-b88f-55ee3aeabd0b - 4
> 14:55:00,078 INFO  [STDOUT] Found: 07902117-4a07-423f-8872-455f76febfec - 4
> 14:55:00,078 INFO  [STDOUT] Found: 9cbf87be-3512-41da-90cd-c85ad6c53ed8 - 4

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://jira.jboss.com/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira

More information about the jboss-jira mailing list