Error: App can't start on test environment

Hey All i was upgrading from 2.8 to 2.9 but i see this error and my app cant start on test environment.

Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version:        Apache Tomcat/7.0.68 (Ubuntu)
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built:          Jun 27 2016 18:13:17 UTC
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number:         7.0.68.0
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name:               Linux
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version:            4.4.0-31-generic
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture:          amd64
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Java Home:             /usr/lib/jvm/java-8-openjdk-amd64/jre
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version:           1.8.0_181-8u181-b13-0ubuntu0.16.04.1-b13
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor:            Oracle Corporation
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE:         /home/dhis/tomcat-dhis
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME:         /usr/share/tomcat7
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/home/dhis/tomcat-dhis/conf/logging.properties
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xmx2000m
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xms1000m
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.endorsed.dirs=/usr/share/tomcat7/endorsed
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/home/dhis/tomcat-dhis
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/usr/share/tomcat7
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/home/dhis/tomcat-dhis/temp
Oct 15, 2018 12:33:03 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-bio-10.129.192.186-8080"]
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 691 ms
Oct 15, 2018 12:33:03 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Oct 15, 2018 12:33:03 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/7.0.68 (Ubuntu)
Oct 15, 2018 12:33:03 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /home/dhis/tomcat-dhis/webapps/ROOT.war
Oct 15, 2018 12:33:12 PM org.apache.catalina.startup.TldConfig execute
INFO: At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
* INFO  2018-10-15 12:33:16,510 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:16,515 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:16,536 File /home/dhis/config/dhis-google-auth.json does not exist (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:16,536 Could not find dhis-google-auth.json (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:16,537 File /home/dhis/config/dhis-google-auth.json does not exist (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:16,537 Could not find dhis-google-auth.json (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:18,112 Hibernate configuration loaded, using dialect: org.hisp.dhis.hibernate.dialect.DhisPostgresDialect, region factory: org.hibernate.cache.ehcache.EhCacheRegionFactory (DefaultHibernateConfigurationProvider.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:36,786 Old apps folder does not exist, stopping discovery (LocalAppStorageService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:37,846 File store configured with provider: 'filesystem', container: 'files' and location: ''. (JCloudsAppStorageService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:37,846 Starting JClouds discovery (JCloudsAppStorageService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:37,853 No apps found during JClouds discovery. (JCloudsAppStorageService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:40,169 File store configured with provider: 'filesystem', container: 'files' and location: ''. (JCloudsFileResourceContentStore.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:40,272 Found the following message senders: [org.hisp.dhis.message.EmailMessageSender@35ef35ec, org.hisp.dhis.sms.config.SmsMessageSender@414ca1f1] (DefaultMessageService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:40,455 Read only configuration initialized, read replicas found: 0 (DefaultDataSourceManager.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:42,385 Following listners are registered: [org.hisp.dhis.sms.listener.DataValueSMSListener@3a5d40fe, org.hisp.dhis.sms.listener.J2MEDataValueSMSListener@33551ad7, org.hisp.dhis.sms.listener.UnregisteredSMSListener@524fae33, org.hisp.dhis.sms.listener.DhisMessageAlertListener@ffb8ce5, org.hisp.dhis.sms.listener.TrackedEntityRegistrationSMSListener@2afb7f85, org.hisp.dhis.sms.listener.ProgramStageDataEntrySMSListener@22ae1bb, org.hisp.dhis.sms.listener.SingleEventListener@7a7df446] (SmsConsumerThread.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:42,563 SMS consumer started (DefaultSmsConsumerService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,110 Scheduled monitoring service (DefaultMonitoringService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,739 Added logger: org.hisp.dhis.resourcetable using file: /home/dhis/config/logs/dhis-analytics-table.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,739 Added logger: org.hisp.dhis.analytics.table using file: /home/dhis/config/logs/dhis-analytics-table.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,740 Added logger: org.hisp.dhis.dxf2 using file: /home/dhis/config/logs/dhis-data-exchange.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,740 Added logger: org.hisp.dhis.dxf2.synch using file: /home/dhis/config/logs/dhis-data-sync.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,740 Added logger: org.hisp.dhis.dxf2.metadata using file: /home/dhis/config/logs/dhis-metadata-sync.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,740 Added logger: org.hisp.dhis.pushanalysis using file: /home/dhis/config/logs/dhis-push-analysis.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:44,741 Added root logger using file: /home/dhis/config/logs/dhis.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:45,284 Session timeout set to 3600 seconds (DefaultAuthenticationSuccessHandler.java [localhost-startStop-1])
* WARN  2018-10-15 12:33:45,523 RP discovery / realm validation disabled;  (RealmVerifier.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:48,311 Version: 2.29, revision: 1cd9ff1, build date: Mon Oct 15 02:20:56 CAT 2018, database name: sfhdb_test, database type: DhisPostgres, Java version: 1.8.0_181 (DefaultSystemService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:48,354 Gateway configuration not found (DefaultGatewayAdministrationService.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:48,374 Executing startup routine [1 of 18, runlevel 1]: InitTableAlteror (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:48,785 Upgraded program stage data elements (InitTableAlteror.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:50,001 Executing startup routine [2 of 18, runlevel 2]: PeriodTypePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:50,017 Executing startup routine [3 of 18, runlevel 3]: DataElementDefaultDimensionPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:50,055 'system-process' update org.hisp.dhis.dataelement.DataElementCategory, name: default, uid: h01nOF2x3NO (AuditLogUtil.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:51,308 Executing startup routine [4 of 18, runlevel 4]: IdentityPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,014 Executing startup routine [5 of 18, runlevel 4]: ReportingIdentityPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,194 Executing startup routine [6 of 18, runlevel 5]: SchedulerUpgrade (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,206 Porting old jobs (SchedulerUpgrade.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,227 'system-process' create org.hisp.dhis.scheduling.JobConfiguration, name: Analytics, uid: TosXBpGix4p (AuditLogUtil.java [localhost-startStop-1])
* ERROR 2018-10-15 12:33:52,250 Could not map job type '[resourceTableTask]' with cron '0 0 23 * * ?' (SchedulerUpgrade.java [localhost-startStop-1])
* ERROR 2018-10-15 12:33:52,250 Could not map job type '[resourceTableTask]' with cron '0 0 23 * * ?' (SchedulerUpgrade.java [localhost-startStop-1])
* ERROR 2018-10-15 12:33:52,250 Could not map job type '[resourceTableTask]' with cron '0 0 23 * * ?' (SchedulerUpgrade.java [localhost-startStop-1])
* ERROR 2018-10-15 12:33:52,251 Could not map job type '[resourceTableTask]' with cron '0 0 23 * * ?' (SchedulerUpgrade.java [localhost-startStop-1])
* ERROR 2018-10-15 12:33:52,251 Could not map job type '[resourceTableTask]' with cron '0 0 23 * * ?' (SchedulerUpgrade.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,252 'system-process' create org.hisp.dhis.scheduling.JobConfiguration, name: Resource table, uid: PvntY7wrLAH (AuditLogUtil.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,256 Moving existing Push Analysis jobs. (SchedulerUpgrade.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,271 'system-process' create org.hisp.dhis.scheduling.JobConfiguration, name: PushAnalysis: JmuWTH9oUcn, uid: cvNt0Yfu1ud (AuditLogUtil.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,283 'system-process' create org.hisp.dhis.scheduling.JobConfiguration, name: PushAnalysis: MWotV5Va75Q, uid: gYCJ0wzIuug (AuditLogUtil.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,291 'system-process' create org.hisp.dhis.scheduling.JobConfiguration, name: PushAnalysis: GeryOIbsWhg, uid: ACOmGC55tUb (AuditLogUtil.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,298 'system-process' create org.hisp.dhis.scheduling.JobConfiguration, name: PushAnalysis: a19w4BhUNo8, uid: xl33RkPZYZR (AuditLogUtil.java [localhost-startStop-1])
* INFO  2018-10-15 12:33:52,302 'system-process' create org.hisp.dhis.scheduling.JobConfiguration, name: PushAnalysis: PNhbOVQfNzv, uid: v3515rgeAGF (AuditLogUtil.java [localhost-startStop-1])
* ERROR 2018-10-15 12:33:52,309 java.lang.NullPointerException
    at org.hisp.dhis.startup.SchedulerUpgrade.lambda$execute$2(SchedulerUpgrade.java:164)
    at java.util.ArrayList.forEach(ArrayList.java:1257)
    at org.hisp.dhis.startup.SchedulerUpgrade.execute(SchedulerUpgrade.java:161)
    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)
    at com.sun.proxy.$Proxy194.execute(Unknown Source)
    at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:113)
    at org.hisp.dhis.system.startup.DefaultStartupRoutineExecutor.execute(DefaultStartupRoutineExecutor.java:70)
    at org.hisp.dhis.system.startup.StartupListener.contextInitialized(StartupListener.java:71)
    at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:5068)
    at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5584)
    at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:147)
    at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:899)
    at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:875)
    at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:652)
    at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1091)
    at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1980)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
 (StartupListener.java [localhost-startStop-1])
Oct 15, 2018 12:33:52 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: One or more listeners failed to start. Full details will be found in the appropriate container log file
Oct 15, 2018 12:33:52 PM org.apache.catalina.core.StandardContext startInternal
SEVERE: Context [] startup failed due to previous errors
* INFO  2018-10-15 12:33:52,327 De-registering jdbc driver: org.postgresql.Driver@22870de3 (StartupListener.java [localhost-startStop-1])
Oct 15, 2018 12:33:52 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [com.google.inject.internal.util.$Finalizer] but has failed to stop it. This is very likely to create a memory leak.
Oct 15, 2018 12:33:52 PM org.apache.catalina.loader.WebappClassLoaderBase clearReferencesThreads
SEVERE: The web application [] appears to have started a thread named [ForkJoinPool.commonPool-worker-25] but has failed to stop it. This is very likely to create a memory leak.
Oct 15, 2018 12:33:52 PM org.apache.catalina.loader.WebappClassLoaderBase checkThreadLocalMapForLeaks
SEVERE: The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@1604926a]) and a value of type [org.hibernate.boot.internal.MetadataImpl] (value [org.hibernate.boot.internal.MetadataImpl@4d8c5915]) 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 memory leak.
Oct 15, 2018 12:33:52 PM org.apache.catalina.loader.WebappClassLoaderBase checkThreadLocalMapForLeaks
SEVERE: The web application [] created a ThreadLocal with key of type [java.lang.ThreadLocal] (value [java.lang.ThreadLocal@3350b2ef]) and a value of type [org.springframework.security.core.context.SecurityContextImpl] (value [org.springframework.security.core.context.SecurityContextImpl@ffffffff: Null authentication]) 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 memory leak.
Oct 15, 2018 12:33:52 PM org.apache.catalina.loader.WebappClassLoaderBase checkThreadLocalMapForLeaks
SEVERE: The web application [] created a ThreadLocal with key of type [com.google.inject.internal.InjectorImpl$1] (value [com.google.inject.internal.InjectorImpl$1@51bed0d6]) and a value of type [java.lang.Object[]] (value [[Ljava.lang.Object;@639b8f49]) 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 memory leak.
Oct 15, 2018 12:33:52 PM org.apache.catalina.loader.WebappClassLoaderBase checkThreadLocalMapForLeaks
SEVERE: The web application [] created a ThreadLocal with key of type [com.google.inject.internal.InjectorImpl$1] (value [com.google.inject.internal.InjectorImpl$1@4cf026de]) and a value of type [java.lang.Object[]] (value [[Ljava.lang.Object;@7a813265]) 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 memory leak.
Oct 15, 2018 12:33:52 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deployment of web application archive /home/dhis/tomcat-dhis/webapps/ROOT.war has finished in 48,819 ms
Oct 15, 2018 12:33:52 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-bio-10.129.192.186-8080"]
Oct 15, 2018 12:33:52 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 48898 ms

please help i dont understand the error

···

developer_lusaka_systems

1 Like

Hi @moses_mwale,

Sorry for the late reply to this post; did you manage to upgrade your instance?

Best,
James.

I did thank you, i am trying to remember what i did so that i share it for everyone

1 Like

Thank you for the update @moses_mwale; the community will appreciate your fix for this.

Best,
James.

1 Like

Hi @moses_mwale

Please note I am facing a challenge. My web app is not deploying. When I looked into the logs I found

Old apps folder does not exist, stopping discovery

Kind of error. Looks like you resolved the issue. Can you please share what did you do.

Thank you and I highly appreciate your help.

Regards

MSP

Hello, @MSP Please share a complete log that everyone can have a look. whats the webapp name, what version of dhis2 are you using?

I restarted the server and services and it is working now.

Great, that’s good news to hear you solved it that way.