Hi, first of all I suggest you to update to 2.1.2 (released a few days ago) and try again. Do you think you can provide a simple test case to reproduce the issue? I would help a lot on our side
Thanks Luigi 2015-09-11 23:59 GMT+02:00 Chris Gomes <[email protected]>: > > Hello, > I really hope someone can shed some light on the performance issues that we > have been experiencing. Thank you much in advance. > > Regards, > -Chris > > I have attached 2 html files - one is heap dump of OrientDB server and the > other is App 2 VM. > Below is also partial stack trace of App 2 and some code snippet where main > transaction boundaries are. > > We are getting long commit time and eventually runs out of memory, currently > *Orient *is becoming *unusable *for what we are trying to do with client *App > 2* as described below. > > *Background*: > Database Server instance using Java 8 > 1) We run OrientDB using server.sh/bat as a standalone and with 1G of heap > space and default Disk Cache > Databases > 2) We have 2 databases created as plocal and graph, let's name them, > Expansion & Universe. > 3) 2 have 2 client applications, both are spring boot project with an > embedded jetty container, run as executable jars > > *Java Client Applications - Spring Boot using Java 8* > 4) App 1 - reads a large xml file (670 Meg and process each business unit of > at a time) and create Vertices and Edges based on the > business concepts described in the xml. NOTE, in both app we define the > schema for Vertices and Edge Type definitions. > For APP 1, Expansion DB barely has any index as we mostly write blindly as > an expansion of elements from XML. BUT, we will need to read the data > from APP 2. To load the file and expand the xml int vertex and edge > representation it takes anywhere from 55 to 2 hours, depending on SSD vs > regular disk, this is on a brand new clean DB. > > One thing that is clear, as data grows, same data file loaded again will take > longer to load, seems like linear growth. I noticed something in the forum > about this already. > This file has about 35,000 business unit worth of data. The raw size in DB is > 2,610,075 edges, 2,610,076 vertices. We have defined about 16 Vertices > (vertex types) and 23 Edges (edge types) in Expansion and Universe DB. > This is just one file and we will get incremental update everyday and will > grow over the time. So, we would need to be able to handle large amount of > data in MANY millions in both databases. > > App 1 runs fine with 256Meg of heap space and though it gets slower over the > time, it runs. > > *5) App 2 *- All edge types have non unique index as we need to look for > existing of vertices in an edge as well as we keep history of relationships > as in what point a relationship is no longer current. > We also have index for some of the Vertex where we have some business key we > need to query on. Overall # of indices are certainly much more than Expansion > DB, > but not overwhelming as we would be doing lot of bulk writing (create/update > vertices, create/update edges) as well as reading to look for existing > vertices or edges. > > 6) NOTE, we use connection pool and transaction. Our transaction boundary > would process a Business unit worth of data, which translates into* average > of 100 vertices/edges.* > However some extreme cases we could end up creating/updating about *1500 > vertices/edges*. > 7) App 2 has 2 Graph connection Factory one for each DB (Expansion and > Universe). App reads one Business unit worth of vertices/edges from Expansion > DB and in a transaction writes (create/update/lookup) into Universe DB. > *Average for this varies from 2 sec to 4 secs depending on SSD vs non-SSD > disks. * > > *8) With 1G of heap for the App2, it will eventually get out of memory > exception.* I have only been able to process 30,000 business units read from > Expansion DB and it took over 11 hours before getting out of memory. > This is on a SSD drive. At this performance, the app and DB becomes pretty > much unusable. > > 9) Tried few suggestions based on forum and documentation - *disabling > transaction log, but I don't think it made any real difference*. > > *Here's the stack trace from App 2. I have also heap dumps from both OrientDB > server and App 2.* > > Would love some insights as to what the options are. I am curious if anyone > else is using OrientDB for something like the way I described. I don't think > this usecase is anything out of the ordinary. > > *--- Stack Trace from Client App 2: Note, Caused by: > java.lang.OutOfMemoryError: Java heap space---* > > 2015-09-11 04:11:16.858 DEBUG 1132 --- [qtp174969681-23] > .b.u.u.UniverseMergeRequestServiceFacade : Processed 30555 statements with an > average of 1332 milliseconds > 2015-09-11 04:17:52.406 DEBUG 1132 --- [qtp174969681-23] > c.b.u.u.StatementUniverseMergeService : > {"delivery-id":"1e556f40-7e00-d9ba-9464-22000b9447eb","log-type":"universe-merge-statement","universe-merge-request-uuid":"c0fbbf7d-358e-4a01-a5c1-44007a311aab","statement-uid":"1e4ed31a-3631-df77-b997-22000a4590b6"} > 2015-09-11 04:17:55.268 DEBUG 1132 --- [qtp174969681-23] > c.b.u.u.StatementUniverseMergeService : > {"delivery-id":"1e556f40-7e00-d9ba-9464-22000b9447eb","log-type":"universe-merge-statement","universe-merge-request-uuid":"c0fbbf7d-358e-4a01-a5c1-44007a311aab","statement-uid":"1e4ed31a-3f9b-d96a-b997-22000a4590b6"} > 2015-09-11 04:18:01.435 DEBUG 1132 --- [qtp174969681-23] > c.b.u.u.StatementUniverseMergeService : > {"delivery-id":"1e556f40-7e00-d9ba-9464-22000b9447eb","log-type":"universe-merge-statement","universe-merge-request-uuid":"c0fbbf7d-358e-4a01-a5c1-44007a311aab","statement-uid":"1e4ed31a-3fe7-d518-b997-22000a4590b6"} > 2015-09-11 04:34:02.328 ERROR 1132 --- [qtp174969681-23] > .b.u.u.UniverseMergeRequestServiceFacade : Universe merge request for > deliveries failed for extraction date > 2001-01-01 00:00:00.0 > > com.bps.commons.exception.StateDumpException: Exception thrown when creating > the statement due to Exception during response processing. > at > com.bps.urjanet.universe.StatementUniverseMergeService.merge(StatementUniverseMergeService.java:97) > at > com.bps.urjanet.universe.UniverseMergeRequestServiceFacade.processMergeRequest(UniverseMergeRequestServiceFacade.java:87) > at > com.bps.urjanet.universe.resource.UniverseMergeResource.requestUniverseMerge(UniverseMergeResource.java:47) > at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) > at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) > at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) > at java.lang.reflect.Method.invoke(Unknown Source) > at > org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) > at > org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:151) > at > org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:172) > at > org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:152) > at > org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:104) > at > org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:384) > at > org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:342) > at > org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:101) > at > org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:271) > at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) > at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) > at org.glassfish.jersey.internal.Errors.process(Errors.java:315) > at org.glassfish.jersey.internal.Errors.process(Errors.java:297) > at org.glassfish.jersey.internal.Errors.process(Errors.java:267) > at > org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:297) > at > org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:254) > at > org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1030) > at > org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:377) > at > org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:381) > at > org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:344) > at > org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:221) > at > org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669) > at > org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:224) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.springframework.boot.actuate.autoconfigure.EndpointWebMvcAutoConfiguration$ApplicationContextHeaderFilter.doFilterInternal(EndpointWebMvcAutoConfiguration.java:291) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:102) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) > at > org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) > at > org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:201) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:57) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) > at > org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) > at > org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:85) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.springframework.boot.actuate.autoconfigure.MetricFilterAutoConfiguration$MetricsFilter.doFilterInternal(MetricFilterAutoConfiguration.java:90) > at > org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) > at > org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) > at > org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) > at > org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) > at > org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577) > at > org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223) > at > org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) > at > org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) > at > org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) > at > org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) > at > org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) > at > org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) > at org.eclipse.jetty.server.Server.handle(Server.java:497) > at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310) > at > org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257) > at > org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) > at > org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) > at > org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) > at java.lang.Thread.run(Unknown Source) > Caused by: > com.orientechnologies.orient.enterprise.channel.binary.OResponseProcessingException: > Exception during response processing. > at > com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.throwSerializedException(OChannelBinaryAsynchClient.java:445) > at > com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.handleStatus(OChannelBinaryAsynchClient.java:400) > at > com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:282) > at > com.orientechnologies.orient.enterprise.channel.binary.OChannelBinaryAsynchClient.beginResponse(OChannelBinaryAsynchClient.java:171) > at > com.orientechnologies.orient.client.remote.OStorageRemote.beginResponse(OStorageRemote.java:2136) > at > com.orientechnologies.orient.client.remote.OStorageRemote.commit(OStorageRemote.java:1364) > at > com.orientechnologies.orient.client.remote.OStorageRemoteThread.commit(OStorageRemoteThread.java:448) > at > com.orientechnologies.orient.core.tx.OTransactionOptimistic.doCommit(OTransactionOptimistic.java:596) > at > com.orientechnologies.orient.core.tx.OTransactionOptimistic.commit(OTransactionOptimistic.java:156) > at > com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2578) > at > com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2547) > at > com.tinkerpop.blueprints.impls.orient.OrientTransactionalGraph.commit(OrientTransactionalGraph.java:161) > > > > * at > com.bps.urjanet.universe.StatementUniverseMergeService.merge(StatementUniverseMergeService.java:85) > ... 95 common frames omittedCaused by: java.lang.OutOfMemoryError: Java > heap space* > 2015-09-11 04:34:02.349 ERROR 1132 --- [qtp174969681-23] > c.b.u.u.r.StateDumpExceptionMapper : > StateDumpExceptionMapper>>toResponse:Error Occured: Exception thrown when > updating the StatementsDelivery due to Transaction was rolled back more times > than it was started. > Transaction was rolled back more times than it was started. > > > com.bps.commons.exception.StateDumpException: Exception thrown when updating > the StatementsDelivery due to Transaction was rolled back more times than it > was started. > ... > Caused by: com.orientechnologies.orient.core.exception.OTransactionException: > Transaction was rolled back more times than it was started. > at > com.orientechnologies.orient.core.tx.OTransactionOptimistic.rollback(OTransactionOptimistic.java:188) > at > com.orientechnologies.orient.core.tx.OTransactionOptimistic.rollback(OTransactionOptimistic.java:169) > at > com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.endResponse(ONetworkProtocolBinary.java:1764) > at > com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.readRecord(ONetworkProtocolBinary.java:1662) > at > com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.executeRequest(ONetworkProtocolBinary.java:353) > at > com.orientechnologies.orient.server.network.protocol.binary.OBinaryNetworkProtocolAbstract.execute(OBinaryNetworkProtocolAbstract.java:223) > at > com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77) > > > > *///Code snippet of where the main transaction processing happens. This > method is called from another service to loop for each Business unit of > work.As you can see, each business unit of work is where transactions are > happening. * > > public TreeVertex merge(params...){ > > List<Reference> references = new ArrayList<>(); > List<MeasurementPeriod> measurementPeriods = new ArrayList<>(); > List<SummaryData> summaryDatas = new ArrayList<>(); > List<RateComponents> rateComponentsList = new ArrayList<>(); > Map<String, OrientVertex> vertexMap = new HashMap<>(); //<UID, > Vertex> Only objects that have a UID that are created in process. > > *OrientGraph mergedGraph = > this.orientUniverseGraphFactory.getTx();* //Exception should flow through. > This is a problem. > OrientVertex statement = null; > > try { > *mergedGraph.begin();* > > *mergedGraph.getRawGraph().getTransaction().setUsingLog(false);* > > > statementProcessor.endEdgesWithStatementUid(mergedGraph, uid); //If any > edges are found with the statement UID, then end those relationships. > > statement = process(mergedGraph, expandedTreeVertex, > deliveryId, uid, vertexMap, > references, measurementPeriods, > summaryDatas, rateComponentsList > ); > > *mergedGraph.commit();* > > } catch (Exception e) { > *mergedGraph.rollback();* > > throw new StateDumpException("Exception thrown when > creating the statement due to " + e.getMessage(), e) > .addStateDump("universeMergeRequestUuid", > universeMergeRequestUuid) > .addStateDump("deliveryId", deliveryId) > .addStateDump("statement-uid", uid); > } finally { > > > *if (mergedGraph != null) { mergedGraph.shutdown(); > }* > } > > * mergedGraph = this.orientUniverseGraphFactory.getTx(); > *//Exception should flow through. This is a problem. > try { > > *mergedGraph.begin(); > mergedGraph.getRawGraph().getTransaction().setUsingLog(false);* > > childProcessor.postProcess(mergedGraph, statement, > references, measurementPeriods, summaryDatas, rateComponentsList); > *mergedGraph.commit();* > > } catch (Exception e) { > mergedGraph.rollback(); > > throw new StateDumpException("Exception thrown when > creating the statement due to " + e.getMessage(), e) > > .addStateDump("universeMergeRequestUuid", universeMergeRequestUuid) > .addStateDump("deliveryId", deliveryId) > .addStateDump("uid", uid); > } finally { > > > *if (mergedGraph != null) { mergedGraph.shutdown(); > }* > } > > > } > ---- > > -- > > --- > You received this message because you are subscribed to the Google Groups > "OrientDB" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to [email protected]. > For more options, visit https://groups.google.com/d/optout. > -- --- You received this message because you are subscribed to the Google Groups "OrientDB" group. To unsubscribe from this group and stop receiving emails from it, send an email to [email protected]. For more options, visit https://groups.google.com/d/optout.
