egeria icon indicating copy to clipboard operation
egeria copied to clipboard

'building a data catalog' -also postgres integration - v.slow with graph repo

Open planetf1 opened this issue 4 years ago • 11 comments

Running through the 'building a data catalog' notebook takes around 2 minutes when using the local graph repo running locally (MacOS) in a coco pharma configuration, which seems rather slow. We don't expect berkeley+local graph to be particularly scalable - better suited to dev, but it still seems excessive.

Not done any profiling yet.

We have 290 incoming events, 60 ClassifiedEntityEvent 76 NewEntityEvent 80 NewRelationshipEvent 36 ReclassifiedEntityEvent 38 UpdatedEntityEvent

this is across all servers/platforms so some parallelism, but on an individual server (thread) is at around 1 'transaction' every 2-3 seconds

Needs investigating

planetf1 avatar Jun 17 '20 15:06 planetf1

Repeated... if we start with all the servers configured, started, and stabilized/idle, then with graph around 1:50 is typical, whilst inmemory takes around 22s. This is running locally (MBP 2016) otherwise fairly idle. CPU not maxing, low disk activity

While it's expected inmem would be many times faster than when using persistant storage, and for scaling, an external JanusGraph server is a more likely topology, the number of asset related API calls here is low - so we didn't manage many in a 2 minute period, which is a concern.

planetf1 avatar Aug 24 '20 12:08 planetf1

Taking a look with the YourKit profiler (CPU sampling & async sampling of the multiple chassis) it's not clear there's any particular hotspots when specifically running this notebook

This would probably benefit from a collective profiling session @grahamwallis @mandy-chessell and indeed a closer look at the logs/audit messages during the notebook run, and perhaps closer inspection of individual REST API calls.

planetf1 avatar Aug 24 '20 15:08 planetf1

Whilst sampling (regular or async) didn't identify any delays, a full trace does seem to indicate a lot of time (in my case 34s - and the only execution was the noetbook at 1:50 total) in

AssetHandler.java:3801 org.odpi.openmetadata.commonservices.repositoryhandler.RepositoryHandler.getEntitiesByName(String, InstanceProperties, String, int, int, String) 34651

And indeed digging deeper 25s of this in the following backtrace:

org.springframework.web.client.RestTemplate.postForObject(String, Object, Class, Object[]) RestTemplate.java
org.odpi.openmetadata.adapters.connectors.restclients.spring.SpringRESTClientConnector.callPostRESTCall(String, Class, String, Object, Object[]) SpringRESTClientConnector.java:439
org.odpi.openmetadata.repositoryservices.clients.MetadataCollectionServicesClient.callPostRESTCall(String, Class, String, Object, Object[]) MetadataCollectionServicesClient.java:5018
org.odpi.openmetadata.repositoryservices.clients.MetadataCollectionServicesClient.callEntityListPostRESTCall(String, String, Object, Object[]) MetadataCollectionServicesClient.java:4740
org.odpi.openmetadata.repositoryservices.clients.MetadataCollectionServicesClient.findEntitiesByProperty(String, String, InstanceProperties, MatchCriteria, int, List, List, Date, String, SequencingOrder, int) MetadataCollectionServicesClient.java:1513
org.odpi.openmetadata.adapters.repositoryservices.rest.repositoryconnector.OMRSRESTMetadataCollection.findEntitiesByProperty(String, String, InstanceProperties, MatchCriteria, int, List, List, Date, String, SequencingOrder, int) OMRSRESTMetadataCollection.java:1077
org.odpi.openmetadata.repositoryservices.enterprise.repositoryconnector.executors.FindEntitiesByPropertyExecutor.issueRequestToRepository(String, OMRSMetadataCollection) FindEntitiesByPropertyExecutor.java:187
org.odpi.openmetadata.repositoryservices.enterprise.repositoryconnector.control.ParallelFederationControl.executeCommand(RepositoryExecutor) ParallelFederationControl.java:56
org.odpi.openmetadata.repositoryservices.enterprise.repositoryconnector.EnterpriseOMRSMetadataCollection.findEntitiesByProperty(String, String, InstanceProperties, MatchCriteria, int, List, List, Date, String, SequencingOrder, int) EnterpriseOMRSMetadataCollection.java:1241
org.odpi.openmetadata.commonservices.repositoryhandler.RepositoryHandler.getEntitiesByName(String, InstanceProperties, String, int, int, String) RepositoryHandler.java:1905
org.odpi.openmetadata.commonservices.ocf.metadatamanagement.handlers.AssetHandler.findAssets(String, String, String, int, int, String) AssetHandler.java:3801
org.odpi.openmetadata.commonservices.ocf.metadatamanagement.handlers.AssetHandler.findAssets(String, String, int, int, String) AssetHandler.java:3752
org.odpi.openmetadata.commonservices.ocf.metadatamanagement.handlers.AssetHandler.findAssetGUIDs(String, String, int, int, String) AssetHandler.java:3724
org.odpi.openmetadata.accessservices.assetconsumer.server.AssetConsumerRESTServices.findAssets(String, String, String, int, int) AssetConsumerRESTServices.java:126
org.odpi.openmetadata.accessservices.assetconsumer.server.spring.AssetConsumerResource.findAssets(String, String, int, int, String) AssetConsumerResource.java:288
jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) NativeMethodAccessorImpl.java (native)
jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Object, Object[]) NativeMethodAccessorImpl.java:62
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Object, Object[]) DelegatingMethodAccessorImpl.java:43
java.lang.reflect.Method.invoke(Object, Object[]) Method.java:564
org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(Object[]) InvocableHandlerMethod.java:190
org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(NativeWebRequest, ModelAndViewContainer, Object[]) InvocableHandlerMethod.java:138
org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletWebRequest, ModelAndViewContainer, Object[]) ServletInvocableHandlerMethod.java:105
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(HttpServletRequest, HttpServletResponse, HandlerMethod) RequestMappingHandlerAdapter.java:878
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(HttpServletRequest, HttpServletResponse, HandlerMethod) RequestMappingHandlerAdapter.java:792
org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(HttpServletRequest, HttpServletResponse, Object) AbstractHandlerMethodAdapter.java:87
org.springframework.web.servlet.DispatcherServlet.doDispatch(HttpServletRequest, HttpServletResponse) DispatcherServlet.java:1040
org.springframework.web.servlet.DispatcherServlet.doService(HttpServletRequest, HttpServletResponse) DispatcherServlet.java:943
org.springframework.web.servlet.FrameworkServlet.processRequest(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:1006
org.springframework.web.servlet.FrameworkServlet.doPost(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:909
javax.servlet.http.HttpServlet.service(HttpServletRequest, HttpServletResponse) HttpServlet.java:652
org.springframework.web.servlet.FrameworkServlet.service(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:883
javax.servlet.http.HttpServlet.service(ServletRequest, ServletResponse) HttpServlet.java:733
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:231
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.tomcat.websocket.server.WsFilter.doFilter(ServletRequest, ServletResponse, FilterChain) WsFilter.java:53
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.RequestContextFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) RequestContextFilter.java:100
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.FormContentFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) FormContentFilter.java:93
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) WebMvcMetricsFilter.java:93
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) CharacterEncodingFilter.java:201
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.catalina.core.StandardWrapperValve.invoke(Request, Response) StandardWrapperValve.java:202
org.apache.catalina.core.StandardContextValve.invoke(Request, Response) StandardContextValve.java:96
org.apache.catalina.authenticator.AuthenticatorBase.invoke(Request, Response) AuthenticatorBase.java:541
org.apache.catalina.core.StandardHostValve.invoke(Request, Response) StandardHostValve.java:139
org.apache.catalina.valves.ErrorReportValve.invoke(Request, Response) ErrorReportValve.java:92
org.apache.catalina.core.StandardEngineValve.invoke(Request, Response) StandardEngineValve.java:74
org.apache.catalina.connector.CoyoteAdapter.service(Request, Response) CoyoteAdapter.java:343
org.apache.coyote.http11.Http11Processor.service(SocketWrapperBase) Http11Processor.java:373
org.apache.coyote.AbstractProcessorLight.process(SocketWrapperBase, SocketEvent) AbstractProcessorLight.java:65
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(SocketWrapperBase, SocketEvent) AbstractProtocol.java:868
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun() NioEndpoint.java:1589
org.apache.tomcat.util.net.SocketProcessorBase.run() SocketProcessorBase.java:49
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) ThreadPoolExecutor.java:1130
java.util.concurrent.ThreadPoolExecutor$Worker.run() ThreadPoolExecutor.java:630
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run() TaskThread.java:61
java.lang.Thread.run() Thread.java:832

This is elapsed time

The next significant backtrace is in the graph db itself - in this case in lucene with 17s:

org.janusgraph.diskstorage.lucene.LuceneIndex.query(IndexQuery, KeyInformation$IndexRetriever, BaseTransaction) LuceneIndex.java
org.janusgraph.diskstorage.indexing.IndexTransaction.queryStream(IndexQuery) IndexTransaction.java:108
org.janusgraph.diskstorage.BackendTransaction$6.call() BackendTransaction.java:416
org.janusgraph.diskstorage.BackendTransaction$6.call() BackendTransaction.java:413
org.janusgraph.diskstorage.util.BackendOperation.executeDirect(Callable, Duration) BackendOperation.java:68
org.janusgraph.diskstorage.util.BackendOperation.execute(Callable, Duration) BackendOperation.java:54
org.janusgraph.diskstorage.BackendTransaction.executeRead(Callable) BackendTransaction.java:469
org.janusgraph.diskstorage.BackendTransaction.indexQuery(String, IndexQuery) BackendTransaction.java:413
org.janusgraph.graphdb.database.IndexSerializer.query(JointIndexQuery$Subquery, BackendTransaction) IndexSerializer.java:533
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.lambda$null$3(JointIndexQuery$Subquery) StandardJanusGraphTx.java:1332
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3$$Lambda$1269.apply(Object)
org.janusgraph.graphdb.query.profile.QueryProfiler.profile(String, QueryProfiler, Query, boolean, Function) QueryProfiler.java:99
org.janusgraph.graphdb.query.profile.QueryProfiler.profile(QueryProfiler, Query, boolean, Function) QueryProfiler.java:91
org.janusgraph.graphdb.query.profile.QueryProfiler.profile(QueryProfiler, Query, Function) QueryProfiler.java:83
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.lambda$null$4(JointIndexQuery$Subquery, JointIndexQuery$Subquery) StandardJanusGraphTx.java:1332
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3$$Lambda$1268.call()
com.google.common.cache.LocalCache$LocalManualCache$1.load(Object) LocalCache.java:4876
com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(Object, CacheLoader) LocalCache.java:3529
com.google.common.cache.LocalCache$Segment.loadSync(Object, int, LocalCache$LoadingValueReference, CacheLoader) LocalCache.java:2278
com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(Object, int, CacheLoader) LocalCache.java:2155
com.google.common.cache.LocalCache$Segment.get(Object, int, CacheLoader) LocalCache.java:2045
com.google.common.cache.LocalCache.get(Object, CacheLoader) LocalCache.java:3951
com.google.common.cache.LocalCache$LocalManualCache.get(Object, Callable) LocalCache.java:4871
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.lambda$execute$5(JointIndexQuery$Subquery, int) StandardJanusGraphTx.java:1331
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3$$Lambda$1267.call(int)
org.janusgraph.graphdb.query.QueryUtil.processIntersectingRetrievals(List, int) QueryUtil.java:316
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.execute(GraphCentricQuery, JointIndexQuery, Object, QueryProfiler) StandardJanusGraphTx.java:1341
org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.execute(ElementQuery, BackendQuery, Object, QueryProfiler) StandardJanusGraphTx.java:1233
org.janusgraph.graphdb.query.QueryProcessor$LimitAdjustingIterator.getNewIterator(int) QueryProcessor.java:194
org.janusgraph.graphdb.query.LimitAdjustingIterator.hasNext() LimitAdjustingIterator.java:68
com.google.common.collect.Iterators$5.computeNext() Iterators.java:635
com.google.common.collect.AbstractIterator.tryToComputeNext() AbstractIterator.java:141
com.google.common.collect.AbstractIterator.hasNext() AbstractIterator.java:136
org.janusgraph.graphdb.query.ResultSetIterator.nextInternal() ResultSetIterator.java:54
org.janusgraph.graphdb.query.ResultSetIterator.<init>(Iterator, int) ResultSetIterator.java:44
org.janusgraph.graphdb.query.QueryProcessor.iterator() QueryProcessor.java:66
com.google.common.collect.Iterables$4.iterator() Iterables.java:559
org.janusgraph.graphdb.tinkerpop.optimize.JanusGraphStep.executeGraphCentricQuery(GraphCentricQueryBuilder, List, Map$Entry) JanusGraphStep.java:155
org.janusgraph.graphdb.tinkerpop.optimize.JanusGraphStep.lambda$null$1(GraphCentricQueryBuilder, List, Map$Entry) JanusGraphStep.java:94
org.janusgraph.graphdb.tinkerpop.optimize.JanusGraphStep$$Lambda$1027.accept(Object)
java.lang.Iterable.forEach(Consumer) Iterable.java:75
org.janusgraph.graphdb.tinkerpop.optimize.JanusGraphStep.lambda$new$2() JanusGraphStep.java:94
org.janusgraph.graphdb.tinkerpop.optimize.JanusGraphStep$$Lambda$1003.get()
org.apache.tinkerpop.gremlin.process.traversal.step.map.GraphStep.processNextStart() GraphStep.java:157
org.apache.tinkerpop.gremlin.process.traversal.step.util.AbstractStep.hasNext() AbstractStep.java:143
org.apache.tinkerpop.gremlin.process.traversal.util.DefaultTraversal.hasNext() DefaultTraversal.java:197
org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSMetadataStore.findEntitiesByProperty(String, InstanceProperties, MatchCriteria, Boolean) GraphOMRSMetadataStore.java:1715
org.odpi.openmetadata.adapters.repositoryservices.graphrepository.repositoryconnector.GraphOMRSMetadataCollection.findEntitiesByProperty(String, String, InstanceProperties, MatchCriteria, int, List, List, Date, String, SequencingOrder, int) GraphOMRSMetadataCollection.java:1246
org.odpi.openmetadata.repositoryservices.localrepository.repositoryconnector.LocalOMRSMetadataCollection.findEntitiesByProperty(String, String, InstanceProperties, MatchCriteria, int, List, List, Date, String, SequencingOrder, int) LocalOMRSMetadataCollection.java:1922
org.odpi.openmetadata.repositoryservices.rest.server.OMRSRepositoryRESTServices.findEntitiesByProperty(String, String, EntityPropertyFindRequest) OMRSRepositoryRESTServices.java:2572
org.odpi.openmetadata.repositoryservices.rest.server.spring.LocalRepositoryServicesResource.findEntitiesByProperty(String, String, EntityPropertyFindRequest) LocalRepositoryServicesResource.java:873
jdk.internal.reflect.GeneratedMethodAccessor578.invoke(Object, Object[])
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Object, Object[]) DelegatingMethodAccessorImpl.java:43
java.lang.reflect.Method.invoke(Object, Object[]) Method.java:564
org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(Object[]) InvocableHandlerMethod.java:190
org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(NativeWebRequest, ModelAndViewContainer, Object[]) InvocableHandlerMethod.java:138
org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletWebRequest, ModelAndViewContainer, Object[]) ServletInvocableHandlerMethod.java:105
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(HttpServletRequest, HttpServletResponse, HandlerMethod) RequestMappingHandlerAdapter.java:878
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(HttpServletRequest, HttpServletResponse, HandlerMethod) RequestMappingHandlerAdapter.java:792
org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(HttpServletRequest, HttpServletResponse, Object) AbstractHandlerMethodAdapter.java:87
org.springframework.web.servlet.DispatcherServlet.doDispatch(HttpServletRequest, HttpServletResponse) DispatcherServlet.java:1040
org.springframework.web.servlet.DispatcherServlet.doService(HttpServletRequest, HttpServletResponse) DispatcherServlet.java:943
org.springframework.web.servlet.FrameworkServlet.processRequest(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:1006
org.springframework.web.servlet.FrameworkServlet.doPost(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:909
javax.servlet.http.HttpServlet.service(HttpServletRequest, HttpServletResponse) HttpServlet.java:652
org.springframework.web.servlet.FrameworkServlet.service(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:883
javax.servlet.http.HttpServlet.service(ServletRequest, ServletResponse) HttpServlet.java:733
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:231
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.tomcat.websocket.server.WsFilter.doFilter(ServletRequest, ServletResponse, FilterChain) WsFilter.java:53
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.RequestContextFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) RequestContextFilter.java:100
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.FormContentFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) FormContentFilter.java:93
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) WebMvcMetricsFilter.java:93
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) CharacterEncodingFilter.java:201
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.catalina.core.StandardWrapperValve.invoke(Request, Response) StandardWrapperValve.java:202
org.apache.catalina.core.StandardContextValve.invoke(Request, Response) StandardContextValve.java:96
org.apache.catalina.authenticator.AuthenticatorBase.invoke(Request, Response) AuthenticatorBase.java:541
org.apache.catalina.core.StandardHostValve.invoke(Request, Response) StandardHostValve.java:139
org.apache.catalina.valves.ErrorReportValve.invoke(Request, Response) ErrorReportValve.java:92
org.apache.catalina.core.StandardEngineValve.invoke(Request, Response) StandardEngineValve.java:74
org.apache.catalina.connector.CoyoteAdapter.service(Request, Response) CoyoteAdapter.java:343
org.apache.coyote.http11.Http11Processor.service(SocketWrapperBase) Http11Processor.java:373
org.apache.coyote.AbstractProcessorLight.process(SocketWrapperBase, SocketEvent) AbstractProcessorLight.java:65
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(SocketWrapperBase, SocketEvent) AbstractProtocol.java:868
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun() NioEndpoint.java:1589
org.apache.tomcat.util.net.SocketProcessorBase.run() SocketProcessorBase.java:49
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) ThreadPoolExecutor.java:1130
java.util.concurrent.ThreadPoolExecutor$Worker.run() ThreadPoolExecutor.java:630
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run() TaskThread.java:61
java.lang.Thread.run() Thread.java:832

We also get a fair few seconds updating a classification - and this pattern is repeated for other writes along the lines of:

org.springframework.web.client.RestTemplate.postForObject(String, Object, Class, Object[]) RestTemplate.java
org.odpi.openmetadata.adapters.connectors.restclients.spring.SpringRESTClientConnector.callPostRESTCall(String, Class, String, Object, Object[]) SpringRESTClientConnector.java:439
org.odpi.openmetadata.repositoryservices.clients.MetadataCollectionServicesClient.callPostRESTCall(String, Class, String, Object, Object[]) MetadataCollectionServicesClient.java:5018
org.odpi.openmetadata.repositoryservices.clients.MetadataCollectionServicesClient.callEntityDetailPostRESTCall(String, String, Object, Object[]) MetadataCollectionServicesClient.java:4677
org.odpi.openmetadata.repositoryservices.clients.MetadataCollectionServicesClient.updateEntityClassification(String, String, String, InstanceProperties) MetadataCollectionServicesClient.java:3070
org.odpi.openmetadata.adapters.repositoryservices.rest.repositoryconnector.OMRSRESTMetadataCollection.updateEntityClassification(String, String, String, InstanceProperties) OMRSRESTMetadataCollection.java:2065
org.odpi.openmetadata.repositoryservices.enterprise.repositoryconnector.EnterpriseOMRSMetadataCollection.updateEntityClassification(String, String, String, InstanceProperties) EnterpriseOMRSMetadataCollection.java:3131
org.odpi.openmetadata.commonservices.repositoryhandler.RepositoryHandler.reclassifyEntity(String, String, String, String, InstanceProperties, String) RepositoryHandler.java:698
org.odpi.openmetadata.commonservices.ocf.metadatamanagement.handlers.AssetHandler.reclassifyAsset(String, Asset, Asset, InstanceProperties, InstanceProperties, InstanceProperties, String) AssetHandler.java:1862
org.odpi.openmetadata.commonservices.ocf.metadatamanagement.handlers.AssetHandler.updateAsset(String, Asset, AssetAuditHeader, Asset, SchemaType, List, Connection, String) AssetHandler.java:1679
org.odpi.openmetadata.commonservices.ocf.metadatamanagement.handlers.AssetHandler.updateAssetOwner(String, String, String, OwnerType, String) AssetHandler.java:2341
org.odpi.openmetadata.accessservices.assetowner.server.AssetOwnerRESTServices.updateAssetOwner(String, String, String, OwnerRequestBody) AssetOwnerRESTServices.java:1082
org.odpi.openmetadata.accessservices.assetowner.server.spring.AssetOwnerResource.updateAssetOwner(String, String, String, OwnerRequestBody) AssetOwnerResource.java:611
jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) NativeMethodAccessorImpl.java (native)
jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Object, Object[]) NativeMethodAccessorImpl.java:62
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Object, Object[]) DelegatingMethodAccessorImpl.java:43
java.lang.reflect.Method.invoke(Object, Object[]) Method.java:564
org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(Object[]) InvocableHandlerMethod.java:190
org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(NativeWebRequest, ModelAndViewContainer, Object[]) InvocableHandlerMethod.java:138
org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletWebRequest, ModelAndViewContainer, Object[]) ServletInvocableHandlerMethod.java:105
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(HttpServletRequest, HttpServletResponse, HandlerMethod) RequestMappingHandlerAdapter.java:878
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(HttpServletRequest, HttpServletResponse, HandlerMethod) RequestMappingHandlerAdapter.java:792
org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(HttpServletRequest, HttpServletResponse, Object) AbstractHandlerMethodAdapter.java:87
org.springframework.web.servlet.DispatcherServlet.doDispatch(HttpServletRequest, HttpServletResponse) DispatcherServlet.java:1040
org.springframework.web.servlet.DispatcherServlet.doService(HttpServletRequest, HttpServletResponse) DispatcherServlet.java:943
org.springframework.web.servlet.FrameworkServlet.processRequest(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:1006
org.springframework.web.servlet.FrameworkServlet.doPost(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:909
javax.servlet.http.HttpServlet.service(HttpServletRequest, HttpServletResponse) HttpServlet.java:652
org.springframework.web.servlet.FrameworkServlet.service(HttpServletRequest, HttpServletResponse) FrameworkServlet.java:883
javax.servlet.http.HttpServlet.service(ServletRequest, ServletResponse) HttpServlet.java:733
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:231
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.tomcat.websocket.server.WsFilter.doFilter(ServletRequest, ServletResponse, FilterChain) WsFilter.java:53
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.RequestContextFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) RequestContextFilter.java:100
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.FormContentFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) FormContentFilter.java:93
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) WebMvcMetricsFilter.java:93
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(HttpServletRequest, HttpServletResponse, FilterChain) CharacterEncodingFilter.java:201
org.springframework.web.filter.OncePerRequestFilter.doFilter(ServletRequest, ServletResponse, FilterChain) OncePerRequestFilter.java:119
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:193
org.apache.catalina.core.ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) ApplicationFilterChain.java:166
org.apache.catalina.core.StandardWrapperValve.invoke(Request, Response) StandardWrapperValve.java:202
org.apache.catalina.core.StandardContextValve.invoke(Request, Response) StandardContextValve.java:96
org.apache.catalina.authenticator.AuthenticatorBase.invoke(Request, Response) AuthenticatorBase.java:541
org.apache.catalina.core.StandardHostValve.invoke(Request, Response) StandardHostValve.java:139
org.apache.catalina.valves.ErrorReportValve.invoke(Request, Response) ErrorReportValve.java:92
org.apache.catalina.core.StandardEngineValve.invoke(Request, Response) StandardEngineValve.java:74
org.apache.catalina.connector.CoyoteAdapter.service(Request, Response) CoyoteAdapter.java:343
org.apache.coyote.http11.Http11Processor.service(SocketWrapperBase) Http11Processor.java:373
org.apache.coyote.AbstractProcessorLight.process(SocketWrapperBase, SocketEvent) AbstractProcessorLight.java:65
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(SocketWrapperBase, SocketEvent) AbstractProtocol.java:868
org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun() NioEndpoint.java:1589
org.apache.tomcat.util.net.SocketProcessorBase.run() SocketProcessorBase.java:49
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) ThreadPoolExecutor.java:1130
java.util.concurrent.ThreadPoolExecutor$Worker.run() ThreadPoolExecutor.java:630
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run() TaskThread.java:61
java.lang.Thread.run() Thread.java:832

Warrants team discussion.

Embedded rest calls seem to be causing the high latency here - but a comparison with inmem (since the behaviour should be the same?) may be worthwhile. Also note this behaviour is in a cohort - although that is typical.

cc: @mandy-chessell

planetf1 avatar Aug 25 '20 08:08 planetf1

Discussed on status call 25 Aug - Agreed to repeat these tests after a large set of changes is integrated in the next week.

planetf1 avatar Aug 25 '20 09:08 planetf1

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar Jan 26 '21 00:01 github-actions[bot]

This should be retested after performance changes made in 2.7, plus new support in our demo environment for graph/persistence

planetf1 avatar Feb 04 '21 12:02 planetf1

This doesn't seem so slow when I tried again, taking just over a minute to work through the process. some queries (including python) take up to 5s but I don't see anything specifically actionable here -- other performance tests have been done, and we will revisit this area if/when splitting up the front/backend for the graph repo, so closing for now.

planetf1 avatar Mar 10 '21 17:03 planetf1

Performance problems are becoming apparent with the graph repository more generally

Experimenting with the Postgres connector. Interesting observation - to pull in the metadata from a sample customer db takes 2 mins with inmemory - which is ok (java maxes cpu, ~9000 events)

Same using the default Janusgraph implementation - 1 hr 15 mins.

I/O is probably killing it on mac. Added latency. (seen as java maxes at less than 1 core’s worth)

Of course Janus is untuned, and using local single threaded embedded version with berkelydb

See https://github.com/odpi/egeria-charts/issues/125 to use XTDB in these demos.

planetf1 avatar Feb 09 '22 17:02 planetf1

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar May 03 '22 00:05 github-actions[bot]

Checked with 3.10-SNAPSHOT. Similar times

planetf1 avatar Jun 17 '22 15:06 planetf1

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar Aug 17 '22 00:08 github-actions[bot]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar Oct 17 '22 01:10 github-actions[bot]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar Dec 31 '22 00:12 github-actions[bot]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar Mar 05 '23 00:03 github-actions[bot]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 20 days if no further activity occurs. Thank you for your contributions.

github-actions[bot] avatar May 08 '23 00:05 github-actions[bot]

Closing this given broader performance discussions are ongoing, and some recent tests have occurred, as well as improvements cc: @dwolfson

planetf1 avatar May 23 '23 12:05 planetf1