* INFO  2015-07-29 12:53:45,703 [Level: INFO, category: DATAMART, time: Wed Jul 29 12:53:45 SAST 2015, message: Analytics table update process started] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-07-29 12:53:45,754 [Level: INFO, category: DATAMART, time: Wed Jul 29 12:53:45 SAST 2015, message: Updating resource tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-07-29 12:53:45,773 Using 5 organisation unit levels for org unit structure table (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:45,784 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-2])
* INFO  2015-07-29 12:53:47,319 Organisation unit structure table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,468 Create category option combo name table SQL: CREATE TABLE _categoryoptioncomboname ( categoryoptioncomboid INTEGER NOT NULL PRIMARY KEY, categoryoptioncomboname VARCHAR(250), approvallevel INTEGER ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,483 Category option combo name table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,559 Create category option group set table SQL: CREATE TABLE _categoryoptiongroupsetstructure ( categoryoptioncomboid INTEGER NOT NULL, PRIMARY KEY ( categoryoptioncomboid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,561 Category option group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,567 Create data element group set table SQL: CREATE TABLE _dataelementgroupsetstructure ( dataelementid INTEGER NOT NULL, dataelementname VARCHAR (250), PRIMARY KEY ( dataelementid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,568 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-2])
* INFO  2015-07-29 12:53:47,569 Data element group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,574 Create indicator group set table SQL: CREATE TABLE _indicatorgroupsetstructure ( indicatorid INTEGER NOT NULL, indicatorname VARCHAR (250), PRIMARY KEY ( indicatorid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,576 Populate indicator group set structure SQL: insert into _indicatorgroupsetstructure select i.indicatorid as indicatorid, i.name as indicatorname from indicator i (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,576 Indicator group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:47,585 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-2])
* INFO  2015-07-29 12:53:47,588 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-2])
* INFO  2015-07-29 12:53:49,081 Organisation unit group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:49,097 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-2])
* INFO  2015-07-29 12:53:49,100 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-2])
* INFO  2015-07-29 12:53:49,101 Category table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:49,151 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-2])
* INFO  2015-07-29 12:53:49,218 Data element table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:49,318 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-2])
* INFO  2015-07-29 12:53:49,378 Date period table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:49,396 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-2])
* INFO  2015-07-29 12:53:53,109 Period table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,110 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-2])
* INFO  2015-07-29 12:53:53,111 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-2])
* INFO  2015-07-29 12:53:53,112 Create data element category option combo index SQL: CREATE INDEX dataelement_categoryoptioncombo ON _dataelementcategoryoptioncombo (dataelementuid, categoryoptioncombouid) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,114 Data element category option combo table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,183 [Level: INFO, category: DATAMART, time: Wed Jul 29 12:53:53 SAST 2015, message: Updating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,185 Starting update, processes: 3, org unit levels: 5: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,192 Approval enabled: false (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,192 Get tables using earliest: null (AbstractJdbcTableManager.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,288 Table update start: analytics, processes: 3, partitions: [analytics_2015], last years: null, earliest: null: 00:00:00.103 (Clock.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,288 [Level: INFO, category: DATAMART, time: Wed Jul 29 12:53:53 SAST 2015, message: Performing pre-create table work, processes: 3, org unit levels: 5] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,289 Performed pre-create table work: 00:00:00.104 (Clock.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,289 [Level: INFO, category: DATAMART, time: Wed Jul 29 12:53:53 SAST 2015, message: Creating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,293 Creating table: analytics_temp_2015, columns: 26 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,296 Created analytics tables: 00:00:00.111 (Clock.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,296 [Level: INFO, category: DATAMART, time: Wed Jul 29 12:53:53 SAST 2015, message: Populating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-07-29 12:53:53,296 Populate table task number: 1 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-07-29 12:53:55,304 Populated analytics_temp_2015, int: 2.00 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-67])
* INFO  2015-07-29 12:53:55,324 Populated analytics_temp_2015, bool: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-67])
* INFO  2015-07-29 12:53:55,346 Populated analytics_temp_2015, bool: 0.02 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-67])
* INFO  2015-07-29 12:53:55,358 Populated analytics_temp_2015, trueOnly: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-67])
* INFO  2015-07-29 12:53:55,373 Populated analytics_temp_2015, string: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-67])
* INFO  2015-07-29 12:53:55,374 Populated analytics tables: 00:00:02.189 (Clock.java [taskScheduler-2])
* INFO  2015-07-29 12:53:55,374 [Level: INFO, category: DATAMART, time: Wed Jul 29 12:53:55 SAST 2015, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-07-29 12:53:55,380 [Level: ERROR, category: DATAMART, time: Wed Jul 29 12:53:55 SAST 2015, message: Process failed: Exception during execution] (InMemoryNotifier.java [taskScheduler-2])
* ERROR 2015-07-29 12:53:55,391 Unexpected error occurred in scheduled task. (TaskUtils.java [taskScheduler-2])
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