jackrabbit-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ian Boston <...@tfd.co.uk>
Subject Re: relentless InvalidItemStateException
Date Tue, 19 Oct 2010 08:44:14 GMT
Another one along the same lines.
AFAICT, we add a node, it gets a UUID added but when it comes to saving the node the child
node has disappeared from the HierachyManager at line 291 (JR2.1.1) because the parent NodeState
didn't have the child node, that state being stored in a LinkedMap. Presumable because it
got removed. I will add some logging of Node IDs in ItemState to see if that happens.

This appears to be happening a lot concurrently under moderate load (12 concurrent request
threads in Jmeter). Works perfectly sequentially or under low load.

I should admit that we have removed quite a bit of blocking and synchronisation in the code
base surrounding Sessions in the AccessControlProviders blocking other sessions  and restructured
some of the Event Listeners to avoid sharing sessions between threads, but made no changes
below the Session level. All of this has made Jackrabbit non sequential on read, but could
be exposing bugs that anyone using the standard DefaultAccessManager just would not see. Unfortunately,
we have to be able to run the server non single threaded, so cant live without those changes.

Any ideas ?

Thanks
Ian


19.10.2010 09:18:58.531 *INFO* [127.0.0.1 [1287476338438] POST /system/userManager/group.create.json
HTTP/1.1] org.sakaiproject.nakamura.user.servlet.CreateSakaiGroupServlet Failed to create
group Unable to update item: node / javax.jcr.RepositoryException: Unable to update item:
node /
	at org.apache.jackrabbit.core.ItemImpl.save(ItemImpl.java:1156)
	at org.apache.jackrabbit.core.SessionImpl.save(SessionImpl.java:920)
	at org.apache.jackrabbit.core.security.user.UserManagerImpl.createGroup(UserManagerImpl.java:500)
	at org.apache.jackrabbit.core.security.user.UserManagerImpl.createGroup(UserManagerImpl.java:468)
	at org.sakaiproject.nakamura.user.servlet.CreateSakaiGroupServlet.handleOperation(CreateSakaiGroupServlet.java:292)
	at org.apache.sling.jackrabbit.usermanager.impl.post.AbstractAuthorizablePostServlet.doPost(AbstractAuthorizablePostServlet.java:127)
	at org.apache.sling.api.servlets.SlingAllMethodsServlet.mayService(SlingAllMethodsServlet.java:148)
	at org.apache.sling.api.servlets.SlingSafeMethodsServlet.service(SlingSafeMethodsServlet.java:344)
	at org.apache.sling.api.servlets.SlingSafeMethodsServlet.service(SlingSafeMethodsServlet.java:375)
	at org.apache.sling.engine.impl.request.RequestData.service(RequestData.java:523)
	at org.apache.sling.engine.impl.SlingMainServlet.processRequest(SlingMainServlet.java:427)
	at org.apache.sling.engine.impl.filter.RequestSlingFilterChain.render(RequestSlingFilterChain.java:48)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:64)
	at org.apache.sling.engine.impl.debug.RequestProgressTrackerLogFilter.doFilter(RequestProgressTrackerLogFilter.java:59)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
	at org.sakaiproject.nakamura.batch.RequestEventsFilter.doFilter(RequestEventsFilter.java:96)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
	at org.sakaiproject.nakamura.files.pool.ContentPoolFilter.doFilter(ContentPoolFilter.java:77)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
	at org.sakaiproject.nakamura.privacy.RestPrivacyFilter.doFilter(RestPrivacyFilter.java:81)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
	at org.sakaiproject.nakamura.persistence.TransactionManagerFilter.doFilter(TransactionManagerFilter.java:95)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
	at org.sakaiproject.nakamura.cluster.ClusterTrackingFilter.doFilter(ClusterTrackingFilter.java:87)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
	at org.sakaiproject.nakamura.http.cache.CacheControlFilter.doFilter(CacheControlFilter.java:198)
	at org.apache.sling.engine.impl.filter.AbstractSlingFilterChain.doFilter(AbstractSlingFilterChain.java:60)
	at org.apache.sling.engine.impl.SlingMainServlet.service(SlingMainServlet.java:313)
	at org.apache.sling.engine.impl.SlingMainServlet.service(SlingMainServlet.java:207)
	at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:502)
	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:389)
	at org.ops4j.pax.web.service.internal.HttpServiceServletHandler.handle(HttpServiceServletHandler.java:64)
	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
	at org.ops4j.pax.web.service.internal.HttpServiceContext.handle(HttpServiceContext.java:111)
	at org.ops4j.pax.web.service.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:64)
	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
	at org.mortbay.jetty.Server.handle(Server.java:324)
	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:535)
	at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:880)
	at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:747)
	at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
	at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520)
Caused by: org.apache.jackrabbit.core.state.ItemStateException: Unable to resolve path for
item: 3e5d581b-986b-386d-a83e-83a0acee0674/{http://www.jcp.org/jcr/1.0}uuid
	at org.apache.jackrabbit.core.observation.EventStateCollection.getPath(EventStateCollection.java:683)
	at org.apache.jackrabbit.core.observation.EventStateCollection.createEventStates(EventStateCollection.java:435)
	at org.apache.jackrabbit.core.state.SharedItemStateManager$Update.begin(SharedItemStateManager.java:709)
	at org.apache.jackrabbit.core.state.SharedItemStateManager.beginUpdate(SharedItemStateManager.java:1455)
	at org.apache.jackrabbit.core.state.SharedItemStateManager.update(SharedItemStateManager.java:1485)
	at org.apache.jackrabbit.core.state.LocalItemStateManager.update(LocalItemStateManager.java:351)
	at org.apache.jackrabbit.core.state.XAItemStateManager.update(XAItemStateManager.java:354)
	at org.apache.jackrabbit.core.state.LocalItemStateManager.update(LocalItemStateManager.java:326)
	at org.apache.jackrabbit.core.state.SessionItemStateManager.update(SessionItemStateManager.java:328)
	at org.apache.jackrabbit.core.ItemImpl.save(ItemImpl.java:1150)
	... 44 more
Caused by: javax.jcr.ItemNotFoundException: failed to build path of 3e5d581b-986b-386d-a83e-83a0acee0674:
b8984547-0d1f-42b3-bf9f-8684449f2fb3 has no child entry for 3e5d581b-986b-386d-a83e-83a0acee0674
	at org.apache.jackrabbit.core.HierarchyManagerImpl.buildPath(HierarchyManagerImpl.java:291)
	at org.apache.jackrabbit.core.CachingHierarchyManager.buildPath(CachingHierarchyManager.java:198)
	at org.apache.jackrabbit.core.HierarchyManagerImpl.buildPath(HierarchyManagerImpl.java:280)
	at org.apache.jackrabbit.core.CachingHierarchyManager.buildPath(CachingHierarchyManager.java:198)
	at org.apache.jackrabbit.core.HierarchyManagerImpl.getPath(HierarchyManagerImpl.java:395)
	at org.apache.jackrabbit.core.CachingHierarchyManager.getPath(CachingHierarchyManager.java:232)
	at org.apache.jackrabbit.core.observation.EventStateCollection.getPath(EventStateCollection.java:678)
	... 53 more


On 18 Oct 2010, at 22:06, Ian Boston wrote:

> I also get things like this:
> 
> 1-ad9e-4574-8f6c-9545a7e3ba5b: b65ef847-0127-4a3b-9260-86012124616a has no child entry
for a99b9f31-ad9e-4574-8f6c-9545a7e3ba5b javax.jcr.ItemNotFoundException: failed to build
path of a99b9f31-ad9e-4574-8f6c-9545a7e3ba5b: b65ef847-0127-4a3b-9260-86012124616a has no
child entry for a99b9f31-ad9e-4574-8f6c-9545a7e3ba5b
> 	at org.apache.jackrabbit.core.HierarchyManagerImpl.buildPath(HierarchyManagerImpl.java:291)
> 	at org.apache.jackrabbit.core.CachingHierarchyManager.buildPath(CachingHierarchyManager.java:198)
> 	at org.apache.jackrabbit.core.HierarchyManagerImpl.buildPath(HierarchyManagerImpl.java:280)
> 	at org.apache.jackrabbit.core.CachingHierarchyManager.buildPath(CachingHierarchyManager.java:198)
> 	at org.apache.jackrabbit.core.HierarchyManagerImpl.buildPath(HierarchyManagerImpl.java:280)
> 	at org.apache.jackrabbit.core.CachingHierarchyManager.buildPath(CachingHierarchyManager.java:198)
> 	at org.apache.jackrabbit.core.HierarchyManagerImpl.getPath(HierarchyManagerImpl.java:395)
> 	at org.apache.jackrabbit.core.CachingHierarchyManager.getPath(CachingHierarchyManager.java:232)
> 	at org.apache.jackrabbit.core.lock.LockManagerImpl.getPath(LockManagerImpl.java:856)
> 	at org.apache.jackrabbit.core.lock.LockManagerImpl.checkLock(LockManagerImpl.java:702)
> 	at org.apache.jackrabbit.core.lock.XALockManager.checkLock(XALockManager.java:174)
> 	at org.apache.jackrabbit.core.ItemValidator.checkLock(ItemValidator.java:392)
> 	at org.apache.jackrabbit.core.ItemValidator.checkCondition(ItemValidator.java:315)
> 	at org.apache.jackrabbit.core.ItemValidator.checkModify(ItemValidator.java:277)
> 	at org.apache.jackrabbit.core.NodeImpl.checkSetProperty(NodeImpl.java:1207)
> 	at org.apache.jackrabbit.core.NodeImpl.setProperty(NodeImpl.java:2341)
> 	at org.apache.jackrabbit.core.NodeImpl.setProperty(NodeImpl.java:1596)
> 	at org.apache.jackrabbit.core.NodeImpl.setProperty(NodeImpl.java:2216)
> 	at org.sakaiproject.nakamura.personal.PersonalAuthorizablePostProcessor.updateProfileProperties(PersonalAuthorizablePostProcessor.java:219)
> 	at org.sakaiproject.nakamura.personal.PersonalAuthorizablePostProcessor.createHomeFolder(PersonalAuthorizablePostProcessor.java:287)
> 	at org.sakaiproject.nakamura.personal.PersonalAuthorizablePostProcessor.process(PersonalAuthorizablePostProcessor.java:156)
> 
> 
> On 18 Oct 2010, at 20:38, Ian Boston wrote:
> 
>> Hi,
>> I am having persistent/relentless problems with InvalidItemStateExceptions of the
form  below. In this http request there are multiple save operations, and when there are,
under load (12 concurrent threads) I get random InvalidItemStateExceptions.
>> 
>> They can take 1000s of requests to happen or they can take just a few. Each request
has a unique path so I am reasonably certain no 2 requests are modifying the same node. If
I remove some of the save() operation, then the occurrence drops leading me to think that
there is a problem with doing a sequence of session.save operations.
>> 
>> I am also reasonably certain that there are no Observation managers making changes
in other threads, or SystemSessions making modifications in access control providers and the
like. The test is being run against a single node, no cluster, ClusterNode or Journal that
could be modifying.
>> 
>> Even Stranger is sometimes it reports InvalidItemState on the root node /, but that
might have been before I eliminated all Workspace.copy() operations.
>> 
>> any ideas, I am a bit stuck on this "bug" having been at it for 3 days.
>> 
>> Ian
>> 
>> 18.10.2010 20:29:05.814 *ERROR* [127.0.0.1 [1287430145192] POST /system/userManager/group.create.json
HTTP/1.1] org.sakaiproject.nakamura.personal.ProfileImporter Unable to import content for
profile node node /_group/t/te/tes/test/teste/tester4_gr1_14_4/public/authprofile javax.jcr.InvalidItemStateException:
Item cannot be saved because it has been modified externally: node /
>> 	at org.apache.jackrabbit.core.ItemImpl.getTransientStates(ItemImpl.java:249)
>> 	at org.apache.jackrabbit.core.ItemImpl.save(ItemImpl.java:981)
>> 	at org.apache.jackrabbit.core.SessionImpl.save(SessionImpl.java:920)
>> 	at org.apache.sling.jcr.contentloader.internal.DefaultContentImporter.importContent(DefaultContentImporter.java:112)
>> 	at org.sakaiproject.nakamura.personal.ProfileImporter.importFromJsonString(ProfileImporter.java:102)
>> 	at org.sakaiproject.nakamura.personal.ProfileImporter.importFromParameters(ProfileImporter.java:90)
>> 	at org.sakaiproject.nakamura.personal.PersonalAuthorizablePostProcessor.updateProfileProperties(PersonalAuthorizablePostProcessor.java:191)
>> 	at org.sakaiproject.nakamura.personal.PersonalAuthorizablePostProcessor.createHomeFolder(PersonalAuthorizablePostProcessor.java:287)
>> 	at org.sakaiproject.nakamura.personal.PersonalAuthorizablePostProcessor.process(PersonalAuthorizablePostProcessor.java:156)
>> 	at org.sakaiproject.nakamura.user.AuthorizablePostProcessServiceImpl.process(AuthorizablePostProcessServiceImpl.java:132)
>> 	at org.sakaiproject.nakamura.user.AuthorizablePostProcessServiceImpl.process(AuthorizablePostProcessServiceImpl.java:167)
>> 
>> 
>> 
> 


Mime
View raw message