@mattab opened this issue on April 19th 2015

Follows up #7602 - The goal of this issue is to make minor changes to log output to keep logs small and readable.

Current output looks like:

INFO CoreAdminHome[2015-04-19 23:43:35] Starting Scheduled tasks... 
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\CoreAdminHome\Tasks.purgeOutdatedArchives...
INFO CoreAdminHome[2015-04-19 23:43:35] Purging archives in 84 archive tables.
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.133s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\ExamplePlugin\Tasks.myTaskWithParam_anystring...
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.000s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\ExamplePlugin\Tasks.myTask...
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.000s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\ExamplePlugin\Tasks.myTask...
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.000s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\ExamplePlugin\Tasks.myTask...
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.000s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\ExamplePlugin\Tasks.myTask...
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.000s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\ExamplePlugin\Tasks.myTaskWithParam_anystring...
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.000s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\UsersManager\Tasks.setUserDefaultReportPreference...
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.005s
INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: executing task Piwik\Plugins\ScheduledReports\API.sendReport_1...
WARNING ScheduledReports[2015-04-19 23:43:36] Preventing the same scheduled report from being sent again (report #1 for period "Week 6 April - 12 April 2015")
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.624s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\TrafficMonitor\Tasks.doCacheTotalActionsNbFromRawData...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.050s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\CoreAdminHome\Tasks.purgeInvalidatedArchives...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.001s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.deleteReportData...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.004s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\PrivacyManager\Tasks.deleteLogData...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.003s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\CorePluginsAdmin\Tasks.clearAllCacheEntries...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.001s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\CorePluginsAdmin\Tasks.sendNotificationIfUpdatesAvailable...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.001s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\CoreAdminHome\Tasks.optimizeArchiveTable...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.089s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\ExamplePlugin\Tasks.myTask...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.000s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\UserCountry\GeoIPAutoUpdater.update...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.037s
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: executing task Piwik\Plugins\CoreUpdater\Tasks.sendNotificationIfUpdateAvailable...
INFO CoreAdminHome[2015-04-19 23:43:36] Scheduler: finished. Time elapsed: 0.001s
INFO CoreAdminHome[2015-04-19 23:43:36] done
Piwik\Plugins\CoreAdminHome\Tasks.purgeOutdatedArchives - Time elapsed: 0.133s
Piwik\Plugins\ExamplePlugin\Tasks.myTaskWithParam_anystring - Time elapsed: 0.000s
Piwik\Plugins\ExamplePlugin\Tasks.myTask - Time elapsed: 0.000s
Piwik\Plugins\ExamplePlugin\Tasks.myTask - Time elapsed: 0.000s
Piwik\Plugins\ExamplePlugin\Tasks.myTask - Time elapsed: 0.000s
Piwik\Plugins\ExamplePlugin\Tasks.myTask - Time elapsed: 0.000s
Piwik\Plugins\ExamplePlugin\Tasks.myTaskWithParam_anystring - Time elapsed: 0.000s
Piwik\Plugins\UsersManager\Tasks.setUserDefaultReportPreference - Time elapsed: 0.004s
Piwik\Plugins\ScheduledReports\API.sendReport_1 - Time elapsed: 0.623s
Piwik\Plugins\TrafficMonitor\Tasks.doCacheTotalActionsNbFromRawData - Time elapsed: 0.049s
Piwik\Plugins\CoreAdminHome\Tasks.purgeInvalidatedArchives - Time elapsed: 0.001s
Piwik\Plugins\PrivacyManager\Tasks.deleteReportData - Time elapsed: 0.004s
Piwik\Plugins\PrivacyManager\Tasks.deleteLogData - Time elapsed: 0.003s
Piwik\Plugins\CorePluginsAdmin\Tasks.clearAllCacheEntries - Time elapsed: 0.001s
Piwik\Plugins\CorePluginsAdmin\Tasks.sendNotificationIfUpdatesAvailable - Time elapsed: 0.001s
Piwik\Plugins\CoreAdminHome\Tasks.optimizeArchiveTable - Time elapsed: 0.089s
Piwik\Plugins\ExamplePlugin\Tasks.myTask - Time elapsed: 0.000s
Piwik\Plugins\UserCountry\GeoIPAutoUpdater.update - Time elapsed: 0.037s
Piwik\Plugins\CoreUpdater\Tasks.sendNotificationIfUpdateAvailable - Time elapsed: 0.000s

### Tasks

To keep the output simpler we can: - remove INFO CoreAdminHome[2015-04-19 23:43:35] Scheduler: finished. Time elapsed: 0.000s for each task - the summary is displayed at the end anyway - one can find out during script execution how long a task took by looking at the datetime in the log line - when printing out the summary of tasks with the time it took, each line should be prefixed with the standard log line prefix eg. INFO CoreAdminHome[2015-04-19 23:43:35] - currently it is displayed without line prefix eg.

[...]
Piwik\Plugins\ExamplePlugin\Tasks.myTaskWithParam_anystring - Time elapsed: 0.000s
Piwik\Plugins\UsersManager\Tasks.setUserDefaultReportPreference - Time elapsed: 0.004s
Piwik\Plugins\ScheduledReports\API.sendReport_1 - Time elapsed: 0.623s
Piwik\Plugins\TrafficMonitor\Tasks.doCacheTotalActionsNbFromRawData - Time elapsed: 0.049s
Piwik\Plugins\CoreAdminHome\Tasks.purgeInvalidatedArchives - Time elapsed: 0.001s
Piwik\Plugins\PrivacyManager\Tasks.deleteReportData - Time elapsed: 0.004s
Piwik\Plugins\PrivacyManager\Tasks.deleteLogData - Time elapsed: 0.003s
[...]
@diosmosis commented on April 19th 2015

I removed the summary from being printed, it shouldn't appear...

See CronArchive::runScheduledTasks()

@mattab commented on April 20th 2015

it's displayed when I run ./console core:run-scheduled-tasks --force (didn't test in core:archive maybe it's different there?)

@diosmosis commented on April 20th 2015

Ah, ok, I didn't modify core:run-scheduled-tasks. I will remove the summary there too.

@mnapoli commented on April 20th 2015

+1 the idea we discussed with @diosmosis was to keep the Scheduler: finished. Time elapsed: 0.000s lines and remove the summary instead (that way the "finished" lines are just beside the "started" lines).

This issue was closed on April 20th 2015
Powered by GitHub Issue Mirror