← Back to team overview

dhis2-devs team mailing list archive

Re: Errors while importing datavalues in 2.24

 

Hi Jose

Lars will probably remember better.. but I think in 2.22 we had preheating
where all the object were loading in before the import started, so the
lookups would be very quick (but require more memory)

In later versions I think it now will try and "switch" over automagically..
but I don't think it then preloades all your references (just caching after
the cache miss threshold is reached), so if you have 42k org units... that
might be very slow

-- 
Morten Olav Hansen
Senior Engineer, DHIS 2
University of Oslo
http://www.dhis2.org

On Mon, Oct 17, 2016 at 10:27 PM, Jose Garcia Muñoz <josemp10@xxxxxxxxx>
wrote:

>
> Well at the end got imported (sometimes throws a memory exception), but it
> took more than 1 hour to import 7973 datavalues. It was just a few minutes
> in 2.22 with same import and same server.
>
> On Mon, Oct 17, 2016 at 4:29 PM, Jose Garcia Muñoz <josemp10@xxxxxxxxx>
> wrote:
>
>>
>> It seems to be memory issue happening in 2.24? If I try the same import
>> with the same org.units in 2.22, everything works well. With 2.24, I'm
>> normally getting the follow log message...
>>
>> * INFO  2016-10-17 14:03:07,531 Org unit cache heated after cache miss
>> threshold reached (DefaultDataValueSetService.java [taskScheduler-6])
>>
>>
>> On Fri, Oct 14, 2016 at 1:51 PM, Jason Pickering <
>> jason.p.pickering@xxxxxxxxx> wrote:
>>
>>> Seems like a memory issue
>>>
>>>  java.lang.OutOfMemoryError: GC overhead limit exceeded
>>>
>>> On Fri, Oct 14, 2016, 13:35 Jose Garcia Muñoz <josemp10@xxxxxxxxx>
>>> wrote:
>>>
>>>>
>>>> Thanks Lars,
>>>>
>>>> I have run data integrity, but the system has passed "Organisation
>>>> units with cyclic references ". I didn't get any errors importing events,
>>>> but aggregated... Will try to divide the file in small chunks to try to
>>>> figure it out...
>>>>
>>>> Thanks
>>>> Jose
>>>>
>>>> On Fri, Oct 14, 2016 at 11:02 AM, Lars Helge Øverland <lars@xxxxxxxxx>
>>>> wrote:
>>>>
>>>> Hi Jose,
>>>>
>>>> my best guess here is a cyclic parent relationship in the org unit
>>>> hierarchy, i.e. you have one or more org units where the one of the
>>>> ancestors are also a child.
>>>>
>>>> Try running data admin > integrity checks and look for "Organisation
>>>> units with cyclic references ", or look for it through SQL.
>>>>
>>>> best regards,
>>>>
>>>> Lars
>>>>
>>>>
>>>> On Fri, Oct 14, 2016 at 1:09 AM, Jose Garcia Muñoz <josemp10@xxxxxxxxx>
>>>> wrote:
>>>>
>>>>
>>>> Dear devs,
>>>>
>>>> I'm trying to import an XML file (900K) with around 8.000 datavalues in
>>>> 2.24 (build revision 1502fe2). However, I'm getting 2 different kind of
>>>> errors during the import... (attached at the end of the email)
>>>>
>>>> Any ideas? The only thing I can think of, is the huge number of org.
>>>> units that this instance has (42.000 org. units) with 8 GB. Would it be
>>>> related to a memory problem? (although the XML file is very small)
>>>>
>>>> I have also selected Preloaded Cache = No
>>>>
>>>> Many thanks!
>>>>
>>>>
>>>> *Error 1*
>>>>
>>>> * INFO  2016-10-13 21:55:55,780 [Level: INFO, category:
>>>> DATAVALUE_IMPORT, time: Thu Oct 13 21:55:55 UTC 2016, message: Importing
>>>> data values] (InMemoryNotifier.java [taskScheduler-7])
>>>> * ERROR 2016-10-13 22:10:55,332 java.lang.RuntimeException:
>>>> org.hibernate.PropertyAccessException: Exception occurred inside
>>>> getter of org.hisp.dhis.organisationunit.OrganisationUnit.path
>>>>         at org.hisp.dhis.commons.collection.CachingMap.get(CachingMap.j
>>>> ava:90)
>>>>         at org.hisp.dhis.dxf2.datavalueset.DefaultDataValueSetService.s
>>>> aveDataValueSet(DefaultDataValueSetService.java:954)
>>>>         at org.hisp.dhis.dxf2.datavalueset.DefaultDataValueSetService.s
>>>> aveDataValueSet(DefaultDataValueSetService.java:488)
>>>>         at org.hisp.dhis.dxf2.datavalueset.tasks.ImportDataValueTask.ca
>>>> ll(ImportDataValueTask.java:102)
>>>>         at org.hisp.dhis.security.SecurityContextRunnable.run(SecurityC
>>>> ontextRunnable.java:57)
>>>>         at org.springframework.scheduling.support.DelegatingErrorHandli
>>>> ngRunnable.run(DelegatingErrorHandlingRunnable.java:54)
>>>>         at java.util.concurrent.Executors$RunnableAdapter.call(Executor
>>>> s.java:511)
>>>>         at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>>>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>>> tureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>>>>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>>> tureTask.run(ScheduledThreadPoolExecutor.java:293)
>>>>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>>> Executor.java:1142)
>>>>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>>> lExecutor.java:617)
>>>>         at java.lang.Thread.run(Thread.java:745)
>>>> Caused by: org.hibernate.PropertyAccessException: Exception occurred
>>>> inside getter of org.hisp.dhis.organisationunit.OrganisationUnit.path
>>>>         at org.hibernate.property.access.spi.GetterMethodImpl.get(Gette
>>>> rMethodImpl.java:44)
>>>>         at org.hibernate.tuple.entity.AbstractEntityTuplizer.getPropert
>>>> yValues(AbstractEntityTuplizer.java:505)
>>>>         at org.hibernate.tuple.entity.PojoEntityTuplizer.getPropertyVal
>>>> ues(PojoEntityTuplizer.java:217)
>>>>         at org.hibernate.persister.entity.AbstractEntityPersister.getPr
>>>> opertyValues(AbstractEntityPersister.java:4613)
>>>>         at org.hibernate.event.internal.DefaultFlushEntityEventListener
>>>> .getValues(DefaultFlushEntityEventListener.java:178)
>>>>         at org.hibernate.event.internal.DefaultFlushEntityEventListener
>>>> .onFlushEntity(DefaultFlushEntityEventListener.java:135)
>>>>         at org.hibernate.event.internal.AbstractFlushingEventListener.f
>>>> lushEntities(AbstractFlushingEventListener.java:216)
>>>>         at org.hibernate.event.internal.AbstractFlushingEventListener.f
>>>> lushEverythingToExecutions(AbstractFlushingEventListener.java:85)
>>>>         at org.hibernate.event.internal.DefaultAutoFlushEventListener.o
>>>> nAutoFlush(DefaultAutoFlushEventListener.java:44)
>>>>         at org.hibernate.internal.SessionImpl.autoFlushIfRequired(Sessi
>>>> onImpl.java:1264)
>>>>         at org.hibernate.internal.SessionImpl.list(SessionImpl.java:178
>>>> 0)
>>>>         at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:3
>>>> 63)
>>>>         at org.hibernate.internal.CriteriaImpl.uniqueResult(CriteriaImp
>>>> l.java:385)
>>>>         at org.hisp.dhis.dataset.hibernate.HibernateLockExceptionStore.
>>>> getCount(HibernateLockExceptionStore.java:167)
>>>>         at org.hisp.dhis.dataset.DefaultDataSetService.isLockedPeriod(D
>>>> efaultDataSetService.java:384)
>>>>         at sun.reflect.GeneratedMethodAccessor709.invoke(Unknown
>>>> Source)
>>>>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>>> thodAccessorImpl.java:43)
>>>>         at java.lang.reflect.Method.invoke(Method.java:498)
>>>>         at org.springframework.aop.support.AopUtils.invokeJoinpointUsin
>>>> gReflection(AopUtils.java:302)
>>>>         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.TransactionInter
>>>> ceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
>>>>         at org.springframework.transaction.interceptor.TransactionAspec
>>>> tSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
>>>>         at org.springframework.transaction.interceptor.TransactionInter
>>>> ceptor.invoke(TransactionInterceptor.java:96)
>>>>         at org.springframework.aop.framework.ReflectiveMethodInvocation
>>>> .proceed(ReflectiveMethodInvocation.java:179)
>>>>         at org.springframework.aop.interceptor.ExposeInvocationIntercep
>>>> tor.invoke(ExposeInvocationInterceptor.java:92)
>>>>         at org.springframework.aop.framework.ReflectiveMethodInvocation
>>>> .proceed(ReflectiveMethodInvocation.java:179)
>>>>         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(
>>>> JdkDynamicAopProxy.java:208)
>>>>         at com.sun.proxy.$Proxy77.isLockedPeriod(Unknown Source)
>>>>         at org.hisp.dhis.dxf2.datavalueset.DefaultDataValueSetService.l
>>>> ambda$saveDataValueSet$14(DefaultDataValueSetService.java:955)
>>>>         at org.hisp.dhis.commons.collection.CachingMap.get(CachingMap.j
>>>> ava:82)
>>>>         ... 12 more
>>>> Caused by: java.lang.reflect.InvocationTargetException
>>>>         at sun.reflect.GeneratedMethodAccessor391.invoke(Unknown
>>>> Source)
>>>>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>>> thodAccessorImpl.java:43)
>>>>         at java.lang.reflect.Method.invoke(Method.java:498)
>>>>         at org.hibernate.property.access.spi.GetterMethodImpl.get(Gette
>>>> rMethodImpl.java:41)
>>>>         ... 42 more
>>>> Caused by: java.lang.OutOfMemoryError: GC overhead limit exceeded
>>>>         at java.lang.AbstractStringBuilder.<init>(AbstractStringBuilder
>>>> .java:68)
>>>>         at java.lang.StringBuilder.<init>(StringBuilder.java:101)
>>>>         at org.apache.commons.lang3.StringUtils.join(StringUtils.java:4
>>>> 121)
>>>>         at org.apache.commons.lang3.StringUtils.join(StringUtils.java:4
>>>> 177)
>>>>         at org.hisp.dhis.organisationunit.OrganisationUnit.getPath(Orga
>>>> nisationUnit.java:901)
>>>>         at sun.reflect.GeneratedMethodAccessor391.invoke(Unknown
>>>> Source)
>>>>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>>> thodAccessorImpl.java:43)
>>>>         at java.lang.reflect.Method.invoke(Method.java:498)
>>>>         at org.hibernate.property.access.spi.GetterMethodImpl.get(Gette
>>>> rMethodImpl.java:41)
>>>>         at org.hibernate.tuple.entity.AbstractEntityTuplizer.getPropert
>>>> yValues(AbstractEntityTuplizer.java:505)
>>>>         at org.hibernate.tuple.entity.PojoEntityTuplizer.getPropertyVal
>>>> ues(PojoEntityTuplizer.java:217)
>>>>         at org.hibernate.persister.entity.AbstractEntityPersister.getPr
>>>> opertyValues(AbstractEntityPersister.java:4613)
>>>>         at org.hibernate.event.internal.DefaultFlushEntityEventListener
>>>> .getValues(DefaultFlushEntityEventListener.java:178)
>>>>         at org.hibernate.event.internal.DefaultFlushEntityEventListener
>>>> .onFlushEntity(DefaultFlushEntityEventListener.java:135)
>>>>         at org.hibernate.event.internal.AbstractFlushingEventListener.f
>>>> lushEntities(AbstractFlushingEventListener.java:216)
>>>>         at org.hibernate.event.internal.AbstractFlushingEventListener.f
>>>> lushEverythingToExecutions(AbstractFlushingEventListener.java:85)
>>>>         at org.hibernate.event.internal.DefaultAutoFlushEventListener.o
>>>> nAutoFlush(DefaultAutoFlushEventListener.java:44)
>>>>         at org.hibernate.internal.SessionImpl.autoFlushIfRequired(Sessi
>>>> onImpl.java:1264)
>>>>         at org.hibernate.internal.SessionImpl.list(SessionImpl.java:178
>>>> 0)
>>>>         at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:3
>>>> 63)
>>>>         at org.hibernate.internal.CriteriaImpl.uniqueResult(CriteriaImp
>>>> l.java:385)
>>>>         at org.hisp.dhis.dataset.hibernate.HibernateLockExceptionStore.
>>>> getCount(HibernateLockExceptionStore.java:167)
>>>>         at org.hisp.dhis.dataset.DefaultDataSetService.isLockedPeriod(D
>>>> efaultDataSetService.java:384)
>>>>         at sun.reflect.GeneratedMethodAccessor709.invoke(Unknown
>>>> Source)
>>>>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>>> thodAccessorImpl.java:43)
>>>>         at java.lang.reflect.Method.invoke(Method.java:498)
>>>>         at org.springframework.aop.support.AopUtils.invokeJoinpointUsin
>>>> gReflection(AopUtils.java:302)
>>>>         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.TransactionInter
>>>> ceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
>>>>         at org.springframework.transaction.interceptor.TransactionAspec
>>>> tSupport.invokeWithinTransaction(TransactionAspectSupport.java:281)
>>>>         at org.springframework.transaction.interceptor.TransactionInter
>>>> ceptor.invoke(TransactionInterceptor.java:96)
>>>>  (DefaultDataValueSetService.java [taskScheduler-3])
>>>>
>>>> ------------------------------------------------------------
>>>> -------------------------------------------------
>>>>
>>>>
>>>> *Error 2:*
>>>>
>>>> * INFO  2016-10-13 22:47:36,040 [Level: INFO, category:
>>>> DATAVALUE_IMPORT, time: Thu Oct 13 22:47:36 UTC 2016, message: Importing
>>>> data values] (InMemoryNotifier.java [taskScheduler-7])
>>>> CachingMap* INFO  2016-10-13 22:49:58,444 Org unit cache heated after
>>>> cache miss threshold reached (DefaultDataValueSetService.java
>>>> [taskScheduler-7])
>>>> Org unit cache heated after cache miss threshold reached* ERROR
>>>> 2016-10-13 22:56:14,899 Unable to render Velocity Template, '/main.vm'
>>>> (CommonsLogger.java [http-apr-8081-exec-1])
>>>> ClientAbortException:  java.io.IOException
>>>>         at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuf
>>>> fer.java:371)
>>>>         at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffe
>>>> r.java:333)
>>>>         at org.apache.catalina.connector.CoyoteOutputStream.flush(Coyot
>>>> eOutputStream.java:101)
>>>>         at org.springframework.security.web.context.OnCommittedResponse
>>>> Wrapper$SaveContextServletOutputStream.flush(OnCommittedResp
>>>> onseWrapper.java:437)
>>>>         at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297)
>>>>         at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141)
>>>>         at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229
>>>> )
>>>>         at org.apache.struts2.dispatcher.VelocityResult.doExecute(Veloc
>>>> ityResult.java:160)
>>>>         at org.apache.struts2.dispatcher.StrutsResultSupport.execute(St
>>>> rutsResultSupport.java:191)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.executeResul
>>>> t(DefaultActionInvocation.java:369)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:273)
>>>>         at org.hisp.dhis.webportal.interceptor.XWorkPortalUserIntercept
>>>> or.intercept(XWorkPortalUserInterceptor.java:85)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.webportal.interceptor.XWorkPortalModuleInterce
>>>> ptor.intercept(XWorkPortalModuleInterceptor.java:91)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.webportal.interceptor.XWorkPortalMenuIntercept
>>>> or.intercept(XWorkPortalMenuInterceptor.java:94)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.webportal.interceptor.XWorkPortalParamsInterce
>>>> ptor.intercept(XWorkPortalParamsInterceptor.java:150)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.interceptor.ContextInterceptor.intercept(Conte
>>>> xtInterceptor.java:83)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.interceptor.UserSettingInterceptor.intercept(U
>>>> serSettingInterceptor.java:81)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.security.intercept.LoginInterceptor.intercept(
>>>> LoginInterceptor.java:85)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.security.intercept.XWorkSecurityInterceptor.in
>>>> tercept(XWorkSecurityInterceptor.java:116)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.interceptor.SystemSettingInterceptor.intercept
>>>> (SystemSettingInterceptor.java:115)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.interceptor.I18nInterceptor.intercept(I18nInte
>>>> rceptor.java:139)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at com.opensymphony.xwork2.interceptor.ParametersInterceptor.do
>>>> Intercept(ParametersInterceptor.java:229)
>>>>         at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.
>>>> intercept(MethodFilterInterceptor.java:98)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at com.opensymphony.xwork2.interceptor.StaticParametersIntercep
>>>> tor.intercept(StaticParametersInterceptor.java:191)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.hisp.dhis.interceptor.ExceptionInterceptor.intercept(Exc
>>>> eptionInterceptor.java:113)
>>>>         at com.opensymphony.xwork2.DefaultActionInvocation.invoke(Defau
>>>> ltActionInvocation.java:244)
>>>>         at org.apache.struts2.impl.StrutsActionProxy.execute(StrutsActi
>>>> onProxy.java:54)
>>>>         at org.apache.struts2.dispatcher.Dispatcher.serviceAction(Dispa
>>>> tcher.java:564)
>>>>         at org.apache.struts2.dispatcher.ng.ExecuteOperations.executeAc
>>>> tion(ExecuteOperations.java:81)
>>>>         at org.apache.struts2.dispatcher.ng.filter.StrutsPrepareAndExec
>>>> uteFilter.doFilter(StrutsPrepareAndExecuteFilter.java:99)
>>>>         at org.apache.catalina.core.ApplicationFilterChain.internalDoFi
>>>> lter(ApplicationFilterChain.java:241)
>>>>         at org.apache.catalina.core.ApplicationFilterChain.doFilter(App
>>>> licationFilterChain.java:208)
>>>>         at org.springframework.security.web.FilterChainProxy$VirtualFil
>>>> terChain.doFilter(FilterChainProxy.java:330)
>>>>         at org.springframework.security.web.access.intercept.FilterSecu
>>>> rityInterceptor.invoke(FilterSecurityInterceptor.java:118)
>>>>         at org.springframework.security.web.access.intercept.FilterSecu
>>>> rityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
>>>>
>>>>
>>>> _______________________________________________
>>>> Mailing list: https://launchpad.net/~dhis2-devs
>>>> Post to     : dhis2-devs@xxxxxxxxxxxxxxxxxxx
>>>> Unsubscribe : https://launchpad.net/~dhis2-devs
>>>> More help   : https://help.launchpad.net/ListHelp
>>>>
>>>>
>>>>
>>>>
>>>> --
>>>> Lars Helge Øverland
>>>> Lead developer, DHIS 2
>>>> University of Oslo
>>>> Skype: larshelgeoverland
>>>> lars@xxxxxxxxx
>>>> http://www.dhis2.org <https://www.dhis2.org/>
>>>>
>>>>
>>>> _______________________________________________
>>>> Mailing list: https://launchpad.net/~dhis2-devs
>>>> Post to     : dhis2-devs@xxxxxxxxxxxxxxxxxxx
>>>> Unsubscribe : https://launchpad.net/~dhis2-devs
>>>> More help   : https://help.launchpad.net/ListHelp
>>>>
>>>
>>
>
> _______________________________________________
> Mailing list: https://launchpad.net/~dhis2-devs
> Post to     : dhis2-devs@xxxxxxxxxxxxxxxxxxx
> Unsubscribe : https://launchpad.net/~dhis2-devs
> More help   : https://help.launchpad.net/ListHelp
>
>

Follow ups

References