MDL-38212 cron: display time and memory usage before each task.

This helps diagnose problems.

Also, call gc_collect_cycles between tasks, which may reduce the
frequency of out-of-memory errors.
This commit is contained in:
Tim Hunt 2013-02-26 14:01:18 +00:00
parent 8673a98d1d
commit 658b9372ee
7 changed files with 40 additions and 1 deletions

View File

@ -106,6 +106,7 @@ abstract class backup_cron_automated_helper {
if ($status) {
mtrace('Running required automated backups...');
cron_trace_time_and_memory();
// This could take a while!
@set_time_limit(0);

View File

@ -3110,6 +3110,7 @@ function calendar_cron() {
require_once($CFG->libdir.'/bennu/bennu.inc.php');
mtrace('Updating calendar subscriptions:');
cron_trace_time_and_memory();
$time = time();
$subscriptions = $DB->get_records_sql('SELECT * FROM {event_subscriptions} WHERE pollinterval > 0 AND lastupdated + pollinterval < ?', array($time));

View File

@ -61,7 +61,7 @@ function cron_run() {
// Start output log
$timenow = time();
mtrace("Server Time: ".date('r',$timenow)."\n\n");
mtrace("Server Time: ".date('r', $timenow)."\n\n");
// Run cleanup core cron jobs, but not every time since they aren't too important.
@ -71,6 +71,7 @@ function cron_run() {
$random100 = rand(0,100);
if ($random100 < 20) { // Approximately 20% of the time.
mtrace("Running clean-up tasks...");
cron_trace_time_and_memory();
// Delete users who haven't confirmed within required period
if (!empty($CFG->deleteunconfirmed)) {
@ -193,6 +194,7 @@ function cron_run() {
// because it might add users that will be needed in enrol plugins
$auths = get_enabled_auth_plugins();
mtrace("Running auth crons if required...");
cron_trace_time_and_memory();
foreach ($auths as $auth) {
$authplugin = get_auth_plugin($auth);
if (method_exists($authplugin, 'cron')) {
@ -241,6 +243,7 @@ function cron_run() {
continue;
}
mtrace("Running cron for enrol_$ename...");
cron_trace_time_and_memory();
$enrol->cron();
$enrol->set_config('lastcron', time());
}
@ -257,6 +260,7 @@ function cron_run() {
$cron_function = $mod->name."_cron";
if (function_exists($cron_function)) {
mtrace("Processing module function $cron_function ...", '');
cron_trace_time_and_memory();
$pre_dbqueries = null;
$pre_dbqueries = $DB->perf_get_queries();
$pre_time = microtime(1);
@ -290,6 +294,7 @@ function cron_run() {
$blockobj = new $classname;
if (method_exists($blockobj,'cron')) {
mtrace("Processing cron function for ".$block->name.'....','');
cron_trace_time_and_memory();
if ($blockobj->cron()) {
$DB->set_field('block', 'lastcron', $timenow, array('id'=>$block->id));
}
@ -310,11 +315,13 @@ function cron_run() {
mtrace('Starting main gradebook job...');
cron_trace_time_and_memory();
grade_cron();
mtrace('done.');
mtrace('Starting processing the event queue...');
cron_trace_time_and_memory();
events_cron();
mtrace('done.');
@ -322,6 +329,7 @@ function cron_run() {
if ($CFG->enablecompletion) {
// Completion cron
mtrace('Starting the completion cron...');
cron_trace_time_and_memory();
require_once($CFG->dirroot.'/completion/cron.php');
completion_cron();
mtrace('done');
@ -331,6 +339,7 @@ function cron_run() {
if ($CFG->enableportfolios) {
// Portfolio cron
mtrace('Starting the portfolio cron...');
cron_trace_time_and_memory();
require_once($CFG->libdir . '/portfoliolib.php');
portfolio_cron();
mtrace('done');
@ -362,6 +371,7 @@ function cron_run() {
if (!empty($CFG->enableblogs) && $CFG->useexternalblogs) {
require_once($CFG->dirroot . '/blog/lib.php');
mtrace("Fetching external blog entries...", '');
cron_trace_time_and_memory();
$sql = "timefetched < ? OR timefetched = 0";
$externalblogs = $DB->get_records_select('blog_external', $sql, array(time() - $CFG->externalblogcrontime));
@ -375,6 +385,7 @@ function cron_run() {
require_once($CFG->dirroot . '/blog/lib.php');
// delete entries whose contextids no longer exists
mtrace("Deleting blog associations linked to non-existent contexts...", '');
cron_trace_time_and_memory();
$DB->delete_records_select('blog_association', 'contextid NOT IN (SELECT id FROM {context})');
mtrace('done.');
}
@ -382,6 +393,7 @@ function cron_run() {
// Run question bank clean-up.
mtrace("Starting the question bank cron...", '');
cron_trace_time_and_memory();
require_once($CFG->libdir . '/questionlib.php');
question_bank::cron();
mtrace('done.');
@ -389,6 +401,7 @@ function cron_run() {
//Run registration updated cron
mtrace(get_string('siteupdatesstart', 'hub'));
cron_trace_time_and_memory();
require_once($CFG->dirroot . '/' . $CFG->admin . '/registration/lib.php');
$registrationmanager = new registration_manager();
$registrationmanager->cron();
@ -404,6 +417,7 @@ function cron_run() {
//cleanup old session linked tokens
//deletes the session linked tokens that are over a day old.
mtrace("Deleting session linked tokens more than one day old...", '');
cron_trace_time_and_memory();
$DB->delete_records_select('external_tokens', 'lastaccess < :onedayago AND tokentype = :tokentype',
array('onedayago' => time() - DAYSECS, 'tokentype' => EXTERNAL_TOKEN_EMBEDDED));
mtrace('done.');
@ -475,6 +489,8 @@ function cron_run() {
mtrace("Cron script completed correctly");
gc_collect_cycles();
mtrace('Cron completed at ' . date('H:i:s') . '. Memory used ' . display_size(memory_get_usage()) . '.');
$difftime = microtime_diff($starttime, microtime());
mtrace("Execution took ".$difftime." seconds");
}
@ -527,6 +543,7 @@ function cron_execute_plugin_type($plugintype, $description = null) {
}
mtrace('Processing cron function for ' . $component . '...');
cron_trace_time_and_memory();
$pre_dbqueries = $DB->perf_get_queries();
$pre_time = microtime(true);
@ -605,6 +622,15 @@ function cron_bc_hack_plugin_functions($plugintype, $plugins) {
return $plugins;
}
/**
* Output some standard information during cron runs. Specifically current time
* and memory usage. This method also does gc_collect_cycles() (before displaying
* memory usage) to try to help PHP manage memory better.
*/
function cron_trace_time_and_memory() {
gc_collect_cycles();
mtrace('... started ' . date('H:i:s') . '. Current memory use ' . display_size(memory_get_usage()) . '.');
}
/**
* Notify admin users or admin user of any failed logins (since last notification).

View File

@ -2004,6 +2004,7 @@ class file_storage {
// find out all stale draft areas (older than 4 days) and purge them
// those are identified by time stamp of the /. root dir
mtrace('Deleting old draft files... ', '');
cron_trace_time_and_memory();
$old = time() - 60*60*24*4;
$sql = "SELECT *
FROM {files}
@ -2019,6 +2020,7 @@ class file_storage {
// remove orphaned preview files (that is files in the core preview filearea without
// the existing original file)
mtrace('Deleting orphaned preview files... ', '');
cron_trace_time_and_memory();
$sql = "SELECT p.*
FROM {files} p
LEFT JOIN {files} o ON (p.filename = o.contenthash)
@ -2041,6 +2043,7 @@ class file_storage {
require_once($CFG->libdir.'/filelib.php');
// Delete files that are associated with a context that no longer exists.
mtrace('Cleaning up files from deleted contexts... ', '');
cron_trace_time_and_memory();
$sql = "SELECT DISTINCT f.contextid
FROM {files} f
LEFT OUTER JOIN {context} c ON f.contextid = c.id
@ -2056,6 +2059,7 @@ class file_storage {
mtrace('done.');
mtrace('Deleting trash files... ', '');
cron_trace_time_and_memory();
fulldelete($this->trashdir);
set_config('fileslastcleanup', time());
mtrace('done.');

View File

@ -171,6 +171,8 @@ function plagiarism_cron() {
}
$plagiarismplugins = plagiarism_load_available_plugins();
foreach($plagiarismplugins as $plugin => $dir) {
mtrace('Processing cron function for plagiarism_plugin_' . $plugin . '...', '');
cron_trace_time_and_memory();
require_once($dir.'/lib.php');
$plagiarismclass = "plagiarism_plugin_$plugin";
$plagiarismplugin = new $plagiarismclass;

View File

@ -809,6 +809,7 @@ class available_update_checker {
$start = mktime(1, 0, 0, date('n', $now), date('j', $now), date('Y', $now)); // 01:00 AM today local time
if ($now > $start + $offset) {
$this->cron_mtrace('Regular daily check for available updates ... ', '');
cron_trace_time_and_memory();
$this->cron_execute();
return;
}

View File

@ -180,6 +180,7 @@ function stats_cron_daily($maxdays=1) {
$defaultfproleid = (int)$CFG->defaultfrontpageroleid;
mtrace("Running daily statistics gathering, starting at $timestart:");
cron_trace_time_and_memory();
$days = 0;
$total = 0;
@ -672,6 +673,7 @@ function stats_cron_weekly() {
$DB->delete_records_select('stats_user_weekly', "timeend > $timestart");
mtrace("Running weekly statistics gathering, starting at $timestart:");
cron_trace_time_and_memory();
$weeks = 0;
while ($now > $nextstartweek) {
@ -814,6 +816,7 @@ function stats_cron_monthly() {
mtrace("Running monthly statistics gathering, starting at $timestart:");
cron_trace_time_and_memory();
$months = 0;
while ($now > $nextstartmonth) {
@ -1074,6 +1077,7 @@ function stats_get_next_month_start($time) {
function stats_clean_old() {
global $DB;
mtrace("Running stats cleanup tasks...");
cron_trace_time_and_memory();
$deletebefore = stats_get_base_monthly();
// delete dailies older than 3 months (to be safe)