Skip to content
Extraits de code Groupes Projets
Valider 87d826e3 rédigé par Matthieu Napoli's avatar Matthieu Napoli
Parcourir les fichiers

Test for the archiver log output

parent c38cb2fe
Aucune branche associée trouvée
Aucune étiquette associée trouvée
Aucune requête de fusion associée trouvée
Masquer les modifications d'espaces
En ligne Côte à côte
core/CronArchive.php
+ 55
− 55
Voir le fichier @ 87d826e3
......@@ -24,6 +24,7 @@ use Piwik\Plugins\CoreAdminHome\API as CoreAdminHomeAPI;
use Piwik\Plugins\SitesManager\API as APISitesManager;
use Piwik\Plugins\UsersManager\API as APIUsersManager;
use Piwik\Plugins\UsersManager\UserPreferences;
use Psr\Log\LoggerInterface;
/**
* ./console core:archive runs as a cron and is a useful tool for general maintenance,
......@@ -84,7 +85,6 @@ class CronArchive
private $validTokenAuths = array();
private $visitsToday = 0;
private $requests = 0;
private $output = '';
private $archiveAndRespectTTL = true;
private $lastSuccessRunTimestamp = false;
......@@ -206,6 +206,11 @@ class CronArchive
*/
private $segmentArchivingRequestUrlProvider;
/**
* @var LoggerInterface
*/
private $logger;
/**
* Returns the option name of the option that stores the time core:archive was last executed.
*
......@@ -228,8 +233,9 @@ class CronArchive
* @param string|null $processNewSegmentsFrom When to archive new segments from. See [General] process_new_segments_from
* for possible values.
*/
public function __construct($piwikUrl = false, $processNewSegmentsFrom = null)
public function __construct($piwikUrl = false, $processNewSegmentsFrom = null, LoggerInterface $logger = null)
{
$this->logger = $logger ?: StaticContainer::get('Psr\Log\LoggerInterface');
$this->formatter = new Formatter();
$this->initPiwikHost($piwikUrl);
......@@ -270,7 +276,7 @@ class CronArchive
$this->allWebsites = APISitesManager::getInstance()->getAllSitesId();
if (!empty($this->shouldArchiveOnlySpecificPeriods)) {
$this->log("- Will only process the following periods: " . implode(", ", $this->shouldArchiveOnlySpecificPeriods) . " (--force-periods)");
$this->logger->info("- Will only process the following periods: " . implode(", ", $this->shouldArchiveOnlySpecificPeriods) . " (--force-periods)");
}
$this->invalidateArchivedReportsForSitesThatNeedToBeArchivedAgain();
......@@ -281,7 +287,7 @@ class CronArchive
$this->websites = $this->createSitesToArchiveQueue($websitesIds);
if ($this->websites->getInitialSiteIds() != $websitesIds) {
$this->log('Will ignore websites and help finish a previous started queue instead. IDs: ' . implode(', ', $this->websites->getInitialSiteIds()));
$this->logger->info('Will ignore websites and help finish a previous started queue instead. IDs: ' . implode(', ', $this->websites->getInitialSiteIds()));
}
/**
......@@ -311,7 +317,7 @@ class CronArchive
$timer = new Timer;
$this->logSection("START");
$this->log("Starting Piwik reports archiving...");
$this->logger->info("Starting Piwik reports archiving...");
do {
$idSite = $this->websites->getNextSiteId();
......@@ -328,7 +334,7 @@ class CronArchive
$skipWebsiteForced = in_array($idSite, $this->shouldSkipSpecifiedSites);
if ($skipWebsiteForced) {
$this->log("Skipped website id $idSite, found in --skip-idsites ");
$this->logger->info("Skipped website id $idSite, found in --skip-idsites ");
$this->skipped++;
continue;
}
......@@ -352,25 +358,25 @@ class CronArchive
Piwik::postEvent('CronArchive.archiveSingleSite.finish', array($idSite, $completed));
} while (!empty($idSite));
$this->log("Done archiving!");
$this->logger->info("Done archiving!");
$this->logSection("SUMMARY");
$this->log("Total visits for today across archived websites: " . $this->visitsToday);
$this->logger->info("Total visits for today across archived websites: " . $this->visitsToday);
$totalWebsites = count($this->allWebsites);
$this->skipped = $totalWebsites - $this->websitesWithVisitsSinceLastRun;
$this->log("Archived today's reports for {$this->websitesWithVisitsSinceLastRun} websites");
$this->log("Archived week/month/year for {$this->archivedPeriodsArchivesWebsite} websites");
$this->log("Skipped {$this->skipped} websites: no new visit since the last script execution");
$this->log("Skipped {$this->skippedDayArchivesWebsites} websites day archiving: existing daily reports are less than {$this->todayArchiveTimeToLive} seconds old");
$this->log("Skipped {$this->skippedPeriodsArchivesWebsite} websites week/month/year archiving: existing periods reports are less than {$this->processPeriodsMaximumEverySeconds} seconds old");
$this->log("Total API requests: {$this->requests}");
$this->logger->info("Archived today's reports for {$this->websitesWithVisitsSinceLastRun} websites");
$this->logger->info("Archived week/month/year for {$this->archivedPeriodsArchivesWebsite} websites");
$this->logger->info("Skipped {$this->skipped} websites: no new visit since the last script execution");
$this->logger->info("Skipped {$this->skippedDayArchivesWebsites} websites day archiving: existing daily reports are less than {$this->todayArchiveTimeToLive} seconds old");
$this->logger->info("Skipped {$this->skippedPeriodsArchivesWebsite} websites week/month/year archiving: existing periods reports are less than {$this->processPeriodsMaximumEverySeconds} seconds old");
$this->logger->info("Total API requests: {$this->requests}");
//DONE: done/total, visits, wtoday, wperiods, reqs, time, errors[count]: first eg.
$percent = $this->websites->getNumSites() == 0
? ""
: " " . round($this->processed * 100 / $this->websites->getNumSites(), 0) . "%";
$this->log("done: " .
$this->logger->info("done: " .
$this->processed . "/" . $this->websites->getNumSites() . "" . $percent . ", " .
$this->visitsToday . " vtoday, $this->websitesWithVisitsSinceLastRun wtoday, {$this->archivedPeriodsArchivesWebsite} wperiods, " .
$this->requests . " req, " . round($timer->getTimeMs()) . " ms, " .
......@@ -378,7 +384,7 @@ class CronArchive
? self::NO_ERROR
: (count($this->errors) . " errors."))
);
$this->log($timer->__toString());
$this->logger->info($timer->__toString());
}
/**
......@@ -395,7 +401,7 @@ class CronArchive
$this->logSection("SUMMARY OF ERRORS");
foreach ($this->errors as $error) {
// do not logError since errors are already in stderr
$this->log("Error: " . $error);
$this->logger->info("Error: " . $error);
}
$summary = count($this->errors) . " total errors during this script execution, please investigate and try and fix these errors.";
......@@ -414,7 +420,7 @@ class CronArchive
$this->logSection("SCHEDULED TASKS");
if ($this->disableScheduledTasks) {
$this->log("Scheduled tasks are disabled with --disable-scheduled-tasks");
$this->logger->info("Scheduled tasks are disabled with --disable-scheduled-tasks");
return;
}
......@@ -502,7 +508,7 @@ class CronArchive
}
if ($skipDayArchive) {
$this->log("Skipped website id $idSite, already done "
$this->logger->info("Skipped website id $idSite, already done "
. $this->formatter->getPrettyTimeFromSeconds($elapsedSinceLastArchiving, true)
. " ago, " . $timerWebsite->__toString());
$this->skippedDayArchivesWebsites++;
......@@ -515,7 +521,7 @@ class CronArchive
} catch(UnexpectedWebsiteFoundException $e) {
// this website was deleted in the meantime
$shouldProceed = false;
$this->log("Skipped website id $idSite, got: UnexpectedWebsiteFoundException, " . $timerWebsite->__toString());
$this->logger->info("Skipped website id $idSite, got: UnexpectedWebsiteFoundException, " . $timerWebsite->__toString());
}
if (!$shouldProceed) {
......@@ -523,7 +529,7 @@ class CronArchive
}
if (!$shouldArchivePeriods) {
$this->log("Skipped website id $idSite periods processing, already done "
$this->logger->info("Skipped website id $idSite periods processing, already done "
. $this->formatter->getPrettyTimeFromSeconds($elapsedSinceLastArchiving, true)
. " ago, " . $timerWebsite->__toString());
$this->skippedDayArchivesWebsites++;
......@@ -549,7 +555,7 @@ class CronArchive
$this->archivedPeriodsArchivesWebsite++;
$requestsWebsite = $this->requests - $requestsBefore;
Log::info("Archived website id = $idSite, "
$this->logger->info("Archived website id = $idSite, "
. $requestsWebsite . " API requests, "
. $timerWebsite->__toString()
. " [" . $this->websites->getNumProcessedWebsites() . "/"
......@@ -634,7 +640,7 @@ class CronArchive
return array();
}
$this->log("- Will pre-process " . count($segments) . " Segments for each website and each period: " . implode(", ", $segments));
$this->logger->info("- Will pre-process " . count($segments) . " Segments for each website and each period: " . implode(", ", $segments));
return $segments;
}
......@@ -708,7 +714,7 @@ class CronArchive
if (0 == $visitsToday
&& !$shouldArchivePeriods
) {
$this->log("Skipped website id $idSite, no visit today, " . $timerWebsite->__toString());
$this->logger->info("Skipped website id $idSite, no visit today, " . $timerWebsite->__toString());
$this->skipped++;
return false;
}
......@@ -717,7 +723,7 @@ class CronArchive
&& !$shouldArchivePeriods
&& $this->shouldArchiveAllSites
) {
$this->log("Skipped website id $idSite, no visits in the last " . $date . " days, " . $timerWebsite->__toString());
$this->logger->info("Skipped website id $idSite, no visits in the last " . $date . " days, " . $timerWebsite->__toString());
$this->skipped++;
return false;
}
......@@ -736,7 +742,7 @@ class CronArchive
$segmentsAllSites = $this->segments;
$segmentsThisSite = SettingsPiwik::getKnownSegmentsToArchiveForSite($idSite);
if (!empty($segmentsThisSite)) {
$this->log(sprintf(
$this->logger->info(sprintf(
"Will pre-process for website id = %s, %s period, %d segments",
$idSite,
$period,
......@@ -786,7 +792,7 @@ class CronArchive
$this->requests += count($urls);
$this->log('- pre-processing all visits');
$this->logger->info('- pre-processing all visits');
$cliMulti = new CliMulti();
$cliMulti->setAcceptInvalidSSLCertificate($this->acceptInvalidSSLCertificate);
......@@ -828,18 +834,12 @@ class CronArchive
*/
private function logSection($title = "")
{
$this->log("---------------------------");
$this->logger->info("---------------------------");
if (!empty($title)) {
$this->log($title);
$this->logger->info($title);
}
}
public function log($m)
{
$this->output .= $m . "\n";
Log::info($m);
}
public function logError($m)
{
if (!defined('PIWIK_ARCHIVE_NO_TRUNCATE')) {
......@@ -847,7 +847,7 @@ class CronArchive
}
$m = str_replace(array("\n", "\t"), " ", $m);
$this->errors[] = $m;
Log::error($m);
$this->logger->error($m);
}
private function logNetworkError($url, $response)
......@@ -993,10 +993,10 @@ class CronArchive
$listSiteIds = implode(',', $siteIds);
try {
$this->log('Will invalidate archived reports for ' . $date . ' for following siteIds: ' . $listSiteIds);
$this->logger->info('Will invalidate archived reports for ' . $date . ' for following siteIds: ' . $listSiteIds);
$this->getApiToInvalidateArchivedReport()->invalidateArchivedReports($siteIds, $date);
} catch (Exception $e) {
$this->log('Failed to invalidate archived reports: ' . $e->getMessage());
$this->logger->info('Failed to invalidate archived reports: ' . $e->getMessage());
}
}
}
......@@ -1008,12 +1008,12 @@ class CronArchive
public function initWebsiteIds()
{
if (count($this->shouldArchiveSpecifiedSites) > 0) {
$this->log("- Will process " . count($this->shouldArchiveSpecifiedSites) . " websites (--force-idsites)");
$this->logger->info("- Will process " . count($this->shouldArchiveSpecifiedSites) . " websites (--force-idsites)");
return $this->shouldArchiveSpecifiedSites;
}
if ($this->shouldArchiveAllSites) {
$this->log("- Will process all " . count($this->allWebsites) . " websites");
$this->logger->info("- Will process all " . count($this->allWebsites) . " websites");
return $this->allWebsites;
}
......@@ -1110,7 +1110,7 @@ class CronArchive
if (count($this->idSitesInvalidatedOldReports) > 0) {
$ids = ", IDs: " . implode(", ", $this->idSitesInvalidatedOldReports);
$this->log("- Will process " . count($this->idSitesInvalidatedOldReports)
$this->logger->info("- Will process " . count($this->idSitesInvalidatedOldReports)
. " other websites because some old data reports have been invalidated (eg. using the Log Import script) "
. $ids);
}
......@@ -1128,7 +1128,7 @@ class CronArchive
$sitesIdWithVisits = APISitesManager::getInstance()->getSitesIdWithVisits(time() - $this->shouldArchiveOnlySitesWithTrafficSince);
$websiteIds = !empty($sitesIdWithVisits) ? ", IDs: " . implode(", ", $sitesIdWithVisits) : "";
$prettySeconds = $this->formatter->getPrettyTimeFromSeconds( $this->shouldArchiveOnlySitesWithTrafficSince, true);
$this->log("- Will process " . count($sitesIdWithVisits) . " websites with new visits since "
$this->logger->info("- Will process " . count($sitesIdWithVisits) . " websites with new visits since "
. $prettySeconds
. " "
. $websiteIds);
......@@ -1189,7 +1189,7 @@ class CronArchive
if (count($websiteDayHasFinishedSinceLastRun) > 0) {
$ids = !empty($websiteDayHasFinishedSinceLastRun) ? ", IDs: " . implode(", ", $websiteDayHasFinishedSinceLastRun) : "";
$this->log("- Will process " . count($websiteDayHasFinishedSinceLastRun)
$this->logger->info("- Will process " . count($websiteDayHasFinishedSinceLastRun)
. " other websites because the last time they were archived was on a different day (in the website's timezone) "
. $ids);
}
......@@ -1214,8 +1214,8 @@ class CronArchive
private function logInitInfo()
{
$this->logSection("INIT");
$this->log("Piwik is installed at: {$this->piwikUrl}");
$this->log("Running Piwik " . Version::VERSION . " as Super User");
$this->logger->info("Piwik is installed at: {$this->piwikUrl}");
$this->logger->info("Running Piwik " . Version::VERSION . " as Super User");
}
private function logArchiveTimeoutInfo()
......@@ -1224,18 +1224,18 @@ class CronArchive
// Recommend to disable browser archiving when using this script
if (Rules::isBrowserTriggerEnabled()) {
$this->log("- 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. ");
$this->log(" See the doc at: http://piwik.org/docs/setup-auto-archiving/");
$this->logger->info("- 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.");
$this->logger->info(" See the doc at: http://piwik.org/docs/setup-auto-archiving/");
}
$this->log("- Reports for today will be processed at most every " . $this->todayArchiveTimeToLive
$this->logger->info("- Reports for today will be processed at most every " . $this->todayArchiveTimeToLive
. " seconds. You can change this value in Piwik UI > Settings > General Settings.");
$this->log("- Reports for the current week/month/year will be refreshed at most every "
$this->logger->info("- Reports for the current week/month/year will be refreshed at most every "
. $this->processPeriodsMaximumEverySeconds . " seconds.");
// Try and not request older data we know is already archived
if ($this->lastSuccessRunTimestamp !== false) {
$dateLast = time() - $this->lastSuccessRunTimestamp;
$this->log("- Archiving was last executed without error "
$this->logger->info("- Archiving was last executed without error "
. $this->formatter->getPrettyTimeFromSeconds($dateLast, true) . " ago");
}
}
......@@ -1257,7 +1257,7 @@ class CronArchive
return $this->forceTimeoutPeriod;
}
$this->log("WARNING: Automatically increasing --force-timeout-for-periods from {$this->forceTimeoutPeriod} to "
$this->logger->info("WARNING: Automatically increasing --force-timeout-for-periods from {$this->forceTimeoutPeriod} to "
. $this->todayArchiveTimeToLive
. " to match the cache timeout for Today's report specified in Piwik UI > Settings > General Settings");
......@@ -1354,7 +1354,7 @@ class CronArchive
$visitsInLastPeriod = '';
}
$this->log("Archived website id = $idSite, period = $period, "
$this->logger->info("Archived website id = $idSite, period = $period, "
. $visitsInLastPeriods
. $visitsInLastPeriod
. $timer->__toString());
......@@ -1592,10 +1592,10 @@ class CronArchive
$urlWithSegment = $this->makeRequestUrl($urlWithSegment);
$request = new Request($urlWithSegment);
$self = $this;
$request->before(function () use ($self, $segment, $segmentCount, &$processedSegmentCount) {
$logger = $this->logger;
$request->before(function () use ($logger, $segment, $segmentCount, &$processedSegmentCount) {
$processedSegmentCount++;
$self->log(sprintf(
$logger->info(sprintf(
'- pre-processing segment %d/%d %s',
$processedSegmentCount,
$segmentCount,
......
tests/PHPUnit/Framework/Mock/FakeLogger.php 0 → 100644
+ 19
− 0
Voir le fichier @ 87d826e3
<?php
namespace Piwik\Tests\Framework\Mock;
use Psr\Log\AbstractLogger;
use Psr\Log\LoggerInterface;
class FakeLogger extends AbstractLogger implements LoggerInterface
{
/**
* @var string
*/
public $output = '';
public function log($level, $message, array $context = array())
{
$this->output .= $message . PHP_EOL;
}
}
tests/PHPUnit/Integration/CronArchiveTest.php
+ 76
− 22
Voir le fichier @ 87d826e3
......@@ -14,21 +14,9 @@ use Piwik\Date;
use Piwik\Db;
use Piwik\Plugins\CoreAdminHome\tests\Framework\Mock\API;
use Piwik\Tests\Framework\Fixture;
use Piwik\Tests\Framework\Mock\FakeLogger;
use Piwik\Tests\Framework\TestCase\IntegrationTestCase;
class TestCronArchive extends CronArchive
{
protected function checkPiwikUrlIsValid()
{
}
protected function initPiwikHost($piwikUrl = false)
{
}
}
use Piwik\Plugins\SegmentEditor\API as SegmentAPI;
/**
* @group Archiver
......@@ -36,16 +24,11 @@ class TestCronArchive extends CronArchive
*/
class CronArchiveTest extends IntegrationTestCase
{
public function setUp()
public function test_getColumnNamesFromTable()
{
parent::setUp();
Fixture::createWebsite('2014-12-12 00:01:02');
Fixture::createWebsite('2014-12-12 00:01:02');
}
public function test_getColumnNamesFromTable()
{
$ar = new ArchiveInvalidator();
$ar->rememberToInvalidateArchivedReportsLater(1, Date::factory('2014-04-05'));
$ar->rememberToInvalidateArchivedReportsLater(2, Date::factory('2014-04-05'));
......@@ -53,11 +36,9 @@ class CronArchiveTest extends IntegrationTestCase
$api = API::getInstance();
ob_start();
$cronarchive = new TestCronArchive(Fixture::getRootUrl() . 'tests/PHPUnit/proxy/index.php');
$cronarchive->setApiToInvalidateArchivedReport($api);
$cronarchive->init();
ob_end_clean();
$expectedInvalidations = array(
array(array(1,2), '2014-04-05'),
......@@ -66,4 +47,77 @@ class CronArchiveTest extends IntegrationTestCase
$this->assertEquals($expectedInvalidations, $api->getInvalidatedReports());
}
public function test_output()
{
Fixture::createWebsite('2014-12-12 00:01:02');
SegmentAPI::getInstance()->add('foo', 'actions>=2', 1, true, true);
$logger = new FakeLogger();
$archiver = new CronArchive(Fixture::getRootUrl() . 'tests/PHPUnit/proxy/index.php', null, $logger);
$archiver->shouldArchiveAllSites = true;
$archiver->shouldArchiveAllPeriodsSince = true;
$archiver->init();
$archiver->run();
$expected = <<<LOG
---------------------------
INIT
Piwik is installed at: %s
Running Piwik %s as Super User
---------------------------
NOTES
- 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.
See the doc at: http://piwik.org/docs/setup-auto-archiving/
- Reports for today will be processed at most every %s seconds. You can change this value in Piwik UI > Settings > General Settings.
- Reports for the current week/month/year will be refreshed at most every %s seconds.
- Will process all 1 websites
---------------------------
START
Starting Piwik reports archiving...
Will pre-process for website id = 1, day period, 1 segments
- pre-processing all visits
- pre-processing segment 1/1 actions>=2
Archived website id = 1, period = day, 0 visits in last last52 days, 0 visits today, Time elapsed: %s
Will pre-process for website id = 1, week period, 1 segments
- pre-processing all visits
- pre-processing segment 1/1 actions>=2
Archived website id = 1, period = week, 0 visits in last last133 weeks, 0 visits this week, Time elapsed: %s
Will pre-process for website id = 1, month period, 1 segments
- pre-processing all visits
- pre-processing segment 1/1 actions>=2
Archived website id = 1, period = month, 0 visits in last last52 months, 0 visits this month, Time elapsed: %s
Will pre-process for website id = 1, year period, 1 segments
- pre-processing all visits
- pre-processing segment 1/1 actions>=2
Archived website id = 1, period = year, 0 visits in last last7 years, 0 visits this year, Time elapsed: %s
Archived website id = 1, 8 API requests, Time elapsed: %s [1/1 done]
Done archiving!
---------------------------
SUMMARY
Total visits for today across archived websites: 0
Archived today's reports for 1 websites
Archived week/month/year for 1 websites
Skipped 0 websites: no new visit since the last script execution
Skipped 0 websites day archiving: existing daily reports are less than 150 seconds old
Skipped 0 websites week/month/year archiving: existing periods reports are less than 3600 seconds old
Total API requests: 8
done: 1/1 100%, 0 vtoday, 1 wtoday, 1 wperiods, 8 req, %s ms, no error
Time elapsed: %s
LOG;
$this->assertStringMatchesFormat($expected, $logger->output);
}
}
class TestCronArchive extends CronArchive
{
protected function checkPiwikUrlIsValid()
{
}
protected function initPiwikHost($piwikUrl = false)
{
}
}
0% ou .
You are about to add 0 people to the discussion. Proceed with caution.
Terminez d'abord l'édition de ce message.
Veuillez vous inscrire ou vous pour commenter