* INFO  2015-09-09 14:11:05,584 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:11:05 EDT 2015, message: Analytics table update process started] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:11:05,584 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:11:05 EDT 2015, message: Updating resource tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:11:05,647 Using 6 organisation unit levels for org unit structure table (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:05,649 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), "idlevel6" INTEGER, "uidlevel6" CHARACTER(11)); (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:17,957 Organisation unit structure table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,311 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])
* WARN  2015-09-09 14:11:18,329 Ignoring category combo, not valid: [IdentifiableObject: id='14259', uid='X12sRWay517', code='null', name='CD4 count and adherence', created='2015-04-22 13:20:44.075', lastUpdated='2015-09-08 14:19:20.832', class='class org.hisp.dhis.dataelement.DataElementCategoryCombo"'] (DefaultResourceTableService.java [taskScheduler-2])
* WARN  2015-09-09 14:11:18,344 Ignoring category combo, not valid: [IdentifiableObject: id='14', uid='OzshuDqmXQI', code='null', name='default', created='2012-01-08 17:43:09.811', lastUpdated='2015-04-09 15:51:23.769', class='class org.hisp.dhis.dataelement.DataElementCategoryCombo"'] (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,411 Category option combo name table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,429 Create category option group set table SQL: CREATE TABLE _categoryoptiongroupsetstructure ( categoryoptioncomboid INTEGER NOT NULL, "point of service" VARCHAR (250), "Uy04K9W5DEQ" CHARACTER(11), PRIMARY KEY ( categoryoptioncomboid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,601 Category option group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,606 Create data element group set table SQL: CREATE TABLE _dataelementgroupsetstructure ( dataelementid INTEGER NOT NULL, dataelementname VARCHAR (250), "Comprehensive TB_HIV" VARCHAR (250), "b4iHaYVnVYe" CHARACTER(11), PRIMARY KEY ( dataelementid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,623 Populate data element group set structure SQL: insert into _dataelementgroupsetstructure select d.dataelementid as dataelementid, d.name as dataelementname, (select deg.name from dataelementgroup deg inner join dataelementgroupmembers degm on degm.dataelementgroupid = deg.dataelementgroupid inner join dataelementgroupsetmembers degsm on degsm.dataelementgroupid = degm.dataelementgroupid and degsm.dataelementgroupsetid = 16129 where degm.dataelementid = d.dataelementid limit 1) as "Comprehensive TB_HIV", (select deg.uid from dataelementgroup deg inner join dataelementgroupmembers degm on degm.dataelementgroupid = deg.dataelementgroupid inner join dataelementgroupsetmembers degsm on degsm.dataelementgroupid = degm.dataelementgroupid and degsm.dataelementgroupsetid = 16129 where degm.dataelementid = d.dataelementid limit 1) as "b4iHaYVnVYe" from dataelement d (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,677 Data element group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,683 Create indicator group set table SQL: CREATE TABLE _indicatorgroupsetstructure ( indicatorid INTEGER NOT NULL, indicatorname VARCHAR (250), "Comprehensive TB_HIV" VARCHAR (250), "YNQRu5lKvVt" CHARACTER(11), PRIMARY KEY ( indicatorid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,690 Populate indicator group set structure SQL: insert into _indicatorgroupsetstructure select i.indicatorid as indicatorid, i.name as indicatorname, (select ig.name from indicatorgroup ig inner join indicatorgroupmembers igm on igm.indicatorgroupid = ig.indicatorgroupid inner join indicatorgroupsetmembers igsm on igsm.indicatorgroupid = igm.indicatorgroupid and igsm.indicatorgroupsetid = 16161 where igm.indicatorid = i.indicatorid limit 1) as "Comprehensive TB_HIV", (select ig.uid from indicatorgroup ig inner join indicatorgroupmembers igm on igm.indicatorgroupid = ig.indicatorgroupid inner join indicatorgroupsetmembers igsm on igsm.indicatorgroupid = igm.indicatorgroupid and igsm.indicatorgroupsetid = 16161 where igm.indicatorid = i.indicatorid limit 1) as "YNQRu5lKvVt" from indicator i (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,709 Indicator group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,713 Create organisation unit group set table SQL: CREATE TABLE _organisationunitgroupsetstructure ( organisationunitid INTEGER NOT NULL, organisationunitname VARCHAR (250), PRIMARY KEY ( organisationunitid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,717 Populate organisation unit group set structure SQL: insert into _organisationunitgroupsetstructure select ou.organisationunitid as organisationunitid, ou.name as organisationunitname from organisationunit ou (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,786 Organisation unit group set table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,808 Create category structure table SQL: CREATE TABLE _categorystructure ( categoryoptioncomboid INTEGER NOT NULL, categoryoptioncomboname VARCHAR (250), "HTC Counselor Monthly Reporting Summary" VARCHAR (250), "JxncT5qyO06" CHARACTER(11), PRIMARY KEY ( categoryoptioncomboid ) ) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,815 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 = 15631 limit 1) as "HTC Counselor Monthly Reporting Summary", (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 = 15631 limit 1) as "JxncT5qyO06" from categoryoptioncombo coc inner join _categoryoptioncomboname con on coc.categoryoptioncomboid = con.categoryoptioncomboid (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,832 Category table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:18,880 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-09-09 14:11:19,052 Data element table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:19,076 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-09-09 14:11:19,154 Date period table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:19,162 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-09-09 14:11:29,740 Period table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:29,741 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-09-09 14:11:29,742 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-09-09 14:11:29,758 Create data element category option combo index SQL: CREATE INDEX dataelement_categoryoptioncombo ON _dataelementcategoryoptioncombo (dataelementuid, categoryoptioncombouid) (JdbcResourceTableStore.java [taskScheduler-2])
* INFO  2015-09-09 14:11:29,841 Data element category option combo table generated (DefaultResourceTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:29,862 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:11:29 EDT 2015, message: Updating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:11:29,863 Starting update, processes: 1, org unit levels: 6: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:11:29,865 Approval enabled: false (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:29,866 Get tables using earliest: null (AbstractJdbcTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,627 Table update start: analytics, processes: 1, partitions: [analytics_2010, analytics_2011, analytics_2012, analytics_2013, analytics_2014, analytics_2015, analytics_2016], last years: null, earliest: null: 00:00:00.764 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,628 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:11:30 EDT 2015, message: Performing pre-create table work, processes: 1, org unit levels: 6] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,637 Performed pre-create table work: 00:00:00.773 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,637 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:11:30 EDT 2015, message: Creating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,643 Creating table: analytics_temp_2010, columns: 24 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,665 Creating table: analytics_temp_2011, columns: 24 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,678 Creating table: analytics_temp_2012, columns: 24 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,696 Creating table: analytics_temp_2013, columns: 24 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,707 Creating table: analytics_temp_2014, columns: 24 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,728 Creating table: analytics_temp_2015, columns: 24 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,741 Creating table: analytics_temp_2016, columns: 24 (JdbcAnalyticsTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,749 Created analytics tables: 00:00:00.885 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,749 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:11:30 EDT 2015, message: Populating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:11:30,749 Populate table task number: 1 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:11:36,670 Populated analytics_temp_2010, int: 5.91 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:36,911 Populated analytics_temp_2010, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:37,153 Populated analytics_temp_2010, bool: 0.23 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:37,399 Populated analytics_temp_2010, trueOnly: 0.23 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:38,778 Populated analytics_temp_2010, string: 1.37 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:44,932 Populated analytics_temp_2011, int: 6.15 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:45,181 Populated analytics_temp_2011, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:45,431 Populated analytics_temp_2011, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:45,450 Populated analytics_temp_2011, trueOnly: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:46,812 Populated analytics_temp_2011, string: 1.36 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:54,404 Populated analytics_temp_2012, int: 7.58 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:54,741 Populated analytics_temp_2012, bool: 0.32 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:54,978 Populated analytics_temp_2012, bool: 0.22 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:55,023 Populated analytics_temp_2012, trueOnly: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:11:56,392 Populated analytics_temp_2012, string: 1.36 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:04,133 Populated analytics_temp_2013, int: 7.74 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:04,385 Populated analytics_temp_2013, bool: 0.23 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:04,625 Populated analytics_temp_2013, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:04,652 Populated analytics_temp_2013, trueOnly: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:06,559 Populated analytics_temp_2013, string: 1.90 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:15,572 Populated analytics_temp_2014, int: 9.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:15,821 Populated analytics_temp_2014, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:16,070 Populated analytics_temp_2014, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:16,098 Populated analytics_temp_2014, trueOnly: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:17,405 Populated analytics_temp_2014, string: 1.29 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:25,268 Populated analytics_temp_2015, int: 7.86 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:25,506 Populated analytics_temp_2015, bool: 0.23 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:25,758 Populated analytics_temp_2015, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:25,780 Populated analytics_temp_2015, trueOnly: 0.02 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:27,109 Populated analytics_temp_2015, string: 1.32 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:34,441 Populated analytics_temp_2016, int: 7.32 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:34,700 Populated analytics_temp_2016, bool: 0.25 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:34,945 Populated analytics_temp_2016, bool: 0.24 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:34,964 Populated analytics_temp_2016, trueOnly: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:36,291 Populated analytics_temp_2016, string: 1.32 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-31])
* INFO  2015-09-09 14:12:36,292 Populated analytics tables: 00:01:06.428 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:36,292 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:36 EDT 2015, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:36,294 Applied aggregation levels: 00:01:06.431 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:36,294 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:36 EDT 2015, message: Creating indexes] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:36,295 No of analytics table indexes: 168 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:12:37,754 Created indexes: 00:01:07.891 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:37,755 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:37 EDT 2015, message: Vacuuming tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:37,759 Vacuumed tables: 00:01:07.895 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:37,759 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:37 EDT 2015, message: Swapping analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,827 Partition tables: [analytics_2010, analytics_2011, analytics_2012, analytics_2013, analytics_2014, analytics_2015, analytics_2016], last years: null: 00:01:08.963 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,827 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Clearing caches] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,828 Table update done: analytics: 00:01:08.964 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,828 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Table update done] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,828 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Updating completeness table] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,839 Starting update, processes: 1, org unit levels: 6: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,839 Get tables using earliest: null (AbstractJdbcTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,844 Table update start: analytics_completeness, processes: 1, partitions: [analytics_completeness_2013, analytics_completeness_2014, analytics_completeness_2015, analytics_completeness_2016], last years: null, earliest: null: 00:00:00.005 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,844 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Performing pre-create table work, processes: 1, org unit levels: 6] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,844 Performed pre-create table work: 00:00:00.005 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,844 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Creating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,855 Creating table: analytics_completeness_temp_2013, columns: 18 (JdbcCompletenessTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,859 Creating table: analytics_completeness_temp_2014, columns: 18 (JdbcCompletenessTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,862 Creating table: analytics_completeness_temp_2015, columns: 18 (JdbcCompletenessTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,866 Creating table: analytics_completeness_temp_2016, columns: 18 (JdbcCompletenessTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,877 Created analytics tables: 00:00:00.038 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,877 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Populating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,877 Populate table task number: 1 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,882 Populated analytics_completeness_temp_2013: 0.00 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-34])
* INFO  2015-09-09 14:12:38,898 Populated analytics_completeness_temp_2014: 0.01 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-34])
* INFO  2015-09-09 14:12:38,945 Populated analytics_completeness_temp_2015: 0.05 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-34])
* INFO  2015-09-09 14:12:38,949 Populated analytics_completeness_temp_2016: 0.00 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-34])
* INFO  2015-09-09 14:12:38,949 Populated analytics tables: 00:00:00.110 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,949 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,952 Applied aggregation levels: 00:00:00.113 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,952 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:38 EDT 2015, message: Creating indexes] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:38,952 No of analytics table indexes: 72 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,406 Created indexes: 00:00:01.567 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,406 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Vacuuming tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,408 Vacuumed tables: 00:00:01.569 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,408 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Swapping analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,503 Partition tables: [analytics_completeness_2013, analytics_completeness_2014, analytics_completeness_2015, analytics_completeness_2016], last years: null: 00:00:01.664 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,503 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Clearing caches] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,503 Table update done: analytics_completeness: 00:00:01.664 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,503 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Table update done] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,503 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Updating completeness target table] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,505 Starting update, processes: 1, org unit levels: 6: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,505 Table update start: analytics_completenesstarget, processes: 1, partitions: [analytics_completenesstarget], last years: null, earliest: null: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,505 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Performing pre-create table work, processes: 1, org unit levels: 6] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,506 Performed pre-create table work: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,506 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Creating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,508 Creating table: analytics_completenesstarget_temp, columns: 7 (JdbcCompletenessTargetTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,510 Created analytics tables: 00:00:00.005 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,510 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Populating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,511 Populate table task number: 1 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,779 Populated analytics_completenesstarget_temp: 0.26 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-37])
* INFO  2015-09-09 14:12:40,780 Populated analytics tables: 00:00:00.275 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,780 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,782 Applied aggregation levels: 00:00:00.277 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,782 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:40 EDT 2015, message: Creating indexes] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:40,783 No of analytics table indexes: 7 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,924 Created indexes: 00:00:04.419 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,925 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Vacuuming tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,926 Vacuumed tables: 00:00:04.421 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,926 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Swapping analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,984 Partition tables: [analytics_completenesstarget], last years: null: 00:00:04.479 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,984 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Clearing caches] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,984 Table update done: analytics_completenesstarget: 00:00:04.479 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,984 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Table update done] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,985 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Updating organisation unit target table] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,986 Starting update, processes: 1, org unit levels: 6: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,987 Table update start: analytics_orgunittarget, processes: 1, partitions: [analytics_orgunittarget], last years: null, earliest: null: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,987 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Performing pre-create table work, processes: 1, org unit levels: 6] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,987 Performed pre-create table work: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,987 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Creating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,989 Creating table: analytics_orgunittarget_temp, columns: 7 (JdbcOrgUnitTargetTableManager.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,992 Created analytics tables: 00:00:00.005 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,992 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:44 EDT 2015, message: Populating analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:44,992 Populate table task number: 1 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:12:45,209 Populated analytics_orgunittarget_temp: 0.22 seconds (AbstractJdbcTableManager.java [SimpleAsyncTaskExecutor-40])
* INFO  2015-09-09 14:12:45,210 Populated analytics tables: 00:00:00.223 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:45,210 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:45 EDT 2015, message: Applying aggregation levels] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:45,212 Applied aggregation levels: 00:00:00.226 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:45,212 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:45 EDT 2015, message: Creating indexes] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:45,213 No of analytics table indexes: 7 (DefaultAnalyticsTableService.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,730 Created indexes: 00:00:02.743 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,730 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:47 EDT 2015, message: Vacuuming tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,732 Vacuumed tables: 00:00:02.745 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,732 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:47 EDT 2015, message: Swapping analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,783 Partition tables: [analytics_orgunittarget], last years: null: 00:00:02.797 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,783 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:47 EDT 2015, message: Clearing caches] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,784 Table update done: analytics_orgunittarget: 00:00:02.797 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,784 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:47 EDT 2015, message: Table update done] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,784 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:47 EDT 2015, message: Updating event analytics table] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,785 Starting update, processes: 1, org unit levels: 6: 00:00:00.000 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,786 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:47 EDT 2015, message: No events exist, not updating event analytics tables] (InMemoryNotifier.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,786 Analytics tables updated: 00:01:42.202 (Clock.java [taskScheduler-2])
* INFO  2015-09-09 14:12:47,786 [Level: INFO, category: DATAMART, time: Wed Sep 09 14:12:47 EDT 2015, message: Analytics tables updated: 00:01:42.202] (InMemoryNotifier.java [taskScheduler-2])