dhis2-devs team mailing list archive

[Olav Poppe <olav.poppe@xxxxxx>]

So just to highlight, this is where it seems to go wrong, but it is not clear why/what:
	
* INFO  2017-12-17 19:18:00,843 [Level: INFO, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-19])
* INFO  2017-12-17 19:18:00,845 [Level: ERROR, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Process failed: null] (InMemoryNotifier.java [taskScheduler-19])

> 18. des. 2017 kl. 07:42 skrev Olav Poppe <olav.poppe@xxxxxx>:
> 
> Thanks Alex, but those email adresses have just been removed from the log for the purpose of sharing it here - they are in the system.
> 
> Regards
> Olav
> 
> 18. des. 2017 kl. 04:07 skrev Alex Tumwesigye <atumwesigye@xxxxxxxxx <mailto:atumwesigye@xxxxxxxxx>>:
> 
>> Hello Olav
>> Add an email address to user sakibou
>> 
>> Alex
>> 
>> On Monday, December 18, 2017, Olav Poppe <olav.poppe@xxxxxx <mailto:olav.poppe@xxxxxx>> wrote:
>> Hi devs, 
>> we have an instance newly upgraded to 2.28 where analytics fails on generation of VALIDATION_RESULTS. This does not happen on the staging server we used for testing, which has a copy of the production server from a few weeks back, so only minor differences. Unfortunately, there is limited info in the log (copied below) - any advice on troubleshooting? Is VALIDATION_RESULTS supposed to have the result of running validation rules? If so, these are the same on the staging and production server.
>> 
>> Regards
>> Olav
>> 
>> 
>> 
>> * INFO  2017-12-17 19:18:00,789 Table update done: analytics_orgunittarget: 00:00:00.577 (Clock.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,789 [Level: INFO, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Table update done] (InMemoryNotifier.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,789 [Level: INFO, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Updating tables: VALIDATION_RESULT] (InMemoryNotifier.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,790 Starting update: analytics_validationresult, processes: 11, org unit levels: 6: 00:00:00.000 (Clock.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,793 Get tables using earliest: Sun Jan 01 00:00:00 UTC 2017 (JdbcValidationResultTableManager.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,796 Table update start: analytics_validationresult, partitions: [analytics_validationresult_2017], last years: 1, earliest: Sun Jan 01 00:00:00 UTC 2017: 00:00:00.006 (Clock.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,797 [Level: INFO, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Performing pre-create table work, org unit levels: 6] (InMemoryNotifier.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,797 Performed pre-create table work: 00:00:00.007 (Clock.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,797 [Level: INFO, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Creating analytics tables] (InMemoryNotifier.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,805 Creating table: analytics_validationresult_temp_2017, columns: 28 (JdbcValidationResultTableManager.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,807 Created analytics tables: 00:00:00.017 (Clock.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,807 [Level: INFO, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Populating analytics tables] (InMemoryNotifier.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,808 Populate table task number: 1 (DefaultAnalyticsTableService.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,843 Populated table in 0.03 seconds: analytics_validationresult_temp_2017 (AbstractJdbcTableManager.java [taskScheduler-15])
>> * INFO  2017-12-17 19:18:00,843 Populated analytics tables: 00:00:00.053 (Clock.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,843 [Level: INFO, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,845 [Level: ERROR, category: ANALYTICSTABLE_UPDATE, time: Sun Dec 17 19:18:00 UTC 2017, message: Process failed: null] (InMemoryNotifier.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,849 'system-process' create org.hisp.dhis.message.MessageConversation, name: Analytics table process failed, uid: rTGPfiuHkgV (AuditLogUtil.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,851 Gateway configuration does not exist (SmsMessageSender.java [taskScheduler-19])
>> * INFO  2017-12-17 19:18:00,853 Sending email to user: null with email address:  to host: smtp.gmail.com:587 <http://smtp.gmail.com:587/> (EmailMessageSender.java [taskScheduler-13])
>> * INFO  2017-12-17 19:18:00,854 Sending email to user: sakibou with email address:  to host: smtp.gmail.com:587 <http://smtp.gmail.com:587/> (EmailMessageSender.java [taskScheduler-11])
>> * ERROR 2017-12-17 19:18:00,858 Unexpected error occurred in scheduled task. (TaskUtils.java [taskScheduler-19])
>> java.lang.NullPointerException
>> 	at org.hisp.dhis.commons.util.ConcurrentUtils.waitForCompletion(ConcurrentUtils.java:53)
>> 	at org.hisp.dhis.analytics.table.DefaultAnalyticsTableService.applyAggregationLevels(DefaultAnalyticsTableService.java:242)
>> 	at org.hisp.dhis.analytics.table.DefaultAnalyticsTableService.update(DefaultAnalyticsTableService.java:137)
>> 	at org.hisp.dhis.analytics.table.DefaultAnalyticsTableGenerator.generateTables(DefaultAnalyticsTableGenerator.java:112)
>> 	at org.hisp.dhis.webapi.controller.ResourceTableController.lambda$analytics$0(ResourceTableController.java:112)
>> 	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
>> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
>> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
>> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>> 	at java.lang.Thread.run(Thread.java:745)
>> * INFO  2017-12-17 19:18:02,357 Email sent using host: smtp.gmail.com:587 <http://smtp.gmail.com:587/> with TLS: true (EmailMessageSender.java [taskScheduler-13])
>> * INFO  2017-12-17 19:18:03,049 Email sent using host: smtp.gmail.com:587 <http://smtp.gmail.com:587/> with TLS: true (EmailMessageSender.java [taskScheduler-11])
>> 
>> 
>> -- 
>> Alex Tumwesigye
>> 
>> Technical Advisor - DHIS2 (Consultant),
>> Ministry of Health/AFENET  | HISP Uganda
>> Kampala
>> Uganda
>> +256 774149 775 <>, + 256 759 800161 <>
>> Skype ID: talexie
>> 
>> IT Consultant (Servers, Networks and Security, Health Information Systems - DHIS2, Disease Outbreak & Surveillance Systems) & Solar Consultant
>> 
>> 
>> "I don't want to be anything other than what I have been - one tree hill "
>> 
> _______________________________________________
> 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