InvalidRecordException running parallel unit tests against server #388

Closed
jotomo opened this Issue Dec 24, 2012 · 3 comments

Projects

None yet

2 participants

@jotomo

Using neo4j-server community edition, 1.8.1 on Oracle JDK 1.6. Not using any plugins or extensions, fresh install, fresh db. Running unit tests against the db via SDN. Interacting with the server solely via REST I shouldn't be able to do damage to the db from my app; however I'm running into the exception below. This is reproducible by running tests in parallel. Running tests sequentially after the exception was thrown works, but in the shell I get the following:

neo4j-sh (0)$ start n=node(*) return n;
NotFoundException: Node[14] not found. This can be because someone else deleted this entity while we were trying to read properties from it, or because of concurrent modification of other properties on this entity. The problem should be temporary.

This message goes away when I restart the server. Then everything seems fine again.
Not sure where to go from here ...

23:28:56.785 [1004265781@qtp-1262404317-6] ERROR org.mortbay.log - /db/data/node/9/relationships
org.neo4j.kernel.impl.nioneo.store.InvalidRecordException: NodeRecord[9] not in use
    at org.neo4j.kernel.impl.nioneo.store.NodeStore.getRecord(NodeStore.java:199) ~[neo4j-kernel-1.8.jar:1.8]
    at org.neo4j.kernel.impl.nioneo.store.NodeStore.getRecord(NodeStore.java:79) ~[neo4j-kernel-1.8.jar:1.8]
    at org.neo4j.kernel.impl.nioneo.xa.WriteTransaction.relationshipCreate(WriteTransaction.java:1322) ~[neo4j-kernel-1.8.jar:1.8]
    at org.neo4j.kernel.impl.persistence.PersistenceManager.relationshipCreate(PersistenceManager.java:161) ~[neo4j-kernel-1.8.jar:1.8]
    at org.neo4j.kernel.impl.core.NodeManager.createRelationship(NodeManager.java:252) ~[neo4j-kernel-1.8.jar:1.8]
    at org.neo4j.kernel.impl.core.NodeImpl.createRelationshipTo(NodeImpl.java:578) ~[neo4j-kernel-1.8.jar:1.8]
    at org.neo4j.kernel.impl.core.NodeProxy.createRelationshipTo(NodeProxy.java:207) ~[neo4j-kernel-1.8.jar:1.8]
    at org.neo4j.server.rest.web.DatabaseActions.createRelationship(DatabaseActions.java:583) ~[neo4j-server-1.8.jar:1.8]
    at org.neo4j.server.rest.web.RestfulGraphDatabase.createRelationship(RestfulGraphDatabase.java:406) ~[neo4j-server-1.8.jar:1.8]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_37]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_37]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_37]
    at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_37]
    at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ResponseOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:205) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:288) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1469) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1400) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1349) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1339) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:537) ~[jersey-server-1.9.jar:1.9]
    at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:699) ~[jersey-server-1.9.jar:1.9]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:820) ~[servlet-api-2.5-20081211.jar:na]
    at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511) ~[jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:390) ~[jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.Server.handle(Server.java:326) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:943) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:843) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:410) [jetty-6.1.25.jar:6.1.25]
    at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582) [jetty-util-6.1.25.jar:6.1.25]
@jotomo

So, is it okay for the server to log exceptions at error log-level when the client behaves badly - hence an issue with my application - or shouldn't this happen? If it's an issue with neo4j, how can I help finding the issue?

@jakewins

Hey @jotomo, you are right, this is a bug in the database. It will be partly resolved (eg significantly lower risk of being encountered) in the upcoming 1.9 release, and will be remedied to go away entirely ASAP after that. It's a high prio issue.

If you run into this in production, you don't have to restart the database, but you can connect to the server with a JMX browser, and through there tell Neo4j to flush it's caches, which is where this issue occurs. To be clear, it does not indicate actual corruption of your data, but that an incorrect record is stuck in the cache.

@jakewins jakewins closed this Feb 18, 2013
@jotomo

Cool. Thanks for the info @jakewins !

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment