Dhis29 instance stop response after few days

Support - Assistance technique
1

the catalina.out 's last few line:

  • INFO 2018-12-23 02:00:00,008 Job ‘Dataset notification’ executed successfully. Time used: 00:00:00.006 (DefaultJobInstance.java [taskScheduler-20])
  • INFO 2018-12-23 02:00:00,009 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Remove expired reserved values, uid: WHYs8xzZoBV (AuditLogUtil.java [taskScheduler-18])
  • INFO 2018-12-23 02:00:00,009 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Dataset notification, uid: nqlz9cXjnG9 (AuditLogUtil.java [taskScheduler-20])
  • INFO 2018-12-23 02:00:00,010 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Credentials expiry alert, uid: aKbPP53W9Gb (AuditLogUtil.java [taskScheduler-12])
  • INFO 2018-12-23 02:00:00,235 ‘system-process’ create org.hisp.dhis.datastatistics.DataStatistics, uid: AaPYBgG42Ix (AuditLogUtil.java [taskScheduler-3])
  • INFO 2018-12-23 02:00:00,277 Saved data statistics snapshot (DataStatisticsJob.java [taskScheduler-3])
  • INFO 2018-12-23 02:00:00,277 Job ‘Data statistics’ executed successfully. Time used: 00:00:00.276 (DefaultJobInstance.java [taskScheduler-3])
  • INFO 2018-12-23 02:00:00,279 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Data statistics, uid: hGEbyphk2xL (AuditLogUtil.java [taskScheduler-3])
  • INFO 2018-12-23 03:00:06,884 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Remove expired reserved values, uid: WHYs8xzZoBV (AuditLogUtil.java [taskScheduler-2])
  • INFO 2018-12-23 03:01:08,242 Job ‘Remove expired reserved values’ started (DefaultJobInstance.java [taskScheduler-2])
  • INFO 2018-12-23 03:01:38,386 Job ‘Remove expired reserved values’ executed successfully. Time used: 00:01:31.502 (DefaultJobInstance.java [taskScheduler-2])
  • INFO 2018-12-23 03:01:38,390 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Remove expired reserved values, uid: WHYs8xzZoBV (AuditLogUtil.java [taskScheduler-2])
  • INFO 2018-12-23 04:00:59,151 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Remove expired reserved values, uid: WHYs8xzZoBV (AuditLogUtil.java [taskScheduler-14])
  • INFO 2018-12-23 08:33:46,915 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Validation result notification, uid: gxsNP9baplk (AuditLogUtil.java [taskScheduler-6])

no other . open the login page will still running and running…

1 Like
2

Are you able to check the CPU and memory usage of that DHIS2 instance at the time the issue happened ? Did it happen again after server restarting ?

1 Like
3 
          total        used        free      shared  buff/cache   available

Mem: 48233 15310 23676 70 9246 32292
Swap: 49083 0 49083

stop response again a day after restart

1 Like
4

Not sure what’s happening here. In the logs you provided, there were some jobs running but it seems there was no error. You might try to disable those jobs and start the server again, but i doubt this would solve the issue ( set column ‘enabled’ to ‘f’ in table ‘jobconfiguration’ )

Please continue to observe the server log and send us any related WARN or ERROR.

1 Like
5
  • INFO 2019-01-07 02:00:00,137 ‘system-process’ create org.hisp.dhis.datastatistics.DataStatistics, uid: FghEVKQeud1 (AuditLogUtil.java [taskScheduler-14])
  • INFO 2019-01-07 02:00:00,158 Saved data statistics snapshot (DataStatisticsJob.java [taskScheduler-14])
  • INFO 2019-01-07 02:00:00,158 Job ‘Data statistics’ executed successfully. Time used: 00:00:00.157 (DefaultJobInstance.java [taskScheduler-14])
  • INFO 2019-01-07 02:00:00,160 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Data statistics, uid: hGEbyphk2xL (AuditLogUtil.java [taskScheduler-14])
    Exception in thread “https-jsse-nio-8443-AsyncTimeout” java.lang.OutOfMemoryError: GC overhead limit exceeded
    at java.util.concurrent.ConcurrentHashMap$KeySetView.iterator(ConcurrentHashMap.java:4578)
    at java.util.Collections$SetFromMap.iterator(Collections.java:5462)
    at org.apache.coyote.AbstractProtocol$AsyncTimeout.run(AbstractProtocol.java:1154)
    at java.lang.Thread.run(Thread.java:748)
  • INFO 2019-01-07 02:23:40,292 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: File resource clean up, uid: Ues0KZB5MWK (AuditLogUtil.java [taskScheduler-17])
  • ERROR 2019-01-07 02:23:40,329 Unexpected error occurred in scheduled task. (TaskUtils.java [taskScheduler-17])
    java.lang.OutOfMemoryError: GC overhead limit exceeded
    at org.postgresql.jdbc.TimestampUtils.toTimestamp(TimestampUtils.java:397)
    at org.postgresql.jdbc.PgResultSet.getTimestamp(PgResultSet.java:610)
    at org.postgresql.jdbc.PgResultSet.getTimestamp(PgResultSet.java:2513)
    at com.mchange.v2.c3p0.impl.NewProxyResultSet.getTimestamp(NewProxyResultSet.java:3955)
    at org.hibernate.type.descriptor.sql.TimestampTypeDescriptor$2.doExtract(TimestampTypeDescriptor.java:84)
    at org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:47)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:260)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:256)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:246)
    at org.hibernate.type.AbstractStandardBasicType.hydrate(AbstractStandardBasicType.java:332)
    at org.hibernate.persister.entity.AbstractEntityPersister.hydrate(AbstractEntityPersister.java:2854)
    at org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1757)
    at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1683)
    at org.hibernate.loader.Loader.getRow(Loader.java:1572)
    at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:742)
    at org.hibernate.loader.Loader.processResultSet(Loader.java:1001)
    at org.hibernate.loader.Loader.doQuery(Loader.java:959)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:351)
    at org.hibernate.loader.Loader.doList(Loader.java:2702)
    at org.hibernate.loader.Loader.doList(Loader.java:2685)
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2517)
    at org.hibernate.loader.Loader.list(Loader.java:2512)

-----------------------but the mem setting is up to 12G
root 23373 1 26 1月06 ? 05:34:45 /home/wcrmyy2017/jdk1.8.0_171/bin/java -Djava.util.logging.config.file= /home/wcrmyy2017/tomcat534/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Dfile.encoding=UTF-8 -Xms2048m -Xmx12096m -server -Djava.awt.headless=true -Djdk.tls.ephemeralDHKeySize=2048 -Djava.protocol.handler.pkgs=org.apache.catalina.webresources -Dorg.apache.catalina.security.SecurityListener.UMASK=0027 -Dignore.endorsed.dirs= -classpath /home/wcrmyy2017/tomcat534/bin/bootstrap.jar:/home/wcrmyy2017/tomcat534/bin/tomcat-juli.jar -Dcatalina.base=/home/wcrmyy2017/tomcat534 -Dcatalina.home=/home/wcrmyy2017/tomcat534 -Djava.io.tmpdir=/home/wcrmyy2017/tomcat534/temp org.apache.catalina.startup.Bootstrap start
w

在 2018-12-27 16:38:16，“Viet Nguyen” noreply@community.dhis2.org 写道：

6

Maybe this is because many heavy jobs run at the same time. Can you try to reschedule those jobs to run at different times such as DataStatistics, File resource clean up, etc.

1 Like
7

Hi @linxd

Did you manage to solve this issue?

We are facing a similar problem in our 2.30 instance,
Suddenly the application stops responding ,when hitting the application URL in the browser , the page just keeps loading and no response is received.

We are really struggling with this and and it would help to know how you managed to solve it…

Thanks
harsh

1 Like
8

I found the error because of : out of memory

uler-24])

  • INFO 2019-01-19 02:16:35,437 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: File resource clean up, uid: Ues0KZB5MWK (AuditLogUtil.java [taskScheduler-19])
  • ERROR 2019-01-19 02:16:35,464 Unexpected error occurred in scheduled task. (TaskUtils.java [taskScheduler-19])
    java.lang.OutOfMemoryError: Java heap space
    at java.util.Arrays.copyOf(Arrays.java:3181)
    at java.util.ArrayList.grow(ArrayList.java:265)
    at java.util.ArrayList.ensureExplicitCapacity(ArrayList.java:239)
    at java.util.ArrayList.ensureCapacityInternal(ArrayList.java:231)
    at java.util.ArrayList.add(ArrayList.java:462)
    at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1696)
    at org.hibernate.loader.Loader.getRow(Loader.java:1572)
    at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:742)
    at org.hibernate.loader.Loader.processResultSet(Loader.java:1001)
    at org.hibernate.loader.Loader.doQuery(Loader.java:959)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:351)
    at org.hibernate.loader.Loader.doList(Loader.java:2702)
    at org.hibernate.loader.Loader.doList(Loader.java:2685)
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2517)
    at org.hibernate.loader.Loader.list(Loader.java:2512)
    at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:109)
    at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1898)
    at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:366)
    at org.hisp.dhis.datavalue.hibernate.HibernateDataValueAuditStore.getDataValueAudits(HibernateDataValueAuditStore.java:120)
    at org.hisp.dhis.datavalue.DefaultDataValueAuditService.getDataValueAudits(DefaultDataValueAuditService.java:91)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:333)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
  • INFO 2019-01-19 03:00:00,001 ‘system-process’ update org.hisp.dhis.scheduling.JobConfiguration, name: Remove expired reserved values, uid: c1tbfVruxnp (AuditLogUtil.java [taskScheduler-13])
  • INFO 2019-01-19 03:00:00,014 Job ‘Remove expired reserved values’ started (DefaultJobInstance.java [taskScheduler-13])
  • INFO 2019-01-19 03:00:00,092 Job ‘Remove expired reserved values’ executed successfully. Time used: 00:00:00.091 (DefaultJobInstance.java [taskScheduler-13])
    –More–(73%)
1 Like
9

looks similar to this : FileResourceCleanUpJob running and loading all datavalueaudit entries - #3 by Stian

2 Likes