INFO  2015-07-30 15:41:55,257 'Elmarie_Claasen': Cleared analytics tables (PerformMaintenanceAction.java [http-nio-8081-exec-9])
* INFO  2015-07-30 15:42:22,578 [Level: INFO, category: DATAMART, time: Thu Jul 30 15:42:22 SAST 2015, message: Analytics table update process started] (InMemoryNotifier.java [taskScheduler-1])
* INFO  2015-07-30 15:42:22,579 [Level: INFO, category: DATAMART, time: Thu Jul 30 15:42:22 SAST 2015, message: Updating resource tables] (InMemoryNotifier.java [taskScheduler-1])
* INFO  2015-07-30 15:42:22,626 Using 5 organisation unit levels for org unit structure table (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:22,641 Create organisation unit structure table SQL: CREATE TABLE _orgunitstructure ( organisationunitid INTEGER NOT NULL PRIMARY KEY, organisationunituid CHARACTER(11), level INTEGER, "idlevel1" INTEGER, "uidlevel1" CHARACTER(11), "idlevel2" INTEGER, "uidlevel2" CHARACTER(11), "idlevel3" INTEGER, "uidlevel3" CHARACTER(11), "idlevel4" INTEGER, "uidlevel4" CHARACTER(11), "idlevel5" INTEGER, "uidlevel5" CHARACTER(11)); (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,723 Organisation unit structure table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,857 Create category option combo name table SQL: CREATE TABLE _categoryoptioncomboname ( categoryoptioncomboid INTEGER NOT NULL PRIMARY KEY, categoryoptioncomboname VARCHAR(250), approvallevel INTEGER ) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,917 Category option combo name table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,965 Create category option group set table SQL: CREATE TABLE _categoryoptiongroupsetstructure ( categoryoptioncomboid INTEGER NOT NULL, PRIMARY KEY ( categoryoptioncomboid ) ) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,968 Category option group set table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,977 Create data element group set table SQL: CREATE TABLE _dataelementgroupsetstructure ( dataelementid INTEGER NOT NULL, dataelementname VARCHAR (250), PRIMARY KEY ( dataelementid ) ) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,981 Populate data element group set structure SQL: insert into _dataelementgroupsetstructure select d.dataelementid as dataelementid, d.name as dataelementname from dataelement d (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,982 Data element group set table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,995 Create indicator group set table SQL: CREATE TABLE _indicatorgroupsetstructure ( indicatorid INTEGER NOT NULL, indicatorname VARCHAR (250), PRIMARY KEY ( indicatorid ) ) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,997 Populate indicator group set structure SQL: insert into _indicatorgroupsetstructure select i.indicatorid as indicatorid, i.name as indicatorname from indicator i (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:24,999 Indicator group set table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:25,015 Create organisation unit group set table SQL: CREATE TABLE _organisationunitgroupsetstructure ( organisationunitid INTEGER NOT NULL, organisationunitname VARCHAR (250), "OrgUnitOwnership" VARCHAR (250), "CkIy9PyAAsM" CHARACTER(11), "OrgUnitRuralUrban" VARCHAR (250), "nQoWiIYO3nt" CHARACTER(11), "OrgUnitType" VARCHAR (250), "BmSB4vqoDfI" CHARACTER(11), "QuintileClassification" VARCHAR (250), "IiDqF9APXUm" CHARACTER(11), PRIMARY KEY ( organisationunitid ) ) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:25,018 Populate organisation unit group set structure SQL: insert into _organisationunitgroupsetstructure select ou.organisationunitid as organisationunitid, ou.name as organisationunitname, (select oug.name from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23755 where ougm.organisationunitid = ou.organisationunitid limit 1) as "OrgUnitOwnership", (select oug.uid from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23755 where ougm.organisationunitid = ou.organisationunitid limit 1) as "CkIy9PyAAsM", (select oug.name from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23756 where ougm.organisationunitid = ou.organisationunitid limit 1) as "OrgUnitRuralUrban", (select oug.uid from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23756 where ougm.organisationunitid = ou.organisationunitid limit 1) as "nQoWiIYO3nt", (select oug.name from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23754 where ougm.organisationunitid = ou.organisationunitid limit 1) as "OrgUnitType", (select oug.uid from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23754 where ougm.organisationunitid = ou.organisationunitid limit 1) as "BmSB4vqoDfI", (select oug.name from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23757 where ougm.organisationunitid = ou.organisationunitid limit 1) as "QuintileClassification", (select oug.uid from orgunitgroup oug inner join orgunitgroupmembers ougm on ougm.orgunitgroupid = oug.orgunitgroupid inner join orgunitgroupsetmembers ougsm on ougsm.orgunitgroupid = ougm.orgunitgroupid and ougsm.orgunitgroupsetid = 23757 where ougm.organisationunitid = ou.organisationunitid limit 1) as "IiDqF9APXUm" from organisationunit ou (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,418 Organisation unit group set table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,434 Create category structure table SQL: CREATE TABLE _categorystructure ( categoryoptioncomboid INTEGER NOT NULL, categoryoptioncomboname VARCHAR (250), "Age" VARCHAR (250), "KNqu95ktPhC" CHARACTER(11), PRIMARY KEY ( categoryoptioncomboid ) ) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,439 Populate category structure SQL: insert into _categorystructure select coc.categoryoptioncomboid as cocid, con.categoryoptioncomboname as cocname, (select co.name from categoryoptioncombos_categoryoptions cocco inner join dataelementcategoryoption co on cocco.categoryoptionid = co.categoryoptionid inner join categories_categoryoptions cco on co.categoryoptionid = cco.categoryoptionid where coc.categoryoptioncomboid = cocco.categoryoptioncomboid and cco.categoryid = 71780 limit 1) as "Age", (select co.uid from categoryoptioncombos_categoryoptions cocco inner join dataelementcategoryoption co on cocco.categoryoptionid = co.categoryoptionid inner join categories_categoryoptions cco on co.categoryoptionid = cco.categoryoptionid where coc.categoryoptioncomboid = cocco.categoryoptioncomboid and cco.categoryid = 71780 limit 1) as "KNqu95ktPhC" from categoryoptioncombo coc inner join _categoryoptioncomboname con on coc.categoryoptioncomboid = con.categoryoptioncomboid (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,441 Category table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,490 Create data element structure SQL: CREATE TABLE _dataelementstructure ( dataelementid INTEGER NOT NULL PRIMARY KEY, dataelementuid CHARACTER(11), dataelementname VARCHAR(250), datasetid INTEGER, datasetuid CHARACTER(11), datasetname VARCHAR(250), datasetapprovallevel INTEGER, periodtypeid INTEGER, periodtypename VARCHAR(250) ) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,565 Data element table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,591 Create period structure SQL: CREATE TABLE _periodstructure (periodid INTEGER NOT NULL PRIMARY KEY, iso VARCHAR(15) NOT NULL, daysno INTEGER NOT NULL, "daily" VARCHAR(15), "weekly" VARCHAR(15), "monthly" VARCHAR(15), "bimonthly" VARCHAR(15), "quarterly" VARCHAR(15), "sixmonthly" VARCHAR(15), "sixmonthlyapril" VARCHAR(15), "yearly" VARCHAR(15), "financialapril" VARCHAR(15), "financialjuly" VARCHAR(15), "financialoct" VARCHAR(15)) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,792 Date period table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:26,807 Create date period structure SQL: CREATE TABLE _dateperiodstructure (dateperiod DATE NOT NULL PRIMARY KEY, "daily" VARCHAR(15), "weekly" VARCHAR(15), "monthly" VARCHAR(15), "bimonthly" VARCHAR(15), "quarterly" VARCHAR(15), "sixmonthly" VARCHAR(15), "sixmonthlyapril" VARCHAR(15), "yearly" VARCHAR(15), "financialapril" VARCHAR(15), "financialjuly" VARCHAR(15), "financialoct" VARCHAR(15)) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,095 Period table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,097 Create data element category option combo SQL: CREATE TABLE _dataelementcategoryoptioncombo (dataelementid INTEGER NOT NULL, dataelementuid VARCHAR(11) NOT NULL, categoryoptioncomboid INTEGER NOT NULL, categoryoptioncombouid VARCHAR(11) NOT NULL) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,099 Insert data element category option combo SQL: insert into _dataelementcategoryoptioncombo (dataelementid, dataelementuid, categoryoptioncomboid, categoryoptioncombouid) select de.dataelementid as dataelementid, de.uid as dataelementuid, coc.categoryoptioncomboid as categoryoptioncomboid, coc.uid as categoryoptioncombouid from dataelement de join categorycombos_optioncombos cc on de.categorycomboid = cc.categorycomboid join categoryoptioncombo coc on cc.categoryoptioncomboid = coc.categoryoptioncomboid (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,100 Create data element category option combo index SQL: CREATE INDEX dataelement_categoryoptioncombo ON _dataelementcategoryoptioncombo (dataelementuid, categoryoptioncombouid) (JdbcResourceTableStore.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,101 Data element category option combo table generated (DefaultResourceTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,174 [Level: INFO, category: DATAMART, time: Thu Jul 30 15:42:31 SAST 2015, message: Updating analytics tables] (InMemoryNotifier.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,199 Starting update, processes: 3, org unit levels: 5: 00:00:00.000 (Clock.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,247 Approval enabled: false (JdbcAnalyticsTableManager.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,248 Get tables using earliest: null (AbstractJdbcTableManager.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,352 Table update start: analytics, processes: 3, partitions: [analytics_2015], last years: null, earliest: null: 00:00:00.174 (Clock.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,352 [Level: INFO, category: DATAMART, time: Thu Jul 30 15:42:31 SAST 2015, message: Performing pre-create table work, processes: 3, org unit levels: 5] (InMemoryNotifier.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,354 Performed pre-create table work: 00:00:00.177 (Clock.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,354 [Level: INFO, category: DATAMART, time: Thu Jul 30 15:42:31 SAST 2015, message: Creating analytics tables] (InMemoryNotifier.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,360 Creating table: analytics_temp_2015, columns: 26 (JdbcAnalyticsTableManager.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,363 Created analytics tables: 00:00:00.186 (Clock.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,363 [Level: INFO, category: DATAMART, time: Thu Jul 30 15:42:31 SAST 2015, message: Populating analytics tables] (InMemoryNotifier.java [taskScheduler-1])
* INFO  2015-07-30 15:42:31,364 Populate table task number: 1 (DefaultAnalyticsTableService.java [taskScheduler-1])
* INFO  2015-07-30 15:42:33,522 Populated analytics_temp_2015, int: 1.95 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-1])
* INFO  2015-07-30 15:42:33,542 Populated analytics_temp_2015, bool: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-1])
* INFO  2015-07-30 15:42:33,564 Populated analytics_temp_2015, bool: 0.02 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-1])
* INFO  2015-07-30 15:42:33,579 Populated analytics_temp_2015, trueOnly: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-1])
* INFO  2015-07-30 15:42:33,592 Populated analytics_temp_2015, string: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-1])
* INFO  2015-07-30 15:42:33,593 Populated analytics tables: 00:00:02.415 (Clock.java [taskScheduler-1])
* INFO  2015-07-30 15:42:33,593 [Level: INFO, category: DATAMART, time: Thu Jul 30 15:42:33 SAST 2015, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-1])
* INFO  2015-07-30 15:42:33,614 [Level: ERROR, category: DATAMART, time: Thu Jul 30 15:42:33 SAST 2015, message: Process failed: Exception during execution] (InMemoryNotifier.java [taskScheduler-1])
* ERROR 2015-07-30 15:42:33,870 Unexpected error occurred in scheduled task. (TaskUtils.java [taskScheduler-1])
java.lang.RuntimeException: Exception during execution
	at org.hisp.dhis.commons.util.ConcurrentUtils.waitForCompletion(ConcurrentUtils.java:57)
	at org.hisp.dhis.analytics.table.DefaultAnalyticsTableService.applyAggregationLevels(DefaultAnalyticsTableService.java:244)
	at org.hisp.dhis.analytics.table.DefaultAnalyticsTableService.update(DefaultAnalyticsTableService.java:133)
	at org.hisp.dhis.analytics.table.scheduling.AnalyticsTableTask.run(AnalyticsTableTask.java:140)
	at org.hisp.dhis.scheduling.ScheduledTasks.run(ScheduledTasks.java:60)
	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)
Caused by: java.util.concurrent.ExecutionException: org.springframework.jdbc.BadSqlGrammarException: StatementCallback; bad SQL grammar [update analytics_temp_2015 set "uidlevel1" = null,"uidlevel2" = null,"uidlevel3" = null,"uidlevel4" = null,"uidlevel5" = null where level > 5 and de in ('jx6lCxe8gYy', 'cjA6JH0kC9B')]; nested exception is org.postgresql.util.PSQLException: ERROR: column "de" does not exist
  Position: 147
	at java.util.concurrent.FutureTask.report(FutureTask.java:122)
	at java.util.concurrent.FutureTask.get(FutureTask.java:192)
	at org.hisp.dhis.commons.util.ConcurrentUtils.waitForCompletion(ConcurrentUtils.java:53)
	... 12 more
Caused by: org.springframework.jdbc.BadSqlGrammarException: StatementCallback; bad SQL grammar [update analytics_temp_2015 set "uidlevel1" = null,"uidlevel2" = null,"uidlevel3" = null,"uidlevel4" = null,"uidlevel5" = null where level > 5 and de in ('jx6lCxe8gYy', 'cjA6JH0kC9B')]; nested exception is org.postgresql.util.PSQLException: ERROR: column "de" does not exist
  Position: 147
	at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:99)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:73)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
	at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:81)
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:416)
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:440)
	at org.hisp.dhis.analytics.table.JdbcAnalyticsTableManager.applyAggregationLevels(JdbcAnalyticsTableManager.java:420)
	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:497)
	at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190)
	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
	at org.springframework.aop.interceptor.AsyncExecutionInterceptor$1.call(AsyncExecutionInterceptor.java:110)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	... 1 more
Caused by: org.postgresql.util.PSQLException: ERROR: column "de" does not exist
  Position: 147
	at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2198)
	at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1927)
	at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255)
	at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:561)
	at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:405)
	at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:397)
	at com.mchange.v2.c3p0.impl.NewProxyStatement.execute(NewProxyStatement.java:1006)
	at org.springframework.jdbc.core.JdbcTemplate$1ExecuteStatementCallback.doInStatement(JdbcTemplate.java:432)
	at org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:405)
	... 12 more