Ticket #644 (new Defect)

Opened 6 years ago

Last modified 6 years ago

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

Reported by: Malte Owned by:
Priority: Major Milestone:
Component: DeepaMehta Standard Distribution Version: 4.2
Keywords: Cc: jri
Complexity: 3 Area: Data Model
Module:

Description

...

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


Change History

comment:1 Changed 6 years ago by 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.

comment:2 Changed 6 years ago by 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!

comment:3 Changed 6 years ago by jri

  • Summary changed from Querying a topic /by_value/uri/ fails caused by lucene NoSuchElementException to Storage layer: the "store topic" operation must be synchronized

comment:4 Changed 6 years ago by jri

  • Milestone Release 4.3 deleted
Note: See TracTickets for help on using tickets.