oeg-upm / epnoi

epnoi is an unified information access middleware which objective is to increase the awareness and simplify the search of relevant content in situations where multiple heterogeneous non-structured information sources are involved.
http://www.epnoi.org
Apache License 2.0
0 stars 1 forks source link

Neo4j degradation #58

Open cbadenes opened 8 years ago

cbadenes commented 8 years ago
cbadenes commented 8 years ago
10:16:49.041 [COMPARATOR] [duler-1] ERROR o.e.s.a.RepeatableActionExecutor - Error executing delete SIMILAR_TO_DOCUMENTS[http://drinventor.eu/similarities/7e289eef-92b8-4ba0-bfba-8c6acb89a53d] after 5 retries
org.neo4j.ogm.session.result.ResultProcessingException: Failed to execute request: {"statements":[{"statement":"MATCH (n)-[r:`SIMILAR_TO`]->(m) WHERE r.`uri` = { `uri` } WITH n,r MATCH p=(n)-[*0..1]-() RETURN p, ID(r)","parameters":{"uri":"http://drinventor.eu/similarities/7e289eef-92b8-4ba0-bfba-8c6acb89a53d"},"resultDataContents":["graph","row"],"includeStats":false}]}
    at org.neo4j.ogm.session.request.DefaultRequest.execute(DefaultRequest.java:126) ~[neo4j-ogm-1.1.5-BETA.jar:na]
    at org.neo4j.ogm.session.request.SessionRequestHandler.execute(SessionRequestHandler.java:99) ~[neo4j-ogm-1.1.5-BETA.jar:na]
    at org.neo4j.ogm.session.request.SessionRequestHandler.execute(SessionRequestHandler.java:72) ~[neo4j-ogm-1.1.5-BETA.jar:na]
    at org.neo4j.ogm.session.delegates.LoadByTypeDelegate.loadAll(LoadByTypeDelegate.java:80) ~[neo4j-ogm-1.1.5-BETA.jar:na]
    at org.neo4j.ogm.session.delegates.LoadByTypeDelegate.loadAll(LoadByTypeDelegate.java:144) ~[neo4j-ogm-1.1.5-BETA.jar:na]
    at org.neo4j.ogm.session.Neo4jSession.loadAll(Neo4jSession.java:193) ~[neo4j-ogm-1.1.5-BETA.jar:na]
    at sun.reflect.GeneratedMethodAccessor355.invoke(Unknown Source) ~[na:na]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_45]
    at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_45]
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:133) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:121) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at com.sun.proxy.$Proxy173.loadAll(Unknown Source) ~[na:na]
    at org.springframework.data.neo4j.repository.query.derived.DerivedGraphRepositoryQuery.execute(DerivedGraphRepositoryQuery.java:64) ~[spring-data-neo4j-4.0.0.RELEASE.jar:na]
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:462) ~[spring-data-commons-1.11.2.RELEASE.jar:na]
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:440) ~[spring-data-commons-1.11.2.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:61) ~[spring-data-commons-1.11.2.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99) ~[spring-tx-4.1.6.RELEASE.jar:na]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:281) ~[spring-tx-4.1.6.RELEASE.jar:na]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96) ~[spring-tx-4.1.6.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136) ~[spring-tx-4.1.6.RELEASE.jar:na]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92) ~[spring-aop-4.1.9.RELEASE.jar:4.1.9.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) ~[spring-aop-4.1.9.RELEASE.jar:na]
    at com.sun.proxy.$Proxy193.findOneByUri(Unknown Source) ~[na:na]
    at org.epnoi.storage.system.graph.repository.edges.UnifiedEdgeGraphRepository.lambda$delete$13(UnifiedEdgeGraphRepository.java:114) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.system.graph.repository.edges.UnifiedEdgeGraphRepository$$Lambda$58/1089583583.run(Unknown Source) ~[na:na]
    at org.epnoi.storage.actions.RepeatableActionExecutor.performRetries(RepeatableActionExecutor.java:40) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.RepeatableActionExecutor.performRetries(RepeatableActionExecutor.java:52) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.RepeatableActionExecutor.performRetries(RepeatableActionExecutor.java:52) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.RepeatableActionExecutor.performRetries(RepeatableActionExecutor.java:52) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.RepeatableActionExecutor.performRetries(RepeatableActionExecutor.java:52) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.RepeatableActionExecutor.performRetries(RepeatableActionExecutor.java:52) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.RepeatableActionExecutor.performRetries(RepeatableActionExecutor.java:52) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.system.graph.repository.edges.UnifiedEdgeGraphRepository.delete(UnifiedEdgeGraphRepository.java:113) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.DeleteRelationAction.lambda$in$24(DeleteRelationAction.java:82) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.storage.actions.DeleteRelationAction$$Lambda$51/1079024345.accept(Unknown Source) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184) [na:1.8.0_45]
    at java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1374) [na:1.8.0_45]
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:512) [na:1.8.0_45]
    at java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:291) [na:1.8.0_45]
    at java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:731) [na:1.8.0_45]
    at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289) [na:1.8.0_45]
    at java.util.concurrent.ForkJoinTask.doInvoke(ForkJoinTask.java:401) [na:1.8.0_45]
    at java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:734) [na:1.8.0_45]
    at java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:160) [na:1.8.0_45]
    at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:174) [na:1.8.0_45]
    at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233) [na:1.8.0_45]
    at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:418) [na:1.8.0_45]
    at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:583) [na:1.8.0_45]
    at org.epnoi.storage.actions.DeleteRelationAction.in(DeleteRelationAction.java:81) [epnoi-storage-0.2-SNAPSHOT.jar:na]
    at org.epnoi.comparator.tasks.SimilarityTask.run(SimilarityTask.java:46) [SimilarityTask.class:na]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) [spring-context-4.1.9.RELEASE.jar:4.1.9.RELEASE]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_45]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_45]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_45]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_45]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_45]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_45]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_45]
Caused by: org.apache.http.client.HttpResponseException: Not Found
    at org.neo4j.ogm.session.request.DefaultRequest.execute(DefaultRequest.java:100) ~[neo4j-ogm-1.1.5-BETA.jar:na]
    ... 67 common frames omitted
cbadenes commented 8 years ago
cbadenes commented 8 years ago
cbadenes commented 8 years ago
cbadenes commented 8 years ago

New Release: Spring Data Neo4j 4.1 Milestone 1 (February 23)

cbadenes commented 8 years ago

It seems fixed by updating library to version 4.1.0.M1 and implementing Neo4J-Templates for each relationship type. Issue moved to Enhacement until Neo4j implements Bolt serialization.

cbadenes commented 8 years ago

significant improvement by using Neo4j-Templates instead of Repositories:

Number of Documents: 50 Number of Items: 50 Number of Parts: 400 Number of Topics: 22 Number of Words: 10

Number of Terms: 10

Number of Provides: 50 Number of Composes: 1 Number of Contains: 50 Number of Bundles: 50 Number of Describes: 400 Number of Deals_With from Docs: 250 Number of Deals_With from Item: 300 Number of Deals_With from Parts: 4400 Number of EmergesIn: 22 Number of Mentions from Topics: 220 Number of Mentions from Terms: 100 Number of Similar Doc: 2500 Number of Similar Item: 2500 Number of Similar Part: 160000 Number of Embedded Words: 10 Number of AppearedIn: 10 Number of HypernymsOf: 100 Number of PairsWith: 100 17:25:49.686 [pool-1-thread-25] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Word),(b:Domain) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:EMBEDDED_IN { uri : {2}, creationTime : {3}, weight : {4} ,vector : {5} } ]->(b) RETURN r: 0 17:25:49.694 [pool-1-thread-22] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Term),(b:Word) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:MENTIONS { uri : {2}, creationTime : {3}, weight : {4} ,times : {5} } ]->(b) RETURN r: 0 17:25:49.694 [pool-1-thread-14] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Word),(b:Domain) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:EMBEDDED_IN { uri : {2}, creationTime : {3}, weight : {4} ,vector : {5} } ]->(b) RETURN r: 0 17:25:49.866 [pool-1-thread-19] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Topic),(b:Word) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:MENTIONS { uri : {2}, creationTime : {3}, weight : {4} ,times : {5} } ]->(b) RETURN r: 0 17:25:50.870 [pool-1-thread-25] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Part),(b:Item) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:DESCRIBES { uri : {2}, creationTime : {3}, weight : {4} } ]->(b) RETURN r: 0 17:25:50.875 [pool-1-thread-16] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Item),(b:Topic) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:DEALS_WITH { uri : {2}, creationTime : {3}, weight : {4} } ]->(b) RETURN r: 0 17:25:50.881 [pool-1-thread-7] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Part),(b:Topic) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:DEALS_WITH { uri : {2}, creationTime : {3}, weight : {4} } ]->(b) RETURN r: 0 17:25:50.883 [pool-1-thread-2] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Part),(b:Topic) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:DEALS_WITH { uri : {2}, creationTime : {3}, weight : {4} } ]->(b) RETURN r: 0 17:25:50.926 [pool-1-thread-11] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Part),(b:Topic) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:DEALS_WITH { uri : {2}, creationTime : {3}, weight : {4} } ]->(b) RETURN r: 0 17:25:50.928 [pool-1-thread-21] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Document),(b:Topic) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:DEALS_WITH { uri : {2}, creationTime : {3}, weight : {4} } ]->(b) RETURN r: 0 17:25:50.933 [pool-1-thread-10] WARN o.e.s.a.RepeatableActionExecutor - Trying to retry MATCH (a:Document),(b:Topic) WHERE a.uri = {0} AND b.uri = {1} CREATE (a)-[r:DEALS_WITH { uri : {2}, creationTime : {3}, weight : {4} } ]->(b) RETURN r: 0 17:25:59.624 [main] INFO o.e.s.ConsistencyTest - Checking step 17:25:59.665 [main] INFO o.e.s.ConsistencyTest - At this time: 4320 similar parts [160000] : 864.0rows/sec 17:26:04.670 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:04.733 [main] INFO o.e.s.ConsistencyTest - At this time: 9650 similar parts [160000] : 1066.0rows/sec 17:26:09.736 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:09.859 [main] INFO o.e.s.ConsistencyTest - At this time: 15060 similar parts [160000] : 1082.0rows/sec 17:26:14.860 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:14.965 [main] INFO o.e.s.ConsistencyTest - At this time: 18853 similar parts [160000] : 758.6rows/sec 17:26:19.970 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:20.075 [main] INFO o.e.s.ConsistencyTest - At this time: 25037 similar parts [160000] : 1236.8rows/sec 17:26:25.079 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:25.263 [main] INFO o.e.s.ConsistencyTest - At this time: 31588 similar parts [160000] : 1310.2rows/sec 17:26:30.265 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:30.407 [main] INFO o.e.s.ConsistencyTest - At this time: 38885 similar parts [160000] : 1459.4rows/sec 17:26:35.408 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:35.591 [main] INFO o.e.s.ConsistencyTest - At this time: 45864 similar parts [160000] : 1395.8rows/sec 17:26:40.594 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:40.806 [main] INFO o.e.s.ConsistencyTest - At this time: 53009 similar parts [160000] : 1429.0rows/sec 17:26:45.810 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:46.086 [main] INFO o.e.s.ConsistencyTest - At this time: 60177 similar parts [160000] : 1433.6rows/sec 17:26:51.090 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:51.411 [main] INFO o.e.s.ConsistencyTest - At this time: 67514 similar parts [160000] : 1467.4rows/sec 17:26:56.411 [main] INFO o.e.s.ConsistencyTest - Checking step 17:26:56.667 [main] INFO o.e.s.ConsistencyTest - At this time: 75267 similar parts [160000] : 1550.6rows/sec 17:27:01.669 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:02.007 [main] INFO o.e.s.ConsistencyTest - At this time: 83216 similar parts [160000] : 1589.8rows/sec 17:27:07.011 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:07.398 [main] INFO o.e.s.ConsistencyTest - At this time: 91129 similar parts [160000] : 1582.6rows/sec 17:27:12.402 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:12.759 [main] INFO o.e.s.ConsistencyTest - At this time: 99185 similar parts [160000] : 1611.2rows/sec 17:27:17.762 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:18.126 [main] INFO o.e.s.ConsistencyTest - At this time: 107158 similar parts [160000] : 1594.6rows/sec 17:27:23.130 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:23.549 [main] INFO o.e.s.ConsistencyTest - At this time: 115202 similar parts [160000] : 1608.8rows/sec 17:27:28.554 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:29.056 [main] INFO o.e.s.ConsistencyTest - At this time: 123303 similar parts [160000] : 1620.2rows/sec 17:27:34.058 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:34.599 [main] INFO o.e.s.ConsistencyTest - At this time: 131804 similar parts [160000] : 1700.2rows/sec 17:27:39.601 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:40.151 [main] INFO o.e.s.ConsistencyTest - At this time: 140167 similar parts [160000] : 1672.6rows/sec 17:27:45.156 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:45.649 [main] INFO o.e.s.ConsistencyTest - At this time: 148314 similar parts [160000] : 1629.4rows/sec 17:27:50.652 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:51.297 [main] INFO o.e.s.ConsistencyTest - At this time: 156719 similar parts [160000] : 1681.0rows/sec 17:27:56.301 [main] INFO o.e.s.ConsistencyTest - Checking step 17:27:56.938 [main] INFO o.e.s.ConsistencyTest - At this time: 160000 similar parts [160000] : 656.2rows/sec Time inserting data: 2 minutes, 8 seconds