Unable to login to DHIS2 on the local instance

Support - Assistance technique
1

Hi all,

I have installed dhis2 versioned 2.33.0 on the local instance following steps mentioned in the Home - DHIS2 Documentation link. I have also restored the sample database dump. I am able to create new users, but couldn’t log in using username as ‘admin’.or a newly created user. Page gets reloaded on the click of the Sign In button.
Following warning message has been displayed in the log-

WARN 2019-11-26 20:07:42,969 Authentication event InteractiveAuthenticationSuccessEvent: admin; details: org.hisp.dhis.security.spring2fa.TwoFactorWebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null (LoggerListener.java [http-nio-8080-exec-1]).

*** Getting a null value in the SessionId

Any help would be appreciated.

Thank you

1 Like
2

Hi @Aparna,
Welcome to the DHIS2 Community! @julhas - could you please assist Aparna with this?

3

Thank you. :slightly_smiling_face:

1 Like
4

Main logs for the reference-

Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server version:        Apache Tomcat/8.0.32 (Ubuntu)
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server built:          Sep 9 2019 12:49:23 UTC
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Server number:         8.0.32.0
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Name:               Linux
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: OS Version:            4.4.0-169-generic
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Architecture:          amd64
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Java Home:             /usr/lib/jvm/java-8-oracle/jre
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Version:           1.8.0_171-b11
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: JVM Vendor:            Oracle Corporation
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_BASE:         /home/dhis/tomcat-dhis
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: CATALINA_HOME:         /usr/share/tomcat8
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.config.file=/home/dhis/tomcat-dhis/conf/logging.properties
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xmx7500m
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Xms4000m
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.endorsed.dirs=/usr/share/tomcat8/endorsed
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.base=/home/dhis/tomcat-dhis
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Dcatalina.home=/usr/share/tomcat8
Nov 27, 2019 2:02:32 PM org.apache.catalina.startup.VersionLoggerListener log
INFO: Command line argument: -Djava.io.tmpdir=/home/dhis/tomcat-dhis/temp
Nov 27, 2019 2:02:33 PM org.apache.coyote.AbstractProtocol init
INFO: Initializing ProtocolHandler ["http-nio-8080"]
Nov 27, 2019 2:02:33 PM org.apache.tomcat.util.net.NioSelectorPool getSharedSelector
INFO: Using a shared selector for servlet write/read
Nov 27, 2019 2:02:33 PM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 2046 ms
Nov 27, 2019 2:02:33 PM org.apache.catalina.core.StandardService startInternal
INFO: Starting service Catalina
Nov 27, 2019 2:02:33 PM org.apache.catalina.core.StandardEngine startInternal
INFO: Starting Servlet Engine: Apache Tomcat/8.0.32 (Ubuntu)
Nov 27, 2019 2:02:33 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deploying web application archive /home/dhis/tomcat-dhis/webapps/ROOT.war
Nov 27, 2019 2:02:51 PM org.apache.jasper.servlet.TldScanner scanJars
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  2019-11-27 14:02:51,488 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:51,492 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:52,092 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:52,093 HTTPS only is enabled, cookies configured as secure (SecureCookieConfiguration.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,355 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,356 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,360 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,362 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,362 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,366 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,367 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,368 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,372 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,373 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,373 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,377 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,379 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,380 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,383 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,385 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,386 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,390 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,391 Monitoring metric for key monitoring.jvm.enabled is disabled (MetricsEnabler.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,393 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,393 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,398 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,400 Monitoring metric for key monitoring.cpu.enabled is disabled (MetricsEnabler.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,402 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,402 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,411 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,412 Monitoring metric for key monitoring.uptime.enabled is disabled (MetricsEnabler.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,413 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,414 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,423 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,427 Monitoring metric for key monitoring.dbpool.enabled is disabled (MetricsEnabler.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,429 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,430 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,438 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,440 Monitoring metric for key monitoring.hibernate.enabled is disabled (MetricsEnabler.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,462 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,462 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,475 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,476 Monitoring metric for key monitoring.api.enabled is disabled (MetricsEnabler.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,479 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,479 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,489 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,490 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,490 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,497 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,499 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,499 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:56,514 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:57,123 System property dhis2.home not set (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:57,124 Environment variable DHIS2_HOME points to /home/dhis/config (DefaultLocationManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:57,132 Loaded dhis-google-auth.json authentication file (DefaultDhisConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:02:59,342 Hibernate configuration loaded: dialect: 'org.hisp.dhis.hibernate.dialect.DhisPostgresDialect', region factory: 'org.hibernate.cache.ehcache.EhCacheRegionFactory', connection pool max size: 80 (DefaultHibernateConfigurationProvider.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:05,191 Simple Local Cache instance created for region:'periodCache' (SimpleCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:12,113 Local Cache (forced) instance created for region:'userIdCache' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:12,731 Read only configuration initialized, read replicas found: 0 (DefaultDataSourceManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:12,846 Local Cache instance created for region:'systemSetting' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:13,294 Local Cache (forced) instance created for region:'periodIdCache' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:14,514 Local Cache (forced) instance created for region:'defaultObjectCache' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:15,885 File store configured with provider: 'filesystem', container: 'files' and location: ''. (JCloudsAppStorageService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:15,900 Local Cache instance created for region:'appCache' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:15,902 Old apps folder does not exist, stopping discovery (LocalAppStorageService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:15,904 Starting JClouds discovery (JCloudsAppStorageService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:15,914 No apps found during JClouds discovery. (JCloudsAppStorageService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,088 Local Cache instance created for region:'userSetting' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,098 Local Cache (forced) instance created for region:'inUserOuHierarchy' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,103 Local Cache (forced) instance created for region:'inUserSearchOuHierarchy' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,414 File store configured with provider: 'filesystem', container: 'files' and location: ''. (JCloudsFileResourceContentStore.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,907 NoOp Cache instance created for region:'eventAnalyticsQueryResponse' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,909 Event analytics server-side cache is enabled: false with expiration: 0 s (DefaultEventAnalyticsService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,913 NoOp Cache instance created for region:'analyticsQueryResponse' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:16,914 Analytics server-side cache is enabled: false with expiration: 0 s (DefaultAnalyticsService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:17,248 Local Cache instance created for region:'tempTrackerOwnership' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:17,251 Local Cache instance created for region:'OrganisationUnitOwner' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:17,693 Found the following message senders:
EmailMessageSender$$EnhancerBySpringCGLIB$$d86e1d4b
SmsMessageSender$$EnhancerBySpringCGLIB$$f0fb9b8a
 (DefaultMessageService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:18,072 Starting embedded Artemis ActiveMQ server. (DefaultAmqpManager.java [localhost-startStop-1])
* WARN  2019-11-27 14:03:18,350 AMQ222275: Failed to deploy queue DLQ: null (ActiveMQServerImpl.java [localhost-startStop-1])
* WARN  2019-11-27 14:03:18,351 AMQ222275: Failed to deploy queue ExpiryQueue: null (ActiveMQServerImpl.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,352 Setting up noop leader manager using dummy NodeId:9e8fcf06-e7a9-4b6e-a607-9dff93136e96 (NoOpLeaderManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,377 Initializing Log4j, max file size: '100MB', max file archives: 0 (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,379 Added logger: org.hisp.dhis.resourcetable using file: /home/dhis/config/logs/dhis-analytics-table.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,380 Added logger: org.hisp.dhis.analytics.table using file: /home/dhis/config/logs/dhis-analytics-table.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,380 Added logger: org.hisp.dhis.dxf2 using file: /home/dhis/config/logs/dhis-data-exchange.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,380 Added logger: org.hisp.dhis.dxf2.synch using file: /home/dhis/config/logs/dhis-data-sync.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,381 Added logger: org.hisp.dhis.dxf2.metadata using file: /home/dhis/config/logs/dhis-metadata-sync.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,381 Added logger: org.hisp.dhis.pushanalysis using file: /home/dhis/config/logs/dhis-push-analysis.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,381 Added root logger using file: /home/dhis/config/logs/dhis.log (Log4JLogConfigInitializer.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:20,757 Simple Local Cache instance created for region:'canDataWriteCocCache' (SimpleCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:21,029 Local Cache instance created for region:'metadataAttributes' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:21,796 DHIS 2 Version: 2.33.0, Revision: 071f135, Build date: Mon Oct 07 14:46:01 IST 2019, Database name: dhis2, Java version: 1.8.0_171 (DefaultSystemService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:21,839 Local Cache instance created for region:'isDataApproved' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:22,192 Following listners are registered: [org.hisp.dhis.sms.listener.TrackedEntityRegistrationSMSListener@c844d2b, org.hisp.dhis.sms.listener.EnrollmentSMSListener@51aa741, org.hisp.dhis.sms.listener.SingleEventListener@4573a8f0, org.hisp.dhis.sms.listener.AggregateDataSetSMSListener@4903b56e, org.hisp.dhis.sms.listener.RelationshipSMSListener@7eb1d8a1, org.hisp.dhis.sms.listener.SimpleEventSMSListener@22e1b12a, org.hisp.dhis.sms.listener.DeleteEventSMSListener@2c63abeb, org.hisp.dhis.sms.listener.UnregisteredSMSListener@7d0c92c1, org.hisp.dhis.sms.listener.J2MEDataValueSMSListener@5a74acb1, org.hisp.dhis.sms.listener.DataValueSMSListener@423d90fd, org.hisp.dhis.sms.listener.DhisMessageAlertListener@7e7933d8, org.hisp.dhis.sms.listener.ProgramStageDataEntrySMSListener@3a7cade, org.hisp.dhis.sms.listener.TrackerEventSMSListener@1d1b5d95] (SmsConsumerThread.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:22,246 SMS consumer started (DefaultSmsConsumerService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:22,583 Local Cache instance created for region:'userFailedLoginAttempt' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:23,301 Local Cache (forced) instance created for region:'attrOptionComboIdCache' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:23,739 Local Cache instance created for region:'googleAccessToken' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:24,207 Scheduled monitoring service (DefaultMonitoringService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:24,626 Session timeout set to 3600 seconds (DefaultAuthenticationSuccessHandler.java [localhost-startStop-1])
* WARN  2019-11-27 14:03:24,762 RP discovery / realm validation disabled;  (RealmVerifier.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:25,432 No Gateway configuration not found (DefaultGatewayAdministrationService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,106 Executing startup routine [1 of 11, runlevel 2]: PeriodTypePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,134 Executing startup routine [2 of 11, runlevel 2]: PeriodTypePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,186 Executing startup routine [3 of 11, runlevel 3]: DataElementDefaultDimensionPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,241 'system-process' update org.hisp.dhis.category.Category, name: default, uid: GLevLNI9wkl (AuditLogUtil.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,915 Executing startup routine [4 of 11, runlevel 7]: ModelUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,926 Executing startup routine [5 of 11, runlevel 9]: FavoriteDataItemUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,941 Executing startup routine [6 of 11, runlevel 9]: AnalyticalObjectEmbeddedDimensionUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:27,947 Executing startup routine [7 of 11, runlevel 11]: ExpressionUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,084 Executing startup routine [8 of 11, runlevel 12]: ConfigurationPopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,085 Encryption is available (ConfigurationPopulator.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,087 Executing startup routine [9 of 11, runlevel 13]: I18nLocalePopulator (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,099 Executing startup routine [10 of 11, runlevel 14]: SettingUpgrader (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,103 Executing startup routine [11 of 11, runlevel 14]: SchedulerStart (DefaultStartupRoutineExecutor.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,122 Setting up default jobs. (SchedulerStart.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,136 'system-process' update org.hisp.dhis.scheduling.JobConfiguration, name: Validation result notification, uid: Js3vHn2AVuG (AuditLogUtil.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,165 Scheduling job: JobConfiguration{uid='Js3vHn2AVuG', displayName='null', cronExpression='0 0 7 * * ?', jobType=VALIDATION_RESULTS_NOTIFICATION, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.025', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 07:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 07:00:00.026} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,168 Scheduled job: JobConfiguration{uid='Js3vHn2AVuG', displayName='null', cronExpression='0 0 7 * * ?', jobType=VALIDATION_RESULTS_NOTIFICATION, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.025', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 07:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 07:00:00.026} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,169 'system-process' update org.hisp.dhis.scheduling.JobConfiguration, name: Remove expired reserved values, uid: uwWCT2BMmlq (AuditLogUtil.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,182 Scheduling job: JobConfiguration{uid='uwWCT2BMmlq', displayName='null', cronExpression='0 0 * ? * *', jobType=REMOVE_EXPIRED_RESERVED_VALUES, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.619', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Wed Nov 27 15:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-11-27 13:00:00.673} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,184 Scheduled job: JobConfiguration{uid='uwWCT2BMmlq', displayName='null', cronExpression='0 0 * ? * *', jobType=REMOVE_EXPIRED_RESERVED_VALUES, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.619', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Wed Nov 27 15:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-11-27 13:00:00.673} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,185 'system-process' update org.hisp.dhis.scheduling.JobConfiguration, name: Dataset notification, uid: YvAwAmrqAtN (AuditLogUtil.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,190 Scheduling job: JobConfiguration{uid='YvAwAmrqAtN', displayName='null', cronExpression='0 0 2 * * ?', jobType=DATA_SET_NOTIFICATION, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.016', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 02:00:00.02} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,191 Scheduled job: JobConfiguration{uid='YvAwAmrqAtN', displayName='null', cronExpression='0 0 2 * * ?', jobType=DATA_SET_NOTIFICATION, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.016', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 02:00:00.02} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,192 'system-process' update org.hisp.dhis.scheduling.JobConfiguration, name: Credentials expiry alert, uid: sHMedQF7VYa (AuditLogUtil.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,197 Scheduling job: JobConfiguration{uid='sHMedQF7VYa', displayName='null', cronExpression='0 0 2 * * ?', jobType=CREDENTIALS_EXPIRY_ALERT, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.096', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 02:00:00.1} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,200 Scheduled job: JobConfiguration{uid='sHMedQF7VYa', displayName='null', cronExpression='0 0 2 * * ?', jobType=CREDENTIALS_EXPIRY_ALERT, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.096', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 02:00:00.1} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,201 'system-process' update org.hisp.dhis.scheduling.JobConfiguration, name: Data statistics, uid: BFa3jDsbtdO (AuditLogUtil.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,206 Scheduling job: JobConfiguration{uid='BFa3jDsbtdO', displayName='null', cronExpression='0 0 2 * * ?', jobType=DATA_STATISTICS, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.160', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 02:00:00.163} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,206 Scheduled job: JobConfiguration{uid='BFa3jDsbtdO', displayName='null', cronExpression='0 0 2 * * ?', jobType=DATA_STATISTICS, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.160', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=COMPLETED, lastExecuted=2019-10-04 02:00:00.163} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,207 'system-process' update org.hisp.dhis.scheduling.JobConfiguration, name: File resource clean up, uid: pd6O228pqr0 (AuditLogUtil.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,214 Scheduling job: JobConfiguration{uid='pd6O228pqr0', displayName='null', cronExpression='0 0 2 * * ?', jobType=FILE_RESOURCE_CLEANUP, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.340', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=FAILED, lastExecuted=2019-10-04 02:00:00.342} (DefaultSchedulingManager.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:28,216 Scheduled job: JobConfiguration{uid='pd6O228pqr0', displayName='null', cronExpression='0 0 2 * * ?', jobType=FILE_RESOURCE_CLEANUP, jobParameters=null, enabled=true, continuousExecution=false, inMemoryJob=false, lastRuntimeExecution='00:00:00.340', userUid='null', leaderOnlyJob=true, jobStatus=SCHEDULED, nextExecutionTime=Thu Nov 28 02:00:00 IST 2019, lastExecutedStatus=FAILED, lastExecuted=2019-10-04 02:00:00.342} (DefaultSchedulingManager.java [localhost-startStop-1])
   * INFO  2019-11-27 14:03:31,818 Local Cache instance created for region:'googleAccessToken' (ExtendedCacheBuilder.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:32,906 No Gateway configuration not found (DefaultGatewayAdministrationService.java [localhost-startStop-1])
* INFO  2019-11-27 14:03:33,339 No Gateway configuration not found (DefaultGatewayAdministrationService.java [localhost-startStop-1])
Nov 27, 2019 2:03:33 PM org.apache.catalina.startup.HostConfig deployWAR
INFO: Deployment of web application archive /home/dhis/tomcat-dhis/webapps/ROOT.war has finished in 60,038 ms
Nov 27, 2019 2:03:33 PM org.apache.coyote.AbstractProtocol start
INFO: Starting ProtocolHandler ["http-nio-8080"]
Nov 27, 2019 2:03:33 PM org.apache.catalina.startup.Catalina start
INFO: Server startup in 60281 ms
* INFO  2019-11-27 14:04:20,981 Login attempt: Aparna123 (TwoFactorAuthenticationProvider.java [http-nio-8080-exec-6])
* WARN  2019-11-27 14:04:23,775 Authentication event InteractiveAuthenticationSuccessEvent: Aparna123; details: org.hisp.dhis.security.spring2fa.TwoFactorWebAuthenticationDetails@b364: RemoteIpAddress: 0:0:0:0:0:0:0:1; SessionId: null (LoggerListener.java [http-nio-8080-exec-6])
6

Hi James,

Sure, let me ping her.

Thanks

1 Like
7

Thank you for always coming through @julhas - you have never disappointed!

1 Like
8

Thanks for the help @julhas :slightly_smiling_face:

1 Like
9

You are welcome @Aparna.

1 Like
10

Just to keep a note. The issue got resolved when I have upgraded Postgres to 11, with tomcat 8 and java 8.
Thanks, @jomutsani, and @julhas for assistance

1 Like
11

Hi @Aparna @julhas What exactly was the problem behind this.

I’m getting the same issue for 2.33.1. we are using postgres 10 and openjdk8 in a Linode instance with Ubuntu 18.04 LTS

* WARN 2019-12-20 14:37:14,473 Authentication event InteractiveAuthenticationSuccessEvent: admin; details: org.hisp.dhis.security.spring2fa.TwoFactorWebAuthenticationDetails@ffff8868: RemoteIpAddress: 113.161.143.244; SessionId: null (LoggerListener.java [http-nio-8080-exec-6])

1 Like
12

@jthomas

I had upgraded postgres to version 11 and it worked. Hopefully it would help you.

Regards
Aparna

1 Like
13

@Aparna & all

I upgraded postgres 10 to 11 but it didn’t solve my problem.

But ultimately my problem turns out to be the following line in dhis.conf

# Enable secure settings if system is deployed on HTTPS, default 'off'
server.https = on

I am using normal http://<ip>:8080 So after i set to off like below it worked fine.

server.https = off

When i turn it on it stop work again, so atleast for me the problem was due to this parameter.

Noting here if at all somebody else face this issue as 2.33 dhis2 installation document
dhis.conf default setting is on

2 Likes
14

@jthomas
Thanks for help
i was facing the same problem and it worked fine for me when i set server.https = off

Regards

2 Likes
15

@dguambe Great… thanks for letting me know

1 Like