Live API: New 'generationTimeMilliseconds' field used to process Average generation time in Visitor Profile (#11095)

* Live API: New 'generationTimeMilliseconds' field used to process Average generation time in Visitor Profile
fixes #11066

* more precision

* Expected test files

* Reporting API: showColumns and hideColumns should be applied recursively (#11100)

* Recursively delete columns specified with hideColumns

* Custom Dimensions tests

* Invalid argument supplied for foreach() + Contents tests

* New unit test for ColumnDelete filter

* Submodules

18 files changed, 372 insertions, 113 deletions

diff --git a/core/DataTable/Filter/ColumnDelete.php b/core/DataTable/Filter/ColumnDelete.php
index 60e53fd7dd..37f0b1bf97 100644
--- a/core/DataTable/Filter/ColumnDelete.php
+++ b/core/DataTable/Filter/ColumnDelete.php
@@ -101,25 +101,8 @@ class ColumnDelete extends BaseFilter
 
         // remove columns specified in $this->columnsToRemove
         if (!empty($this->columnsToRemove)) {
-            foreach ($table as $index => $row) {
-                foreach ($this->columnsToRemove as $column) {
-                    if (!array_key_exists($column, $row)) {
-                        continue;
-                    }
-                    
-                    if ($this->deleteIfZeroOnly) {
-                        $value = $row[$column];
-                        if ($value === false || !empty($value)) {
-                            continue;
-                        }
-                    }
-
-                    unset($table[$index][$column]);
-                }
-            }
-
+            $this->removeColumnsFromTable($table);
             $recurse = true;
-
         }
 
         // remove columns not specified in $columnsToKeep
@@ -128,6 +111,7 @@ class ColumnDelete extends BaseFilter
                 $columnsToDelete = array();
                 foreach ($row as $name => $value) {
                     $keep = false;
+
                     // @see self::APPEND_TO_COLUMN_NAME_TO_KEEP
                     foreach ($this->columnsToKeep as $nameKeep => $true) {
                         if (strpos($name, $nameKeep . self::APPEND_TO_COLUMN_NAME_TO_KEEP) === 0) {
@@ -161,4 +145,46 @@ class ColumnDelete extends BaseFilter
 
         return $table;
     }
+
+    /**
+     * @param $table
+     * @return array
+     */
+    protected function removeColumnsFromTable(&$table)
+    {
+        if(!$this->isArrayAccess($table)) {
+            return;
+        }
+        foreach ($table as $index => &$row) {
+            if(!$this->isArrayAccess($row)) {
+                continue;
+            }
+            foreach ($this->columnsToRemove as $column) {
+
+                if (!array_key_exists($column, $row)) {
+                    continue;
+                }
+
+                if ($this->deleteIfZeroOnly) {
+                    $value = $row[$column];
+                    if ($value === false || !empty($value)) {
+                        continue;
+                    }
+                }
+
+                unset($table[$index][$column]);
+            }
+
+            $this->removeColumnsFromTable($row);
+        }
+    }
+
+    /**
+     * @param $table
+     * @return bool
+     */
+    protected function isArrayAccess(&$table)
+    {
+        return is_array($table) || $table instanceof \ArrayAccess;
+    }
 }
diff --git a/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_day.xml b/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_day.xml
index 292d9feadf..d912bf9433 100644
--- a/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_day.xml
+++ b/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_day.xml
@@ -13,6 +13,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
@@ -118,6 +119,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>13</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
diff --git a/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_month.xml b/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_month.xml
index 292d9feadf..d912bf9433 100644
--- a/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_month.xml
+++ b/plugins/Contents/tests/System/expected/test_Contents__Live.getLastVisitsDetails_month.xml
@@ -13,6 +13,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
@@ -118,6 +119,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>13</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
diff --git a/plugins/Contents/tests/System/expected/test_Contents_contentInteractionMatch__Live.getLastVisitsDetails_day.xml b/plugins/Contents/tests/System/expected/test_Contents_contentInteractionMatch__Live.getLastVisitsDetails_day.xml
index 292d9feadf..d912bf9433 100644
--- a/plugins/Contents/tests/System/expected/test_Contents_contentInteractionMatch__Live.getLastVisitsDetails_day.xml
+++ b/plugins/Contents/tests/System/expected/test_Contents_contentInteractionMatch__Live.getLastVisitsDetails_day.xml
@@ -13,6 +13,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
@@ -118,6 +119,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>13</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
diff --git a/plugins/Contents/tests/System/expected/test_Contents_contentTargetMatch__Live.getLastVisitsDetails_day.xml b/plugins/Contents/tests/System/expected/test_Contents_contentTargetMatch__Live.getLastVisitsDetails_day.xml
index 292d9feadf..d912bf9433 100644
--- a/plugins/Contents/tests/System/expected/test_Contents_contentTargetMatch__Live.getLastVisitsDetails_day.xml
+++ b/plugins/Contents/tests/System/expected/test_Contents_contentTargetMatch__Live.getLastVisitsDetails_day.xml
@@ -13,6 +13,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
@@ -118,6 +119,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>13</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
diff --git a/plugins/Contents/tests/System/expected/test_ContentscontentNameOrPieceMatch__Live.getLastVisitsDetails_day.xml b/plugins/Contents/tests/System/expected/test_ContentscontentNameOrPieceMatch__Live.getLastVisitsDetails_day.xml
index 292d9feadf..d912bf9433 100644
--- a/plugins/Contents/tests/System/expected/test_ContentscontentNameOrPieceMatch__Live.getLastVisitsDetails_day.xml
+++ b/plugins/Contents/tests/System/expected/test_ContentscontentNameOrPieceMatch__Live.getLastVisitsDetails_day.xml
@@ -13,6 +13,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
@@ -118,6 +119,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>13</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>271</timeSpent>
diff --git a/plugins/CustomDimensions b/plugins/CustomDimensions
-Subproject df12314762e14babe08143edc8225a207cfb0b8
+Subproject 8372a86d1681ebd98ae682d0ab0884146d1c7e9
diff --git a/plugins/Live/Visitor.php b/plugins/Live/Visitor.php
index 112a3221d7..f50e495537 100644
--- a/plugins/Live/Visitor.php
+++ b/plugins/Live/Visitor.php
@@ -306,6 +306,7 @@ class Visitor implements VisitorInterface
                     $actionDetail['eventValue'] = round($actionDetail['custom_float'], self::EVENT_VALUE_PRECISION);
                 }
             } elseif ($actionDetail['custom_float'] > 0) {
+                $actionDetail['generationTimeMilliseconds'] = $actionDetail['custom_float'];
                 $actionDetail['generationTime'] = $formatter->getPrettyTimeFromSeconds($actionDetail['custom_float'] / 1000, true);
             }
             unset($actionDetail['custom_float']);
diff --git a/plugins/Live/VisitorProfile.php b/plugins/Live/VisitorProfile.php
index b92ead75e6..181c8bb302 100644
--- a/plugins/Live/VisitorProfile.php
+++ b/plugins/Live/VisitorProfile.php
@@ -355,14 +355,14 @@ class VisitorProfile
     {
         if ($this->profile['totalPageViewsWithTiming']) {
             $this->profile['averagePageGenerationTime'] =
-                round($this->pageGenerationTimeTotal / $this->profile['totalPageViewsWithTiming'], $precision = 2);
+                round($this->pageGenerationTimeTotal / (1000 * $this->profile['totalPageViewsWithTiming']), $precision = 3);
         }
     }
 
     private function handleIfPageGenerationTime($action)
     {
-        if (isset($action['generationTime'])) {
-            $this->pageGenerationTimeTotal += $action['generationTime'];
+        if (isset($action['generationTimeMilliseconds'])) {
+            $this->pageGenerationTimeTotal += $action['generationTimeMilliseconds'];
             ++$this->profile['totalPageViewsWithTiming'];
         }
     }
diff --git a/plugins/SecurityInfo b/plugins/SecurityInfo
-Subproject 0863b58a1c357a1ba1089a45ca80cd62843e407
+Subproject aef66a071ca376813d56585974120e95a1478e3
diff --git a/tests/PHPUnit/System/expected/test_ArchiveCronTest_archive_php_cron_output.txt b/tests/PHPUnit/System/expected/test_ArchiveCronTest_archive_php_cron_output.txt
index 2a4d981fa5..da3d334c0f 100644
--- a/tests/PHPUnit/System/expected/test_ArchiveCronTest_archive_php_cron_output.txt
+++ b/tests/PHPUnit/System/expected/test_ArchiveCronTest_archive_php_cron_output.txt
@@ -10,95 +10,95 @@ try 'php archive.php --url=http://your.piwik/path'
 -------------------------------------------------------
 
 
-INFO [2016-11-15 09:45:30] ---------------------------
-INFO [2016-11-15 09:45:30] INIT
-INFO [2016-11-15 09:45:30] Running Piwik 3.0.0-b2 as Super User
-INFO [2016-11-15 09:45:30] ---------------------------
-INFO [2016-11-15 09:45:30] NOTES
-INFO [2016-11-15 09:45:30] - If you execute this script at least once per hour (or more often) in a crontab, you may disable 'Browser trigger archiving' in Piwik UI > Settings > General Settings.
-INFO [2016-11-15 09:45:30]   See the doc at: http://piwik.org/docs/setup-auto-archiving/
-INFO [2016-11-15 09:45:30] - Reports for today will be processed at most every 150 seconds. You can change this value in Piwik UI > Settings > General Settings.
-INFO [2016-11-15 09:45:30] - Reports for the current week/month/year will be refreshed at most every 3600 seconds.
-INFO [2016-11-15 09:45:30] - Will invalidate archived reports for 2012-08-09 for following websites ids: 1
-INFO [2016-11-15 09:45:30] - Will invalidate archived reports for 2012-08-10 for following websites ids: 1
-INFO [2016-11-15 09:45:30] - Will invalidate archived reports for 2012-08-11 for following websites ids: 1
-INFO [2016-11-15 09:45:30] - Will invalidate archived reports for 2012-08-15 for following websites ids: 1,2,3
-INFO [2016-11-15 09:45:30] - Will invalidate archived reports for 2012-09-30 for following websites ids: 1
-INFO [2016-11-15 09:45:30] - Will invalidate archived reports for 2014-03-12 for following websites ids: 1,3
-INFO [2016-11-15 09:45:30] - Will invalidate archived reports for 2014-03-13 for following websites ids: 1,3
-INFO [2016-11-15 09:45:30] - Will process 3 other websites because some old data reports have been invalidated (eg. using the Log Import script) , IDs: 1, 2, 3
-INFO [2016-11-15 09:45:30] ---------------------------
-INFO [2016-11-15 09:45:30] START
-INFO [2016-11-15 09:45:30] Starting Piwik reports archiving...
-INFO [2016-11-15 09:45:30] Old report was invalidated for website id 1
-INFO [2016-11-15 09:45:30] Will pre-process for website id = 1, period = day, date = last52
-INFO [2016-11-15 09:45:30] - pre-processing all visits
-INFO [2016-11-15 09:45:31] - pre-processing segment 1/3 browserCode==IE
-INFO [2016-11-15 09:45:31] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:45:32] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:45:35] Archived website id = 1, period = day, 3 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 5.122s
-INFO [2016-11-15 09:45:35] Will pre-process for website id = 1, period = week, date = last260
-INFO [2016-11-15 09:45:35] - pre-processing all visits
-INFO [2016-11-15 09:45:35] - pre-processing segment 1/3 browserCode==IE
-INFO [2016-11-15 09:45:35] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:46:26] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:46:55] Archived website id = 1, period = week, 3 segments, 41 visits in last 260 weeks, 0 visits this week, Time elapsed: 80.017s
-INFO [2016-11-15 09:46:55] Will pre-process for website id = 1, period = month, date = last52
-INFO [2016-11-15 09:46:55] - pre-processing all visits
-INFO [2016-11-15 09:46:55] - pre-processing segment 1/3 browserCode==IE
-INFO [2016-11-15 09:46:55] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:47:06] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:47:12] Archived website id = 1, period = month, 3 segments, 41 visits in last 52 months, 0 visits this month, Time elapsed: 16.800s
-INFO [2016-11-15 09:47:12] Will pre-process for website id = 1, period = year, date = last7
-INFO [2016-11-15 09:47:12] - pre-processing all visits
-INFO [2016-11-15 09:47:12] - pre-processing segment 1/3 browserCode==IE
-INFO [2016-11-15 09:47:12] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:47:16] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
-INFO [2016-11-15 09:47:18] Archived website id = 1, period = year, 3 segments, 41 visits in last 7 years, 0 visits this year, Time elapsed: 6.342s
-INFO [2016-11-15 09:47:18] Archived website id = 1, 16 API requests, Time elapsed: 108.287s [1/3 done]
-INFO [2016-11-15 09:47:18] Old report was invalidated for website id 2
-INFO [2016-11-15 09:47:18] Will pre-process for website id = 2, period = day, date = last52
-INFO [2016-11-15 09:47:18] - pre-processing all visits
-INFO [2016-11-15 09:47:20] Archived website id = 2, period = day, 0 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 1.610s
-INFO [2016-11-15 09:47:20] Will pre-process for website id = 2, period = week, date = last260
-INFO [2016-11-15 09:47:20] - pre-processing all visits
-INFO [2016-11-15 09:47:40] Archived website id = 2, period = week, 0 segments, 1 visits in last 260 weeks, 0 visits this week, Time elapsed: 20.198s
-INFO [2016-11-15 09:47:40] Will pre-process for website id = 2, period = month, date = last52
-INFO [2016-11-15 09:47:40] - pre-processing all visits
-INFO [2016-11-15 09:47:44] Archived website id = 2, period = month, 0 segments, 1 visits in last 52 months, 0 visits this month, Time elapsed: 4.258s
-INFO [2016-11-15 09:47:44] Will pre-process for website id = 2, period = year, date = last7
-INFO [2016-11-15 09:47:44] - pre-processing all visits
-INFO [2016-11-15 09:47:45] Archived website id = 2, period = year, 0 segments, 1 visits in last 7 years, 0 visits this year, Time elapsed: 1.143s
-INFO [2016-11-15 09:47:45] Archived website id = 2, 4 API requests, Time elapsed: 27.212s [2/3 done]
-INFO [2016-11-15 09:47:45] Old report was invalidated for website id 3
-INFO [2016-11-15 09:47:45] Will pre-process for website id = 3, period = day, date = last52
-INFO [2016-11-15 09:47:45] - pre-processing all visits
-INFO [2016-11-15 09:47:47] Archived website id = 3, period = day, 0 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 1.496s
-INFO [2016-11-15 09:47:47] Will pre-process for website id = 3, period = week, date = last260
-INFO [2016-11-15 09:47:47] - pre-processing all visits
-INFO [2016-11-15 09:48:08] Archived website id = 3, period = week, 0 segments, 15 visits in last 260 weeks, 0 visits this week, Time elapsed: 21.096s
-INFO [2016-11-15 09:48:08] Will pre-process for website id = 3, period = month, date = last52
-INFO [2016-11-15 09:48:08] - pre-processing all visits
-INFO [2016-11-15 09:48:12] Archived website id = 3, period = month, 0 segments, 15 visits in last 52 months, 0 visits this month, Time elapsed: 4.401s
-INFO [2016-11-15 09:48:12] Will pre-process for website id = 3, period = year, date = last7
-INFO [2016-11-15 09:48:12] - pre-processing all visits
-INFO [2016-11-15 09:48:14] Archived website id = 3, period = year, 0 segments, 15 visits in last 7 years, 0 visits this year, Time elapsed: 1.760s
-INFO [2016-11-15 09:48:14] Archived website id = 3, 4 API requests, Time elapsed: 28.759s [3/3 done]
-INFO [2016-11-15 09:48:14] Done archiving!
-INFO [2016-11-15 09:48:14] ---------------------------
-INFO [2016-11-15 09:48:14] SUMMARY
-INFO [2016-11-15 09:48:14] Total visits for today across archived websites: 0
-INFO [2016-11-15 09:48:14] Archived today's reports for 3 websites
-INFO [2016-11-15 09:48:14] Archived week/month/year for 3 websites
-INFO [2016-11-15 09:48:14] Skipped 0 websites
-INFO [2016-11-15 09:48:14] - 0 skipped because no new visit since the last script execution
-INFO [2016-11-15 09:48:14] - 0 skipped because existing daily reports are less than 150 seconds old
-INFO [2016-11-15 09:48:14] - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
-INFO [2016-11-15 09:48:14] Total API requests: 24
-INFO [2016-11-15 09:48:14] done: 3/3 100%, 0 vtoday, 3 wtoday, 3 wperiods, 24 req, 164395 ms, no error
-INFO [2016-11-15 09:48:14] Time elapsed: 164.395s
-INFO [2016-11-15 09:48:14] ---------------------------
-INFO [2016-11-15 09:48:14] SCHEDULED TASKS
-INFO [2016-11-15 09:48:14] Starting Scheduled tasks...
-INFO [2016-11-15 09:48:14] done
-INFO [2016-11-15 09:48:14] ---------------------------
\ No newline at end of file
+INFO [2016-12-26 22:26:34] ---------------------------
+INFO [2016-12-26 22:26:34] INIT
+INFO [2016-12-26 22:26:34] Running Piwik 3.0.0 as Super User
+INFO [2016-12-26 22:26:34] ---------------------------
+INFO [2016-12-26 22:26:34] NOTES
+INFO [2016-12-26 22:26:34] - If you execute this script at least once per hour (or more often) in a crontab, you may disable 'Browser trigger archiving' in Piwik UI > Settings > General Settings.
+INFO [2016-12-26 22:26:34]   See the doc at: http://piwik.org/docs/setup-auto-archiving/
+INFO [2016-12-26 22:26:34] - Reports for today will be processed at most every 150 seconds. You can change this value in Piwik UI > Settings > General Settings.
+INFO [2016-12-26 22:26:34] - Reports for the current week/month/year will be refreshed at most every 3600 seconds.
+INFO [2016-12-26 22:26:34] - Will invalidate archived reports for 2012-08-09 for following websites ids: 1
+INFO [2016-12-26 22:26:34] - Will invalidate archived reports for 2012-08-10 for following websites ids: 1
+INFO [2016-12-26 22:26:34] - Will invalidate archived reports for 2012-08-11 for following websites ids: 1
+INFO [2016-12-26 22:26:34] - Will invalidate archived reports for 2012-08-15 for following websites ids: 1,2,3
+INFO [2016-12-26 22:26:34] - Will invalidate archived reports for 2012-09-30 for following websites ids: 1
+INFO [2016-12-26 22:26:34] - Will invalidate archived reports for 2014-03-12 for following websites ids: 1,3
+INFO [2016-12-26 22:26:34] - Will invalidate archived reports for 2014-03-13 for following websites ids: 1,3
+INFO [2016-12-26 22:26:34] - Will process 3 other websites because some old data reports have been invalidated (eg. using the Log Import script) , IDs: 1, 2, 3
+INFO [2016-12-26 22:26:34] ---------------------------
+INFO [2016-12-26 22:26:34] START
+INFO [2016-12-26 22:26:34] Starting Piwik reports archiving...
+INFO [2016-12-26 22:26:34] Old report was invalidated for website id 1
+INFO [2016-12-26 22:26:34] Will pre-process for website id = 1, period = day, date = last52
+INFO [2016-12-26 22:26:34] - pre-processing all visits
+INFO [2016-12-26 22:26:35] - pre-processing segment 1/3 browserCode==IE
+INFO [2016-12-26 22:26:35] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:26:36] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:26:39] Archived website id = 1, period = day, 3 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 5.167s
+INFO [2016-12-26 22:26:39] Will pre-process for website id = 1, period = week, date = last260
+INFO [2016-12-26 22:26:39] - pre-processing all visits
+INFO [2016-12-26 22:26:39] - pre-processing segment 1/3 browserCode==IE
+INFO [2016-12-26 22:26:39] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:27:34] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:28:04] Archived website id = 1, period = week, 3 segments, 41 visits in last 260 weeks, 0 visits this week, Time elapsed: 84.873s
+INFO [2016-12-26 22:28:04] Will pre-process for website id = 1, period = month, date = last52
+INFO [2016-12-26 22:28:04] - pre-processing all visits
+INFO [2016-12-26 22:28:04] - pre-processing segment 1/3 browserCode==IE
+INFO [2016-12-26 22:28:04] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:28:15] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:28:20] Archived website id = 1, period = month, 3 segments, 13 visits in last 52 months, 0 visits this month, Time elapsed: 16.383s
+INFO [2016-12-26 22:28:20] Will pre-process for website id = 1, period = year, date = last7
+INFO [2016-12-26 22:28:20] - pre-processing all visits
+INFO [2016-12-26 22:28:20] - pre-processing segment 1/3 browserCode==IE
+INFO [2016-12-26 22:28:20] - pre-processing segment 2/3 visitCount<=5;visitorType!=non-existing-type;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:28:26] - pre-processing segment 3/3 visitCount<=5;visitorType!=re%2C%3Btest%20is%20encoded;daysSinceFirstVisit<=50
+INFO [2016-12-26 22:28:28] Archived website id = 1, period = year, 3 segments, 41 visits in last 7 years, 0 visits this year, Time elapsed: 8.056s
+INFO [2016-12-26 22:28:28] Archived website id = 1, 16 API requests, Time elapsed: 114.487s [1/3 done]
+INFO [2016-12-26 22:28:28] Old report was invalidated for website id 2
+INFO [2016-12-26 22:28:28] Will pre-process for website id = 2, period = day, date = last52
+INFO [2016-12-26 22:28:28] - pre-processing all visits
+INFO [2016-12-26 22:28:30] Archived website id = 2, period = day, 0 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 1.499s
+INFO [2016-12-26 22:28:30] Will pre-process for website id = 2, period = week, date = last260
+INFO [2016-12-26 22:28:30] - pre-processing all visits
+INFO [2016-12-26 22:28:50] Archived website id = 2, period = week, 0 segments, 1 visits in last 260 weeks, 0 visits this week, Time elapsed: 20.592s
+INFO [2016-12-26 22:28:50] Will pre-process for website id = 2, period = month, date = last52
+INFO [2016-12-26 22:28:50] - pre-processing all visits
+INFO [2016-12-26 22:28:54] Archived website id = 2, period = month, 0 segments, 0 visits in last 52 months, 0 visits this month, Time elapsed: 3.807s
+INFO [2016-12-26 22:28:54] Will pre-process for website id = 2, period = year, date = last7
+INFO [2016-12-26 22:28:54] - pre-processing all visits
+INFO [2016-12-26 22:28:56] Archived website id = 2, period = year, 0 segments, 1 visits in last 7 years, 0 visits this year, Time elapsed: 1.512s
+INFO [2016-12-26 22:28:56] Archived website id = 2, 4 API requests, Time elapsed: 27.413s [2/3 done]
+INFO [2016-12-26 22:28:56] Old report was invalidated for website id 3
+INFO [2016-12-26 22:28:56] Will pre-process for website id = 3, period = day, date = last52
+INFO [2016-12-26 22:28:56] - pre-processing all visits
+INFO [2016-12-26 22:28:57] Archived website id = 3, period = day, 0 segments, 0 visits in last 52 days, 0 visits today, Time elapsed: 1.609s
+INFO [2016-12-26 22:28:57] Will pre-process for website id = 3, period = week, date = last260
+INFO [2016-12-26 22:28:57] - pre-processing all visits
+INFO [2016-12-26 22:29:19] Archived website id = 3, period = week, 0 segments, 15 visits in last 260 weeks, 0 visits this week, Time elapsed: 21.300s
+INFO [2016-12-26 22:29:19] Will pre-process for website id = 3, period = month, date = last52
+INFO [2016-12-26 22:29:19] - pre-processing all visits
+INFO [2016-12-26 22:29:23] Archived website id = 3, period = month, 0 segments, 12 visits in last 52 months, 0 visits this month, Time elapsed: 4.174s
+INFO [2016-12-26 22:29:23] Will pre-process for website id = 3, period = year, date = last7
+INFO [2016-12-26 22:29:23] - pre-processing all visits
+INFO [2016-12-26 22:29:25] Archived website id = 3, period = year, 0 segments, 15 visits in last 7 years, 0 visits this year, Time elapsed: 2.320s
+INFO [2016-12-26 22:29:25] Archived website id = 3, 4 API requests, Time elapsed: 29.407s [3/3 done]
+INFO [2016-12-26 22:29:25] Done archiving!
+INFO [2016-12-26 22:29:25] ---------------------------
+INFO [2016-12-26 22:29:25] SUMMARY
+INFO [2016-12-26 22:29:25] Total visits for today across archived websites: 0
+INFO [2016-12-26 22:29:25] Archived today's reports for 3 websites
+INFO [2016-12-26 22:29:25] Archived week/month/year for 3 websites
+INFO [2016-12-26 22:29:25] Skipped 0 websites
+INFO [2016-12-26 22:29:25] - 0 skipped because no new visit since the last script execution
+INFO [2016-12-26 22:29:25] - 0 skipped because existing daily reports are less than 150 seconds old
+INFO [2016-12-26 22:29:25] - 0 skipped because existing week/month/year periods reports are less than 3600 seconds old
+INFO [2016-12-26 22:29:25] Total API requests: 24
+INFO [2016-12-26 22:29:25] done: 3/3 100%, 0 vtoday, 3 wtoday, 3 wperiods, 24 req, 171446 ms, no error
+INFO [2016-12-26 22:29:25] Time elapsed: 171.446s
+INFO [2016-12-26 22:29:25] ---------------------------
+INFO [2016-12-26 22:29:25] SCHEDULED TASKS
+INFO [2016-12-26 22:29:25] Starting Scheduled tasks...
+INFO [2016-12-26 22:29:25] done
+INFO [2016-12-26 22:29:25] ---------------------------
\ No newline at end of file
diff --git a/tests/PHPUnit/System/expected/test_ArchiveCronTest_preArchivedSegment_noOptions__Live.getLastVisitsDetails_year.xml b/tests/PHPUnit/System/expected/test_ArchiveCronTest_preArchivedSegment_noOptions__Live.getLastVisitsDetails_year.xml
index dea1215c4e..4a3badd91f 100644
--- a/tests/PHPUnit/System/expected/test_ArchiveCronTest_preArchivedSegment_noOptions__Live.getLastVisitsDetails_year.xml
+++ b/tests/PHPUnit/System/expected/test_ArchiveCronTest_preArchivedSegment_noOptions__Live.getLastVisitsDetails_year.xml
@@ -19,6 +19,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>123</generationTimeMilliseconds>
 				<generationTime>0.12s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>0</timeSpent>
@@ -50,6 +51,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>120</generationTimeMilliseconds>
 				<generationTime>0.12s</generationTime>
 				<interactionPosition>5</interactionPosition>
 				<timeSpent>0</timeSpent>
@@ -70,6 +72,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>23</generationTimeMilliseconds>
 				<generationTime>0.02s</generationTime>
 				<interactionPosition>9</interactionPosition>
 				<timeSpent>52</timeSpent>
@@ -90,6 +93,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>234</generationTimeMilliseconds>
 				<generationTime>0.23s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>50</timeSpent>
@@ -110,6 +114,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>294</generationTimeMilliseconds>
 				<generationTime>0.29s</generationTime>
 				<interactionPosition>6</interactionPosition>
 				<timeSpent>49</timeSpent>
@@ -130,6 +135,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>237</generationTimeMilliseconds>
 				<generationTime>0.24s</generationTime>
 				<interactionPosition>10</interactionPosition>
 				<timeSpent>26</timeSpent>
@@ -150,6 +156,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>1324</generationTimeMilliseconds>
 				<generationTime>1.32s</generationTime>
 				<interactionPosition>3</interactionPosition>
 				<timeSpent>26</timeSpent>
@@ -170,6 +177,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>624</generationTimeMilliseconds>
 				<generationTime>0.62s</generationTime>
 				<interactionPosition>7</interactionPosition>
 				<timeSpent>7</timeSpent>
@@ -190,6 +198,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>543</generationTimeMilliseconds>
 				<generationTime>0.54s</generationTime>
 				<interactionPosition>4</interactionPosition>
 				<timeSpent>8</timeSpent>
@@ -210,6 +219,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>343</generationTimeMilliseconds>
 				<generationTime>0.34s</generationTime>
 				<interactionPosition>8</interactionPosition>
 				<icon />
diff --git a/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_day.xml b/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_day.xml
index 10d41c5fe3..cbcb34d9ba 100644
--- a/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_day.xml
+++ b/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_day.xml
@@ -530,6 +530,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>60</timeSpent>
@@ -718,6 +719,7 @@
 				<pageIdAction>15</pageIdAction>
 				
 				<pageId>10</pageId>
+				<generationTimeMilliseconds>666</generationTimeMilliseconds>
 				<generationTime>0.67s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>60</timeSpent>
@@ -1554,6 +1556,7 @@
 				<pageIdAction>15</pageIdAction>
 				
 				<pageId>33</pageId>
+				<generationTimeMilliseconds>666</generationTimeMilliseconds>
 				<generationTime>0.67s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>60</timeSpent>
diff --git a/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_month.xml b/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_month.xml
index 596636339a..6f28c2fa44 100644
--- a/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_month.xml
+++ b/tests/PHPUnit/System/expected/test_CustomEvents__Live.getLastVisitsDetails_month.xml
@@ -652,6 +652,7 @@
 				<pageIdAction>15</pageIdAction>
 				
 				<pageId>56</pageId>
+				<generationTimeMilliseconds>666</generationTimeMilliseconds>
 				<generationTime>0.67s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>60</timeSpent>
@@ -1362,6 +1363,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>333</generationTimeMilliseconds>
 				<generationTime>0.33s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>60</timeSpent>
@@ -1550,6 +1552,7 @@
 				<pageIdAction>15</pageIdAction>
 				
 				<pageId>10</pageId>
+				<generationTimeMilliseconds>666</generationTimeMilliseconds>
 				<generationTime>0.67s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>60</timeSpent>
diff --git a/tests/PHPUnit/System/expected/test_ImportLogs__Live.getLastVisitsDetails_range.xml b/tests/PHPUnit/System/expected/test_ImportLogs__Live.getLastVisitsDetails_range.xml
index 0fc8515f43..4dccd588ec 100644
--- a/tests/PHPUnit/System/expected/test_ImportLogs__Live.getLastVisitsDetails_range.xml
+++ b/tests/PHPUnit/System/expected/test_ImportLogs__Live.getLastVisitsDetails_range.xml
@@ -30,6 +30,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>292</generationTimeMilliseconds>
 				<generationTime>0.29s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -291,6 +292,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>413</generationTimeMilliseconds>
 				<generationTime>0.41s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -701,6 +703,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>391</generationTimeMilliseconds>
 				<generationTime>0.39s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -968,6 +971,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>119</generationTimeMilliseconds>
 				<generationTime>0.12s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -1088,6 +1092,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>145</generationTimeMilliseconds>
 				<generationTime>0.15s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -1217,6 +1222,7 @@
 						<customVariablePageValue1>403</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>182</generationTimeMilliseconds>
 				<generationTime>0.18s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>2</timeSpent>
@@ -1248,6 +1254,7 @@
 						<customVariablePageValue1>500</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>113</generationTimeMilliseconds>
 				<generationTime>0.11s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>7</timeSpent>
@@ -1391,6 +1398,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>134</generationTimeMilliseconds>
 				<generationTime>0.13s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -1523,6 +1531,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>58</generationTimeMilliseconds>
 				<generationTime>0.06s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -1644,6 +1653,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>123</generationTimeMilliseconds>
 				<generationTime>0.12s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>0</timeSpent>
@@ -1675,6 +1685,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>120</generationTimeMilliseconds>
 				<generationTime>0.12s</generationTime>
 				<interactionPosition>5</interactionPosition>
 				<timeSpent>0</timeSpent>
@@ -1695,6 +1706,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>23</generationTimeMilliseconds>
 				<generationTime>0.02s</generationTime>
 				<interactionPosition>9</interactionPosition>
 				<timeSpent>52</timeSpent>
@@ -1715,6 +1727,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>234</generationTimeMilliseconds>
 				<generationTime>0.23s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>50</timeSpent>
@@ -1735,6 +1748,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>294</generationTimeMilliseconds>
 				<generationTime>0.29s</generationTime>
 				<interactionPosition>6</interactionPosition>
 				<timeSpent>49</timeSpent>
@@ -1755,6 +1769,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>237</generationTimeMilliseconds>
 				<generationTime>0.24s</generationTime>
 				<interactionPosition>10</interactionPosition>
 				<timeSpent>26</timeSpent>
@@ -1775,6 +1790,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>1324</generationTimeMilliseconds>
 				<generationTime>1.32s</generationTime>
 				<interactionPosition>3</interactionPosition>
 				<timeSpent>26</timeSpent>
@@ -1795,6 +1811,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>624</generationTimeMilliseconds>
 				<generationTime>0.62s</generationTime>
 				<interactionPosition>7</interactionPosition>
 				<timeSpent>7</timeSpent>
@@ -1815,6 +1832,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>543</generationTimeMilliseconds>
 				<generationTime>0.54s</generationTime>
 				<interactionPosition>4</interactionPosition>
 				<timeSpent>8</timeSpent>
@@ -1835,6 +1853,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>343</generationTimeMilliseconds>
 				<generationTime>0.34s</generationTime>
 				<interactionPosition>8</interactionPosition>
 				<icon />
@@ -1946,6 +1965,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>1</generationTimeMilliseconds>
 				<generationTime>0.001s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -2194,6 +2214,7 @@
 						<customVariablePageValue3>200</customVariablePageValue3>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>359</generationTimeMilliseconds>
 				<generationTime>0.36s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -2298,6 +2319,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>109</generationTimeMilliseconds>
 				<generationTime>0.11s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>0</timeSpent>
@@ -2356,6 +2378,7 @@
 						<customVariablePageValue3>200</customVariablePageValue3>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>109</generationTimeMilliseconds>
 				<generationTime>0.11s</generationTime>
 				<interactionPosition>3</interactionPosition>
 				<icon />
@@ -2471,6 +2494,7 @@
 						<customVariablePageValue1>404</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>359</generationTimeMilliseconds>
 				<generationTime>0.36s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -2579,6 +2603,7 @@
 						<customVariablePageValue3>404</customVariablePageValue3>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>359</generationTimeMilliseconds>
 				<generationTime>0.36s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>0</timeSpent>
@@ -2610,6 +2635,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>359</generationTimeMilliseconds>
 				<generationTime>0.36s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -3113,6 +3139,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>1</generationTimeMilliseconds>
 				<generationTime>0.001s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -3224,6 +3251,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>9</generationTimeMilliseconds>
 				<generationTime>0.009s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
diff --git a/tests/PHPUnit/System/expected/test_ImportLogs_siteIdThree_TrackedUsingLogReplayWithFixedSiteId__Live.getLastVisitsDetails_range.xml b/tests/PHPUnit/System/expected/test_ImportLogs_siteIdThree_TrackedUsingLogReplayWithFixedSiteId__Live.getLastVisitsDetails_range.xml
index adef933973..1d24cb751b 100644
--- a/tests/PHPUnit/System/expected/test_ImportLogs_siteIdThree_TrackedUsingLogReplayWithFixedSiteId__Live.getLastVisitsDetails_range.xml
+++ b/tests/PHPUnit/System/expected/test_ImportLogs_siteIdThree_TrackedUsingLogReplayWithFixedSiteId__Live.getLastVisitsDetails_range.xml
@@ -19,6 +19,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>292</generationTimeMilliseconds>
 				<generationTime>0.29s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -258,6 +259,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>413</generationTimeMilliseconds>
 				<generationTime>0.41s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -646,6 +648,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>391</generationTimeMilliseconds>
 				<generationTime>0.39s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -891,6 +894,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>119</generationTimeMilliseconds>
 				<generationTime>0.12s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -1000,6 +1004,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>145</generationTimeMilliseconds>
 				<generationTime>0.15s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -1129,6 +1134,7 @@
 						<customVariablePageValue1>403</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>182</generationTimeMilliseconds>
 				<generationTime>0.18s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>2</timeSpent>
@@ -1149,6 +1155,7 @@
 						<customVariablePageValue1>500</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>113</generationTimeMilliseconds>
 				<generationTime>0.11s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>7</timeSpent>
@@ -1281,6 +1288,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>134</generationTimeMilliseconds>
 				<generationTime>0.13s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -1402,6 +1410,7 @@
 						<customVariablePageValue1>200</customVariablePageValue1>
 					</row>
 				</customVariables>
+				<generationTimeMilliseconds>58</generationTimeMilliseconds>
 				<generationTime>0.06s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
diff --git a/tests/PHPUnit/System/expected/test_OneVisitorTwoVisits_withCookieSupport__Live.getLastVisitsDetails_day.xml b/tests/PHPUnit/System/expected/test_OneVisitorTwoVisits_withCookieSupport__Live.getLastVisitsDetails_day.xml
index 453d9a946e..1c1b8ffd04 100644
--- a/tests/PHPUnit/System/expected/test_OneVisitorTwoVisits_withCookieSupport__Live.getLastVisitsDetails_day.xml
+++ b/tests/PHPUnit/System/expected/test_OneVisitorTwoVisits_withCookieSupport__Live.getLastVisitsDetails_day.xml
@@ -24,6 +24,7 @@
 				<pageIdAction>13</pageIdAction>
 				
 				<pageId>9</pageId>
+				<generationTimeMilliseconds>134</generationTimeMilliseconds>
 				<generationTime>0.13s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<icon />
@@ -127,6 +128,7 @@
 				<pageIdAction>2</pageIdAction>
 				
 				<pageId>1</pageId>
+				<generationTimeMilliseconds>234</generationTimeMilliseconds>
 				<generationTime>0.23s</generationTime>
 				<interactionPosition>1</interactionPosition>
 				<timeSpent>180</timeSpent>
@@ -141,6 +143,7 @@
 				<pageIdAction>4</pageIdAction>
 				
 				<pageId>2</pageId>
+				<generationTimeMilliseconds>224</generationTimeMilliseconds>
 				<generationTime>0.22s</generationTime>
 				<interactionPosition>2</interactionPosition>
 				<timeSpent>180</timeSpent>
@@ -218,6 +221,7 @@
 				
 				<pageId>7</pageId>
 				<siteSearchKeyword>Banks Own The World</siteSearchKeyword>
+				<generationTimeMilliseconds>812</generationTimeMilliseconds>
 				<generationTime>0.81s</generationTime>
 				<interactionPosition>3</interactionPosition>
 				<timeSpent>108</timeSpent>
@@ -232,6 +236,7 @@
 				<pageIdAction>11</pageIdAction>
 				
 				<pageId>8</pageId>
+				<generationTimeMilliseconds>24</generationTimeMilliseconds>
 				<generationTime>0.02s</generationTime>
 				<interactionPosition>4</interactionPosition>
 				<icon />
diff --git a/tests/PHPUnit/Unit/DataTable/Filter/ColumnDeleteTest.php b/tests/PHPUnit/Unit/DataTable/Filter/ColumnDeleteTest.php
new file mode 100644
index 0000000000..79fe1619cc
--- /dev/null
+++ b/tests/PHPUnit/Unit/DataTable/Filter/ColumnDeleteTest.php
@@ -0,0 +1,164 @@
+<?php
+/**
+ * Piwik - free/libre analytics platform
+ *
+ * @link http://piwik.org
+ * @license http://www.gnu.org/licenses/gpl-3.0.html GPL v3 or later
+ */
+
+namespace Piwik\Tests\Unit\DataTable\Filter;
+
+use Piwik\DataTable;
+use Piwik\DataTable\Row;
+
+class ColumnDeleteTest extends \PHPUnit_Framework_TestCase
+{
+    private $filter = 'ColumnDelete';
+
+    protected function makeDataTable($appendRowWithSubtable = true)
+    {
+        $table = new DataTable();
+        $table->addRowFromArray(array(Row::COLUMNS => array('label' => 'row1', 'visits' => 0, 'arrayColumn' => array('visits' => 0, 'columnWithin' => 10))));
+        $table->addRowFromArray(array(Row::COLUMNS => array('label' => 'row2', 'visits' => 1, 'arrayColumn' => array('visits' => 1, 'columnWithin' => 11))));
+        $table->addRowFromArray(array(Row::COLUMNS => array('label' => 'row3', 'visits' => 2, 'arrayColumn' => array('visits' => 2, 'columnWithin' => 12))));
+
+        if($appendRowWithSubtable) {
+            $subTable = $this->makeDataTable( $appendRowWithSubtable = false );
+            $table->addRowFromArray(array(
+                Row::COLUMNS => array('label' => 'row4', 'visits' => 3, 'arrayColumn' => array('visits' => 3, 'columnWithin' => 13)),
+                Row::DATATABLE_ASSOCIATED => $subTable
+            ));
+        }
+        return $table;
+    }
+
+    protected function makeDataTable_withoutVisitsColumn($appendRowWithSubtable = true)
+    {
+        $table = new DataTable();
+        $table->addRowFromArray(array(Row::COLUMNS => array('label' => 'row1', 'arrayColumn' => array('columnWithin' => 10))));
+        $table->addRowFromArray(array(Row::COLUMNS => array('label' => 'row2', 'arrayColumn' => array('columnWithin' => 11))));
+        $table->addRowFromArray(array(Row::COLUMNS => array('label' => 'row3', 'arrayColumn' => array('columnWithin' => 12))));
+
+        if($appendRowWithSubtable) {
+            $subTable = $this->makeDataTable_withoutVisitsColumn( $appendRowWithSubtable = false );
+            $table->addRowFromArray(array(
+                Row::COLUMNS => array('label' => 'row4', 'arrayColumn' => array('columnWithin' => 13)),
+                Row::DATATABLE_ASSOCIATED => $subTable
+            ));
+        }
+        return $table;
+    }
+
+    protected function makeDataTable_showOnlyVisitColumn($appendRowWithSubtable = true)
+    {
+        $table = new DataTable();
+        $table->addRowFromArray(array(Row::COLUMNS => array( 'label' => 'row1', 'visits' => 0)));
+        $table->addRowFromArray(array(Row::COLUMNS => array( 'label' => 'row2', 'visits' => 1)));
+        $table->addRowFromArray(array(Row::COLUMNS => array( 'label' => 'row3', 'visits' => 2)));
+
+        if($appendRowWithSubtable) {
+            $subTable = $this->makeDataTable_showOnlyVisitColumn( $appendRowWithSubtable = false );
+            $table->addRowFromArray(array(
+                Row::COLUMNS => array('label' => 'row4', 'visits' => 3),
+                Row::DATATABLE_ASSOCIATED => $subTable
+            ));
+        }
+        return $table;
+    }
+
+    protected function assertSameDataTable(DataTable $table1, DataTable $table2)
+    {
+        $this->assertTrue(DataTable::isEqual($table1, $table2), var_export($table1->getRows(), true) .' different from ' . var_export($table2, true));
+    }
+
+    public function test_filter_DataTable_removeNonExistingColumn()
+    {
+        $table = $this->makeDataTable();
+        $table->filter($this->filter, array('does-not-exist'));
+
+        $this->assertSameDataTable($this->makeDataTable(), $table);
+    }
+
+    public function test_filter_DataTable_removeExistingColumn()
+    {
+        $table = $this->makeDataTable();
+        $table->filter($this->filter, array('visits'));
+
+        $this->assertSameDataTable($this->makeDataTable_withoutVisitsColumn(), $table);
+    }
+
+    public function test_filter_DataTable_keepColumn()
+    {
+        $table = $this->makeDataTable();
+        $table->filter($this->filter, array($hide = '', $show = 'visits'));
+
+        $this->assertSameDataTable($this->makeDataTable_showOnlyVisitColumn(), $table);
+    }
+
+    public function test_filter_array_removeNonExistingColumn()
+    {
+        $array = $this->makeArray();
+
+        $columnDelete = new DataTable\Filter\ColumnDelete(new DataTable(), $hideColumns = 'non-existing-column', $showColumns = array());
+        $filteredArray = $columnDelete->filter($array);
+
+        $this->assertSame($array, $filteredArray);
+    }
+
+    public function test_filter_array_removeExistingColumn()
+    {
+        $columnDelete = new DataTable\Filter\ColumnDelete(new DataTable(), $hideColumns = 'visits', $showColumns = array());
+        $filteredArray = $columnDelete->filter($this->makeArray());
+
+        $this->assertSame($this->makeArray_withoutVisitsColumns(), $filteredArray);
+    }
+
+    public function test_filter_array_keepColumn()
+    {
+        $columnDelete = new DataTable\Filter\ColumnDelete(new DataTable(), $hideColumns = '', $showColumns = 'visits');
+        $filteredArray = $columnDelete->filter($this->makeArray());
+
+        $this->assertSame($this->makeArray_showVisitsColumns(), $filteredArray);
+    }
+
+    /**
+     * @return array
+     */
+    protected function makeArray()
+    {
+        $array = array(
+            array('label' => 'row1', 'visits' => 1, 'arrayColumn' => array('visits' => 0, 'columnWithin' => 10)),
+            array('label' => 'row2', 'visits' => 2, 'arrayColumn' => array('visits' => 1, 'columnWithin' => 11)),
+            array('label' => 'row3', 'visits' => 3, 'arrayColumn' => array('visits' => 2, 'columnWithin' => 12)),
+        );
+        return $array;
+    }
+
+    /**
+     * @return array
+     */
+    protected function makeArray_withoutVisitsColumns()
+    {
+        $array = array(
+            array('label' => 'row1', 'arrayColumn' => array( 'columnWithin' => 10)),
+            array('label' => 'row2', 'arrayColumn' => array( 'columnWithin' => 11)),
+            array('label' => 'row3', 'arrayColumn' => array( 'columnWithin' => 12)),
+        );
+        return $array;
+    }
+
+    /**
+     * @return array
+     */
+    protected function makeArray_showVisitsColumns()
+    {
+        $array = array(
+            array('label' => 'row1', 'visits' => 1),
+            array('label' => 'row2', 'visits' => 2),
+            array('label' => 'row3', 'visits' => 3),
+        );
+        return $array;
+    }
+
+}
+