Refs #7181, add logging to ArchivePurger service + archive purging scheduled tasks + Scheduler, modify CronArchive to run scheduled tasks within same process as core:archive so logs are visible in core:archive output.

1 files changed, 46 insertions, 12 deletions

diff --git a/core/Archive/ArchivePurger.php b/core/Archive/ArchivePurger.php
index e41ce375c5..910a539dbb 100644
--- a/core/Archive/ArchivePurger.php
+++ b/core/Archive/ArchivePurger.php
@@ -10,12 +10,13 @@ namespace Piwik\Archive;
 
 use Piwik\ArchiveProcessor\Rules;
 use Piwik\Config;
+use Piwik\Container\StaticContainer;
 use Piwik\DataAccess\ArchiveTableCreator;
 use Piwik\DataAccess\Model;
 use Piwik\Date;
 use Piwik\Db;
-use Piwik\Log;
 use Piwik\Piwik;
+use Psr\Log\LoggerInterface;
 
 /**
  * Service that purges temporary, error-ed, invalid and custom range archives from archive tables.
@@ -64,7 +65,12 @@ class ArchivePurger
      */
     private $now;
 
-    public function __construct(Model $model = null, Date $purgeCustomRangesOlderThan = null)
+    /**
+     * @var LoggerInterface
+     */
+    private $logger;
+
+    public function __construct(Model $model = null, Date $purgeCustomRangesOlderThan = null, LoggerInterface $logger = null)
     {
         $this->model = $model ?: new Model();
 
@@ -73,6 +79,7 @@ class ArchivePurger
         $this->yesterday = Date::factory('yesterday');
         $this->today = Date::factory('today');
         $this->now = time();
+        $this->logger = $logger ?: StaticContainer::get('Psr\Log\LoggerInterface');
     }
 
     /**
@@ -90,15 +97,25 @@ class ArchivePurger
         // the constraint will hit an INDEX and speed up the inner join that happens in getInvalidatedArchiveIdsSafeToDelete().
         $idSites = $this->model->getSitesWithInvalidatedArchive($numericTable);
         if (empty($idSites)) {
+            $this->logger->info("No sites with invalidated archives found in {table}.", array('table' => $numericTable));
             return;
         }
 
         $archiveIds = $this->model->getInvalidatedArchiveIdsSafeToDelete($numericTable, $idSites);
         if (empty($archiveIds)) {
+            $this->logger->info("No invalidated archives found in {table} with newer, valid archives.", array('table' => $numericTable));
             return;
         }
 
-        $this->deleteArchiveIds($date, $archiveIds);
+        $this->logger->info("Found {countArchiveIds} invalidated archives safe to delete in {table}.", array(
+            'table' => $numericTable, 'countArchiveIds' => count($archiveIds)
+        ));
+
+        $deletedRowCount = $this->deleteArchiveIds($date, $archiveIds);
+
+        $this->logger->info("Deleted {count} rows in {table} and its associated blob table.", array(
+            'table' => $numericTable, 'count' => $deletedRowCount
+        ));
     }
 
     /**
@@ -113,13 +130,21 @@ class ArchivePurger
 
         $idArchivesToDelete = $this->getOutdatedArchiveIds($dateStart, $purgeArchivesOlderThan);
         if (!empty($idArchivesToDelete)) {
-            $this->deleteArchiveIds($dateStart, $idArchivesToDelete);
+            $deletedRowCount = $this->deleteArchiveIds($dateStart, $idArchivesToDelete);
+
+            $this->logger->info("Deleted {count} rows in archive tables (numeric + blob) for {date}.", array(
+                'count' => $deletedRowCount,
+                'date' => $dateStart
+            ));
+        } else {
+            $this->logger->info("No outdated archives found in archive numeric table for {date}.", array('date' => $dateStart));
         }
 
-        Log::debug("Purging temporary archives: done [ purged archives older than %s in %s ] [Deleted IDs: %s]",
-                   $purgeArchivesOlderThan,
-                   $dateStart->toString("Y-m"),
-                   implode(',', $idArchivesToDelete));
+        $this->logger->debug("Purging temporary archives: done [ purged archives older than {date} in {yearMonth} ] [Deleted IDs: {deletedIds}]", array(
+            'date' => $purgeArchivesOlderThan,
+            'yearMonth' => $dateStart->toString('Y-m'),
+            'deletedIds' => implode(',', $idArchivesToDelete)
+        ));
     }
 
     protected function getOutdatedArchiveIds(Date $date, $purgeArchivesOlderThan)
@@ -148,10 +173,16 @@ class ArchivePurger
         $numericTable = ArchiveTableCreator::getNumericTable($date);
         $blobTable    = ArchiveTableCreator::getBlobTable($date);
 
-        $this->model->deleteArchivesWithPeriod($numericTable, $blobTable, Piwik::$idPeriods['range'], $this->purgeCustomRangesOlderThan);
+        $deletedCount = $this->model->deleteArchivesWithPeriod(
+            $numericTable, $blobTable, Piwik::$idPeriods['range'], $this->purgeCustomRangesOlderThan);
+
+        $this->logger->info("Purged {count} range archive rows from {numericTable} & {blobTable}.", array(
+            'count' => $deletedCount,
+            'numericTable' => $numericTable,
+            'blobTable' => $blobTable
+        ));
 
-        Log::debug("Purging Custom Range archives: done [ purged archives older than %s from %s / blob ]",
-            $this->purgeCustomRangesOlderThan, $numericTable);
+        $this->logger->debug("  [ purged archives older than {threshold} ]", array('threshold' => $this->purgeCustomRangesOlderThan));
     }
 
     /**
@@ -159,6 +190,7 @@ class ArchivePurger
      *
      * @param Date $date
      * @param $idArchivesToDelete
+     * @return int Number of rows deleted from both numeric + blob table.
      */
     protected function deleteArchiveIds(Date $date, $idArchivesToDelete)
     {
@@ -166,9 +198,11 @@ class ArchivePurger
         $numericTable = ArchiveTableCreator::getNumericTable($date);
         $blobTable    = ArchiveTableCreator::getBlobTable($date);
 
+        $deletedCount = 0;
         foreach ($batches as $idsToDelete) {
-            $this->model->deleteArchiveIds($numericTable, $blobTable, $idsToDelete);
+            $deletedCount += $this->model->deleteArchiveIds($numericTable, $blobTable, $idsToDelete);
         }
+        return $deletedCount;
     }
 
     /**