Storage layer: the "store topic" operation must be synchronized

[Malte]

...

2014-04-23 03:22:05,246 ERROR CatchAllExceptionMapper          A DeepaMehta resource method or event listener threw an exception resp. an error occurred. Mapping exception/error to response: 500 (Internal Server Error).
java.lang.RuntimeException: Fetching topic failed (key="uri", value="de.kiezatlas.topic.t-378323")
	at de.deepamehta.core.impl.EmbeddedService.getTopic(EmbeddedService.java:108)
	at de.deepamehta.plugins.webservice.WebservicePlugin.getTopic(WebservicePlugin.java:63)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)[:1.6.0_26]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)[:1.6.0_26]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)[:1.6.0_26]
	at java.lang.reflect.Method.invoke(Method.java:597)[:1.6.0_26]
	at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$TypeOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:185)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.uri.rules.ResourceObjectRule.accept(ResourceObjectRule.java:100)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1480)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1411)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1360)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1350)[45:com.sun.jersey.jersey-server:1.14.0]
	at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)[46:com.sun.jersey.servlet:1.14.0]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:538)[46:com.sun.jersey.servlet:1.14.0]
	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:716)[46:com.sun.jersey.servlet:1.14.0]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.handler.ServletHandler.doHandle(ServletHandler.java:96)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.handler.ServletHandler.handle(ServletHandler.java:79)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.dispatch.ServletPipeline.handle(ServletPipeline.java:42)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.dispatch.InvocationFilterChain.doFilter(InvocationFilterChain.java:49)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.dispatch.HttpFilterChain.doFilter(HttpFilterChain.java:33)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.dispatch.FilterPipeline.dispatch(FilterPipeline.java:48)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:39)[50:org.apache.felix.http.jetty:2.2.2]
	at org.apache.felix.http.base.internal.DispatcherServlet.service(DispatcherServlet.java:67)[50:org.apache.felix.http.jetty:2.2.2]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:654)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:445)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:225)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1044)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:372)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:189)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:978)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.Server.handle(Server.java:369)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:486)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:933)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:995)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:644)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:668)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)[50:org.apache.felix.http.jetty:2.2.2]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)[50:org.apache.felix.http.jetty:2.2.2]
	at java.lang.Thread.run(Thread.java:662)[:1.6.0_26]
Caused by: java.util.NoSuchElementException: More than one element in org.neo4j.index.impl.lucene.LuceneIndex$1@38c5564e. First element is 'Node[1139813]' and the second element is 'Node[1139816]'
	at org.neo4j.helpers.collection.IteratorUtil.singleOrNull(IteratorUtil.java:118)
	at org.neo4j.index.impl.lucene.IdToEntityIterator.getSingle(IdToEntityIterator.java:88)
	at org.neo4j.index.impl.lucene.IdToEntityIterator.getSingle(IdToEntityIterator.java:32)
	at de.deepamehta.storage.neo4j.Neo4jStorage.fetchTopic(Neo4jStorage.java:118)
	at de.deepamehta.core.impl.StorageDecorator.fetchTopic(StorageDecorator.java:63)
	at de.deepamehta.core.impl.EmbeddedService.getTopic(EmbeddedService.java:105)
	... 52 more

[jri]

Oh!

The stacktrace reveals there are 2 topics with the same URI (de.kiezatlas.topic.t-378323). The 2 topic IDs are 1139813 and 1139816. I checked the DB: indeed these are 2 Geo Object topics with the same URI. Both are virtually the same thing: "Schulstation \"Ostseekarree\"". Obviously it was created twice. Does this "Schulstation" ring any bells at you?

What I can't explain at the moment is how 2 topics with the same URI could be created in the first place. The DM storage layer is supposed to reject such an operation at the very lowest layer. I'll have to check there.

[jri]

Meanwhile I investigated that situation. Duplicate URIs can reach the DB when multiple threads are involved. So, its a concurrency issue. DM's storage layer must synchronize the "create topic" operation. Checking for URI existence and creating the actual topic constitutes a "critical section". I have to fix that.

Thank you for reporting!