dhis2-devs team mailing list archive

Thread
Date

Problems with 2.16 upgrade

To: <dhis2-devs@xxxxxxxxxxxxxxxxxxx>
From: "Dapo Adejumo" <dapo_adejumo@xxxxxxxxx>
Date: Fri, 12 Sep 2014 22:15:59 +0100
Thread-index: Ac/OzN6Y9cw+YzaLTYezqnOBUhh+TQ==

Hi Devs,

Got this error relating to dataelements while trying to upgrade a database
from 2.15 to 2.16. Any ideas what may be causing this? More logs in
attachment.

 

ERROR 2014-09-12 20:09:01,663 java.lang.IllegalArgumentException: No enum
cons

tant org.hisp.dhis.dataelement.DataElementDomain.t

        at java.lang.Enum.valueOf(Unknown Source)

        at
org.hisp.dhis.hibernate.EnumUserType.nullSafeGet(EnumUserType.java:74

)

        at org.hibernate.type.CustomType.nullSafeGet(CustomType.java:127)

        at org.hibernate.type.AbstractType.hydrate(AbstractType.java:106)

        at
org.hibernate.persister.entity.AbstractEntityPersister.hydrate(Abstra

ctEntityPersister.java:2903)

        at org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1668)

        at
org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1600)

        at org.hibernate.loader.Loader.getRow(Loader.java:1500)

        at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:712)

        at org.hibernate.loader.Loader.processResultSet(Loader.java:940)

        at org.hibernate.loader.Loader.doQuery(Loader.java:910)

        at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Lo

 

...............

Regards,

Dapo Adejumo

+2348033683677

Skype : dapojorge

12-Sep-2014 20:06:36.913 INFO [main] org.apache.catalina.core.AprLifecycleListen
er.init Loaded APR based Apache Tomcat Native library 1.1.30 using APR version 1
.4.8.
12-Sep-2014 20:06:36.915 INFO [main] org.apache.catalina.core.AprLifecycleListen
er.init APR capabilities: IPv6 [true], sendfile [true], accept filters [false],
random [true].
12-Sep-2014 20:06:37.739 INFO [main] org.apache.catalina.core.AprLifecycleListen
er.initializeSSL OpenSSL successfully initialized (OpenSSL 1.0.1g 7 Apr 2014)
12-Sep-2014 20:06:37.893 INFO [main] org.apache.coyote.AbstractProtocol.init Ini
tializing ProtocolHandler ["http-apr-8080"]
12-Sep-2014 20:06:37.905 INFO [main] org.apache.coyote.AbstractProtocol.init Ini
tializing ProtocolHandler ["ajp-apr-8009"]
12-Sep-2014 20:06:37.907 INFO [main] org.apache.catalina.startup.Catalina.load I
nitialization processed in 1302 ms
12-Sep-2014 20:06:37.929 INFO [main] org.apache.catalina.core.StandardService.st
artInternal Starting service Catalina
12-Sep-2014 20:06:37.930 INFO [main] org.apache.catalina.core.StandardEngine.sta
rtInternal Starting Servlet Engine: Apache Tomcat/8.0.8
12-Sep-2014 20:06:37.975 INFO [localhost-startStop-1] org.apache.catalina.startu
p.HostConfig.deployWAR Deploying web application archive C:\apache-tomcat-8.0.8\
webapps\ROOT.war
* INFO  2014-09-12 20:08:06,368 System property dhis2.home not set (DefaultLocat
ionManager.java [localhost-startStop-1])
* INFO  2014-09-12 20:08:06,375 Environment variable DHIS2_HOME points to D:\dhi
s2 (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2014-09-12 20:08:07,938 Hibernate configuration loaded, using dialect: o
rg.hibernate.dialect.PostgreSQLDialect (DefaultHibernateConfigurationProvider.ja
va [localhost-startStop-1])
12-Sep-2014 20:08:14.536 INFO [localhost-startStop-1] com.hazelcast.hibernate.Ha
zelcastLocalCacheRegionFactory.null Starting up HazelcastLocalCacheRegionFactory

12-Sep-2014 20:08:14.559 INFO [localhost-startStop-1] com.hazelcast.config.XmlCo
nfigBuilder.null Looking for hazelcast.xml config file in classpath.
12-Sep-2014 20:08:14.563 INFO [localhost-startStop-1] com.hazelcast.config.XmlCo
nfigBuilder.null Using configuration file file:/C:/apache-tomcat-8.0.8/webapps/R
OOT/WEB-INF/lib/dhis-support-hibernate-2.16.jar!/hazelcast.xml in the classpath.

12-Sep-2014 20:08:15.760 INFO [localhost-startStop-1] com.hazelcast.instance.Def
aultAddressPicker.null null [dev] [3.2.1] Interfaces is enabled, trying to pick
one address matching to one of: [127.0.0.1]
12-Sep-2014 20:08:15.791 INFO [localhost-startStop-1] com.hazelcast.instance.Def
aultAddressPicker.null null [dev] [3.2.1] Picked Address[127.0.0.1]:5701, using
socket ServerSocket[addr=/127.0.0.1,localport=5701], bind any local is false
12-Sep-2014 20:08:16.119 INFO [localhost-startStop-1] com.hazelcast.system.null
[127.0.0.1]:5701 [dev] [3.2.1] Hazelcast Community Edition 3.2.1 (20140428) star
ting at Address[127.0.0.1]:5701
12-Sep-2014 20:08:16.120 INFO [localhost-startStop-1] com.hazelcast.system.null
[127.0.0.1]:5701 [dev] [3.2.1] Copyright (C) 2008-2014 Hazelcast.com
12-Sep-2014 20:08:16.135 INFO [localhost-startStop-1] com.hazelcast.core.Lifecyc
leService.null [127.0.0.1]:5701 [dev] [3.2.1] Address[127.0.0.1]:5701 is STARTIN
G
12-Sep-2014 20:08:16.442 WARNING [localhost-startStop-1] com.hazelcast.instance.
Node.null [127.0.0.1]:5701 [dev] [3.2.1] No join method is enabled! Starting sta
ndalone.
12-Sep-2014 20:08:16.576 INFO [localhost-startStop-1] com.hazelcast.core.Lifecyc
leService.null [127.0.0.1]:5701 [dev] [3.2.1] Address[127.0.0.1]:5701 is STARTED

* ERROR 2014-09-12 20:08:30,453 HHH000388: Unsuccessful: alter table completedat
asetregistration add column attributeoptioncomboid int4 not null (SchemaUpdate.j
ava [localhost-startStop-1])
* ERROR 2014-09-12 20:08:30,455 ERROR: column "attributeoptioncomboid" contains
null values (SchemaUpdate.java [localhost-startStop-1])
* ERROR 2014-09-12 20:08:30,765 HHH000388: Unsuccessful: alter table translation
 add column translationid int4 not null (SchemaUpdate.java [localhost-startStop-
1])
* ERROR 2014-09-12 20:08:30,766 ERROR: column "translationid" contains null valu
es (SchemaUpdate.java [localhost-startStop-1])
* ERROR 2014-09-12 20:08:30,769 HHH000388: Unsuccessful: alter table completedat
asetregistration add constraint fk_completedatasetregistration_attributeoptionco
mboid foreign key (attributeoptioncomboid) references categoryoptioncombo (Schem
aUpdate.java [localhost-startStop-1])
* ERROR 2014-09-12 20:08:30,770 ERROR: column "attributeoptioncomboid" reference
d in foreign key constraint does not exist (SchemaUpdate.java [localhost-startSt
op-1])
* ERROR 2014-09-12 20:08:31,243 HHH000388: Unsuccessful: alter table program_att
ributes add constraint fk_program_attributeid foreign key (trackedentityattribut
eid) references trackedentityattribute (SchemaUpdate.java [localhost-startStop-1
])
* ERROR 2014-09-12 20:08:31,244 ERROR: constraint "fk_program_attributeid" for r
elation "program_attributes" already exists (SchemaUpdate.java [localhost-startS
top-1])
* ERROR 2014-09-12 20:08:31,247 HHH000388: Unsuccessful: alter table programstag
e add constraint fk_programstage_dataentryform foreign key (dataentryformid) ref
erences dataentryform (SchemaUpdate.java [localhost-startStop-1])
* ERROR 2014-09-12 20:08:31,248 ERROR: constraint "fk_programstage_dataentryform
" for relation "programstage" already exists (SchemaUpdate.java [localhost-start
Stop-1])
* INFO  2014-09-12 20:08:34,513 Found the following message senders: [org.hisp.d
his.message.EmailMessageSender@7cdc44a8, org.hisp.dhis.sms.SmsMessageSender@68a0
0814] (DefaultMessageService.java [localhost-startStop-1])
* INFO  2014-09-12 20:08:48,177 Detected apps: [] (DefaultAppManager.java [local
host-startStop-1])
* INFO  2014-09-12 20:08:48,263 SMSLib: A Java API library for sending and recei
ving SMS via a GSM modem or other supported gateways.
This software is distributed under the terms of the Apache v2.0 License.
Web Site: http://smslib.org (Service.java [localhost-startStop-1])
* INFO  2014-09-12 20:08:48,265 Version: 3.5.3 (Service.java [localhost-startSto
p-1])
* INFO  2014-09-12 20:08:48,266 JRE Version: 1.8.0_05 (Service.java [localhost-s
tartStop-1])
* INFO  2014-09-12 20:08:48,267 JRE Impl Version: 25.5-b02 (Service.java [localh
ost-startStop-1])
* INFO  2014-09-12 20:08:48,268 O/S: Windows 8.1 / amd64 / 6.3 (Service.java [lo
calhost-startStop-1])
* INFO  2014-09-12 20:08:51,133 Scheduled task with key: 0 0 0 ? * 1-6 and cron:
 0 0 0 ? * 1-6 (SpringScheduler.java [localhost-startStop-1])
* INFO  2014-09-12 20:08:51,135 Scheduled task with key: 0 0 0 ? * 0 and cron: 0
 0 0 ? * 0 (SpringScheduler.java [localhost-startStop-1])
* WARN  2014-09-12 20:08:54,860 RP discovery / realm validation disabled;  (Real
mVerifier.java [localhost-startStop-1])
* INFO  2014-09-12 20:08:56,480 Executing startup routine [1 of 14, runlevel 1]:
 TableAlteror (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2014-09-12 20:09:01,001 Executing startup routine [2 of 14, runlevel 2]:
 PeriodTypePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1]
)
* INFO  2014-09-12 20:09:01,022 Executing startup routine [3 of 14, runlevel 2]:
 DataElementDefaultDimensionPopulator (DefaultStartupRoutineExecutor.java [local
host-startStop-1])
* INFO  2014-09-12 20:09:01,640 Linked default category with default concept (Da
taElementDefaultDimensionPopulator.java [localhost-startStop-1])
* ERROR 2014-09-12 20:09:01,663 java.lang.IllegalArgumentException: No enum cons
tant org.hisp.dhis.dataelement.DataElementDomain.t
        at java.lang.Enum.valueOf(Unknown Source)
        at org.hisp.dhis.hibernate.EnumUserType.nullSafeGet(EnumUserType.java:74
)
        at org.hibernate.type.CustomType.nullSafeGet(CustomType.java:127)
        at org.hibernate.type.AbstractType.hydrate(AbstractType.java:106)
        at org.hibernate.persister.entity.AbstractEntityPersister.hydrate(Abstra
ctEntityPersister.java:2903)
        at org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1668)
        at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1600)
        at org.hibernate.loader.Loader.getRow(Loader.java:1500)
        at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:712)
        at org.hibernate.loader.Loader.processResultSet(Loader.java:940)
        at org.hibernate.loader.Loader.doQuery(Loader.java:910)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Lo
ader.java:341)
        at org.hibernate.loader.Loader.doList(Loader.java:2516)
        at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2361)
        at org.hibernate.loader.Loader.list(Loader.java:2324)
        at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:490)
        at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslat
orImpl.java:355)
        at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.
java:195)
        at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1268)
        at org.hibernate.internal.QueryImpl.list(QueryImpl.java:101)
        at org.hisp.dhis.hibernate.HibernateGenericStore.getAll(HibernateGeneric
Store.java:345)
        at org.hisp.dhis.dataelement.DefaultDataElementService.getAllDataElement
s(DefaultDataElementService.java:128)
        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.springframework.aop.support.AopUtils.invokeJoinpointUsingReflecti
on(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJo
inpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:150)
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.
proceedWithInvocation(TransactionInterceptor.java:96)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.
invokeWithinTransaction(TransactionAspectSupport.java:260)
        at org.springframework.transaction.interceptor.TransactionInterceptor.in
voke(TransactionInterceptor.java:94)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invok
e(ExposeInvocationInterceptor.java:91)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynami
cAopProxy.java:204)
        at com.sun.proxy.$Proxy51.getAllDataElements(Unknown Source)
        at org.hisp.dhis.dataelement.DataElementDefaultDimensionPopulator.execut
e(DataElementDefaultDimensionPopulator.java:134)
        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.springframework.aop.support.AopUtils.invokeJoinpointUsingReflecti
on(AopUtils.java:317)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJo
inpoint(ReflectiveMethodInvocation.java:183)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:150)
        at org.springframework.transaction.interceptor.TransactionInterceptor$1.
proceedWithInvocation(TransactionInterceptor.java:96)
        at org.springframework.transaction.interceptor.TransactionAspectSupport.
invokeWithinTransaction(TransactionAspectSupport.java:260)
        at org.springframework.transaction.interceptor.TransactionInterceptor.in
voke(TransactionInterceptor.java:94)
        at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(
ReflectiveMethodInvocation.java:172)
        at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynami
cAopProxy.java:204)
        at com.sun.proxy.$Proxy73.execute(Unknown Source)
        at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(De
faultStartupRoutineExecutor.java:115)
        at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(De
faultStartupRoutineExecutor.java:85)
        at org.hisp.dhis.system.startup.StartupListener.contextInitialized(Start
upListener.java:68)
        at org.apache.catalina.core.StandardContext.listenerStart(StandardContex
t.java:4750)
        at org.apache.catalina.core.StandardContext.startInternal(StandardContex
t.java:5170)
        at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
        at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase
.java:724)
        at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:70
0)
        at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:697)

        at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:919)

        at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:
1704)
        at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
        at java.util.concurrent.FutureTask.run(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
        at java.lang.Thread.run(Unknown Source)
 (StartupListener.java [localhost-startStop-1])
12-Sep-2014 20:09:01.672 SEVERE [localhost-startStop-1] org.apache.catalina.core
.StandardContext.startInternal Error listenerStart
12-Sep-2014 20:09:01.673 SEVERE [localhost-startStop-1] org.apache.catalina.core
.StandardContext.startInternal Context [] startup failed due to previous errors
* INFO  2014-09-12 20:09:01,677 De-registering jdbc driver: org.postgresql.Drive
r@c6a37b0 (StartupListener.java [localhost-startStop-1])
12-Sep-2014 20:09:01.762 INFO [localhost-startStop-1] com.hazelcast.hibernate.Ha
zelcastLocalCacheRegionFactory.null Shutting down HazelcastLocalCacheRegionFacto
ry
12-Sep-2014 20:09:01.763 INFO [localhost-startStop-1] com.hazelcast.core.Lifecyc
leService.null [127.0.0.1]:5701 [dev] [3.2.1] Address[127.0.0.1]:5701 is SHUTTIN
G_DOWN
12-Sep-2014 20:09:01.786 INFO [localhost-startStop-1] com.hazelcast.initializer.
null [127.0.0.1]:5701 [dev] [3.2.1] Destroying node initializer.
12-Sep-2014 20:09:01.787 INFO [localhost-startStop-1] com.hazelcast.instance.Nod
e.null [127.0.0.1]:5701 [dev] [3.2.1] Hazelcast Shutdown is completed in 18 ms.
12-Sep-2014 20:09:01.788 INFO [localhost-startStop-1] com.hazelcast.core.Lifecyc
leService.null [127.0.0.1]:5701 [dev] [3.2.1] Address[127.0.0.1]:5701 is SHUTDOW
N
12-Sep-2014 20:09:01.821 SEVERE [localhost-startStop-1] org.apache.catalina.load
er.WebappClassLoader.checkThreadLocalMapForLeaks The web application [] created
a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadL
ocal@11e0becb]) and a value of type [org.springframework.security.core.context.S
ecurityContextImpl] (value [org.springframework.security.core.context.SecurityCo
ntextImpl@ffffffff: Null authentication]) but failed to remove it when the web a
pplication was stopped. Threads are going to be renewed over time to try and avo
id a probable memory leak.
12-Sep-2014 20:09:01.823 SEVERE [localhost-startStop-1] org.apache.catalina.load
er.WebappClassLoader.checkThreadLocalMapForLeaks The web application [] created
a ThreadLocal with key of type [com.hazelcast.util.UuidUtil$1] (value [com.hazel
cast.util.UuidUtil$1@3f5c6b0a]) and a value of type [java.util.Random] (value [j
ava.util.Random@7af2209d]) but failed to remove it when the web application was
stopped. Threads are going to be renewed over time to try and avoid a probable m
emory leak.
12-Sep-2014 20:09:01.833 INFO [localhost-startStop-1] org.apache.catalina.startu
p.HostConfig.deployWAR Deployment of web application archive C:\apache-tomcat-8.
0.8\webapps\ROOT.war has finished in 143,857 ms
12-Sep-2014 20:09:01.838 INFO [main] org.apache.coyote.AbstractProtocol.start St
arting ProtocolHandler ["http-apr-8080"]
12-Sep-2014 20:09:01.861 INFO [main] org.apache.coyote.AbstractProtocol.start St
arting ProtocolHandler ["ajp-apr-8009"]
12-Sep-2014 20:09:01.866 INFO [main] org.apache.catalina.startup.Catalina.start
Server startup in 143959 ms