Query event on all org's events is slow,and cause out of memory

I have done some action like query event is exist, then update if exist, insert if not exist.
I have found that the query response may be slow :
api/events?program=…&filter=de:eq:…

and after done some times, will cause DHIS2 stop response and :

Error log
  • WARN 2022-01-27T18:45:49,734 SQL Error: 0, SQLState: 53200 (SqlExceptionHelper.java [taskScheduler-16])
  • ERROR 2022-01-27T18:45:49,735 Ran out of memory retrieving query results. (SqlExceptionHelper.java [taskScheduler-16])
  • ERROR 2022-01-27T18:45:49,741 Unexpected exception occurred invoking async method: public void org.hisp.dhis.programrule.engine.ProgramRuleEngineListener.onEve
    ntCompletion(org.hisp.dhis.programrule.engine.StageCompletionEvaluationEvent) (SimpleAsyncUncaughtExceptionHandler.java [taskScheduler-16])
    org.hibernate.exception.GenericJDBCException: could not extract ResultSet
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47) ~[hibernate-core-5.4.28.Final.jar:5.4.28.
    Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:67) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.getResultSet(AbstractLoadPlanBasedLoader.java:390) ~[hibernate-core-5.4.28.Final.ja
    r:5.4.28.Final]
    at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:163) ~[hibernate-core-5.4.28
    .Final.jar:5.4.28.Final]
    at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:104) ~[hibernate-core-5.4.28.Final.jar
    :5.4.28.Final]
    at org.hibernate.loader.collection.plan.AbstractLoadPlanBasedCollectionInitializer.initialize(AbstractLoadPlanBasedCollectionInitializer.java:87) ~[hibern
    ate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:710) ~[hibernate-core-5.4.28.Final.jar:5.4.2
    8.Final]
    at org.hibernate.event.internal.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:76) ~[hibern
    ate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:93) ~[hibernate-core-5.4.28.Final.jar:5
    .4.28.Final]
    at org.hibernate.internal.SessionImpl.initializeCollection(SessionImpl.java:2163) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection$4.doWork(AbstractPersistentCollection.java:589) ~[hibernate-core-5.4.28.Final.jar:5.4.28
    .Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:264) ~[hibernate-core-5.4
    .28.Final.jar:5.4.28.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:585) ~[hibernate-core-5.4.28.Final.jar:5.4.
    28.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.read(AbstractPersistentCollection.java:149) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Fin
    al]
    at org.hibernate.collection.internal.PersistentSet.iterator(PersistentSet.java:188) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at java.util.Spliterators$IteratorSpliterator.estimateSize(Spliterators.java:1821) ~[?:?]
    at java.util.Spliterator.getExactSizeIfKnown(Spliterator.java:408) ~[?:?]
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:483) ~[?:?]
    at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
    at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?]
    at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
    at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[?:?]
    at org.hisp.dhis.programrule.engine.DefaultProgramRuleEntityMapperService.toMappedRuleEvents(DefaultProgramRuleEntityMapperService.java:305) ~[dhis-servic
    e-program-rule-2.37-SNAPSHOT.jar:?]
    at jdk.internal.reflect.GeneratedMethodAccessor886.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodIn

    5.RELEASE]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
    Caused by: org.postgresql.util.PSQLException: Ran out of memory retrieving query results.
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2256) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:323) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:481) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:401) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:164) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:114) ~[postgresql-42.2.19.jar:42.2.19]
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:1471) ~[c3p0-0.9.5.5.jar:0.9.5.5]
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:57) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    … 63 more
    Caused by: java.lang.OutOfMemoryError: Java heap space
Error log (continued)
  • ERROR 2022-01-27T23:22:23,919 Ran out of memory retrieving query results. (SqlExceptionHelper.java [taskScheduler-11])
  • ERROR 2022-01-27T23:22:23,945 Unexpected exception occurred invoking async method: public void org.hisp.dhis.programrule.engine.ProgramRuleEngineListener.onEventCompletion(org.hisp.dhis.programrule.engine.StageCompletionEvaluationEvent) (SimpleAsyncUncaughtExceptionHandler.java [taskScheduler-11])
    org.hibernate.exception.GenericJDBCException: could not extract ResultSet
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:67) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.getResultSet(AbstractLoadPlanBasedLoader.java:390) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:163) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:104) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.loader.collection.plan.AbstractLoadPlanBasedCollectionInitializer.initialize(AbstractLoadPlanBasedCollectionInitializer.java:87) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:710) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.event.internal.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:76) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:93) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.internal.SessionImpl.initializeCollection(SessionImpl.java:2163) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection$4.doWork(AbstractPersistentCollection.java:589) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:264) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:585) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.collection.internal.AbstractPersistentCollection.read(AbstractPersistentCollection.java:149) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at org.hibernate.collection.internal.PersistentSet.iterator(PersistentSet.java:188) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    at java.util.Spliterators$IteratorSpliterator.estimateSize(Spliterators.java:1821) ~[?:?]
    at java.util.Spliterator.getExactSizeIfKnown(Spliterator.java:408) ~[?:?]
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:483) ~[?:?]
    at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
    at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?]
    at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
    at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[?:?]
    at org.hisp.dhis.programrule.engine.DefaultProgramRuleEntityMapperService.toMappedRuleEvents(DefaultProgramRuleEntityMapperService.java:305) ~[dhis-service-program-rule-2.37-SNAPSHOT.jar:?]
    at jdk.internal.reflect.GeneratedMethodAccessor927.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.6.jar:5.3.6]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.6.jar:5.3.6]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.6.jar:5.3.6]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at com.sun.proxy.$Proxy311.toMappedRuleEvents(Unknown Source) ~[?:?]
    at org.hisp.dhis.programrule.engine.ProgramRuleEngine.getRuleEvents(ProgramRuleEngine.java:289) ~[dhis-service-program-rule-2.37-SNAPSHOT.jar:?]
    at org.hisp.dhis.programrule.engine.ProgramRuleEngine.evaluate(ProgramRuleEngine.java:102) ~[dhis-service-program-rule-2.37-SNAPSHOT.jar:?]
    at org.hisp.dhis.programrule.engine.DefaultProgramRuleEngineService.evaluateEventAndRunEffects(DefaultProgramRuleEngineService.java:167) ~[dhis-service-program-rule-2.37-SNAPSHOT.jar:?]
    at org.hisp.dhis.programrule.engine.DefaultProgramRuleEngineService.evaluateEventAndRunEffects(DefaultProgramRuleEngineService.java:139) ~[dhis-service-program-rule-2.37-SNAPSHOT.jar:?]
    at jdk.internal.reflect.GeneratedMethodAccessor849.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:566) ~[?:?]
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.6.jar:5.3.6]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.6.jar:5.3.6]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.6.jar:5.3.6]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at com.sun.proxy.$Proxy313.evaluateEventAndRunEffects(Unknown Source) ~[?:?]
    at org.hisp.dhis.programrule.engine.ProgramRuleEngineListener.onEventCompletion(ProgramRuleEngineListener.java:61) ~[dhis-service-program-rule-2.37-SNAPSHOT.jar:?]
    at org.hisp.dhis.programrule.engine.ProgramRuleEngineListener$$FastClassBySpringCGLIB$$de38d172.invoke() ~[dhis-service-program-rule-2.37-SNAPSHOT.jar:?]
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:218) ~[spring-core-5.3.6.jar:5.3.6]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:779) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:750) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115) ~[spring-aop-5.2.15.RELEASE.jar:5.2.15.RELEASE]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
    Caused by: org.postgresql.util.PSQLException: Ran out of memory retrieving query results.
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2256) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:323) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:481) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:401) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:164) ~[postgresql-42.2.19.jar:42.2.19]
    at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:114) ~[postgresql-42.2.19.jar:42.2.19]
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeQuery(NewProxyPreparedStatement.java:1471) ~[c3p0-0.9.5.5.jar:0.9.5.5]
    at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:57) ~[hibernate-core-5.4.28.Final.jar:5.4.28.Final]
    … 61 more
    Caused by: java.lang.OutOfMemoryError: Java heap space

Hi @linxd,
Good to see you back!

What is the size of the Java heap space in your system? Did you try increasing it? Thank you!

Thanks,
set to : -Xms2048m -Xmx7048m

Maybe if you try to query org’s events into smaller chunks rather than running it all at once. What are the specifications of your device (RAM, tomcat version, postgres…etc)? Would it be possible to increase the heap space to Xms12000m,Xmx12000m

There’s been a similar issue but it was for importing events; however, I’d say to see if @Zubair’s suggestion will work here as well: