diff --git a/admin/classes/task_log_table.php b/admin/classes/task_log_table.php index 949e757422e..673e9a18ca4 100644 --- a/admin/classes/task_log_table.php +++ b/admin/classes/task_log_table.php @@ -57,6 +57,8 @@ class task_log_table extends \table_sql { 'userid' => get_string('user', 'admin'), 'timestart' => get_string('task_starttime', 'admin'), 'duration' => get_string('task_duration', 'admin'), + 'hostname' => get_string('hostname', 'tool_task'), + 'pid' => get_string('pid', 'tool_task'), 'db' => get_string('task_dbstats', 'admin'), 'result' => get_string('task_result', 'admin'), 'actions' => '', @@ -132,6 +134,7 @@ class task_log_table extends \table_sql { $sql = "SELECT tl.id, tl.type, tl.component, tl.classname, tl.userid, tl.timestart, tl.timeend, + tl.hostname, tl.pid, tl.dbreads, tl.dbwrites, tl.result, tl.dbreads + tl.dbwrites AS db, tl.timeend - tl.timestart AS duration, diff --git a/admin/cli/scheduled_task.php b/admin/cli/scheduled_task.php index f825f46da35..bd3ad0ed7b5 100644 --- a/admin/cli/scheduled_task.php +++ b/admin/cli/scheduled_task.php @@ -121,6 +121,8 @@ if ($execute = $options['execute']) { exit(1); } + \core\task\manager::scheduled_task_starting($task); + // Increase memory limit. raise_memory_limit(MEMORY_EXTRA); diff --git a/admin/tool/task/lang/en/tool_task.php b/admin/tool/task/lang/en/tool_task.php index 299603f3f89..797f2f1ce43 100644 --- a/admin/tool/task/lang/en/tool_task.php +++ b/admin/tool/task/lang/en/tool_task.php @@ -45,8 +45,10 @@ $string['enablerunnow'] = 'Allow \'Run now\' for scheduled tasks'; $string['enablerunnow_desc'] = 'Allows administrators to run a single scheduled task immediately, rather than waiting for it to run as scheduled. The feature requires \'Path to PHP CLI\' (pathtophp) to be set in System paths. The task runs on the web server, so you may wish to disable this feature to avoid potential performance issues.'; $string['faildelay'] = 'Fail delay'; $string['fromcomponent'] = 'From component: {$a}'; +$string['hostname'] = 'Host name'; $string['lastruntime'] = 'Last run'; $string['nextruntime'] = 'Next run'; +$string['pid'] = 'PID'; $string['plugindisabled'] = 'Plugin disabled'; $string['pluginname'] = 'Scheduled task configuration'; $string['resettasktodefaults'] = 'Reset task schedule to defaults'; diff --git a/lib/classes/task/database_logger.php b/lib/classes/task/database_logger.php index 4e25171a647..d1978fd2423 100644 --- a/lib/classes/task/database_logger.php +++ b/lib/classes/task/database_logger.php @@ -75,6 +75,8 @@ class database_logger implements task_logger { 'dbwrites' => $dbwrites, 'result' => (int) $failed, 'output' => file_get_contents($logpath), + 'hostname' => $task->get_hostname(), + 'pid' => $task->get_pid(), ]; if (is_a($task, adhoc_task::class) && $userid = $task->get_userid()) { diff --git a/lib/classes/task/manager.php b/lib/classes/task/manager.php index 552cd49eeb1..aebdc443358 100644 --- a/lib/classes/task/manager.php +++ b/lib/classes/task/manager.php @@ -255,6 +255,9 @@ class manager { $record->dayofweek = $task->get_day_of_week(); $record->month = $task->get_month(); $record->disabled = $task->get_disabled(); + $record->timestarted = $task->get_timestarted(); + $record->hostname = $task->get_hostname(); + $record->pid = $task->get_pid(); return $record; } @@ -276,6 +279,9 @@ class manager { $record->customdata = $task->get_custom_data_as_string(); $record->userid = $task->get_userid(); $record->timecreated = time(); + $record->timestarted = $task->get_timestarted(); + $record->hostname = $task->get_hostname(); + $record->pid = $task->get_pid(); return $record; } @@ -313,6 +319,15 @@ class manager { if (isset($record->userid)) { $task->set_userid($record->userid); } + if (isset($record->timestarted)) { + $task->set_timestarted($record->timestarted); + } + if (isset($record->hostname)) { + $task->set_hostname($record->hostname); + } + if (isset($record->pid)) { + $task->set_pid($record->pid); + } return $task; } @@ -367,6 +382,15 @@ class manager { if (isset($record->disabled)) { $task->set_disabled($record->disabled); } + if (isset($record->timestarted)) { + $task->set_timestarted($record->timestarted); + } + if (isset($record->hostname)) { + $task->set_hostname($record->hostname); + } + if (isset($record->pid)) { + $task->set_pid($record->pid); + } return $task; } @@ -709,6 +733,9 @@ class manager { */ public static function adhoc_task_failed(adhoc_task $task) { global $DB; + // Finalise the log output. + logmanager::finalise_log(true); + $delay = $task->get_fail_delay(); // Reschedule task with exponential fall off for failing tasks. @@ -724,6 +751,9 @@ class manager { } // Reschedule and then release the locks. + $task->set_timestarted(); + $task->set_hostname(); + $task->set_pid(); $task->set_next_run_time(time() + $delay); $task->set_fail_delay($delay); $record = self::record_from_adhoc_task($task); @@ -734,9 +764,31 @@ class manager { $task->get_cron_lock()->release(); } $task->get_lock()->release(); + } - // Finalise the log output. - logmanager::finalise_log(true); + /** + * Records that a adhoc task is starting to run. + * + * @param adhoc_task $task Task that is starting + * @param int $time Start time (leave blank for now) + * @throws \dml_exception + * @throws \coding_exception + */ + public static function adhoc_task_starting(adhoc_task $task, int $time = 0) { + global $DB; + $pid = (int)getmypid(); + $hostname = (string)gethostname(); + + if (empty($time)) { + $time = time(); + } + + $task->set_timestarted($time); + $task->set_hostname($hostname); + $task->set_pid($pid); + + $record = self::record_from_adhoc_task($task); + $DB->update_record('task_adhoc', $record); } /** @@ -749,6 +801,9 @@ class manager { // Finalise the log output. logmanager::finalise_log(); + $task->set_timestarted(); + $task->set_hostname(); + $task->set_pid(); // Delete the adhoc task record - it is finished. $DB->delete_records('task_adhoc', array('id' => $task->get_id())); @@ -768,6 +823,8 @@ class manager { */ public static function scheduled_task_failed(scheduled_task $task) { global $DB; + // Finalise the log output. + logmanager::finalise_log(true); $delay = $task->get_fail_delay(); @@ -783,20 +840,24 @@ class manager { $delay = 86400; } + $task->set_timestarted(); + $task->set_hostname(); + $task->set_pid(); + $classname = self::get_canonical_class_name($task); $record = $DB->get_record('task_scheduled', array('classname' => $classname)); $record->nextruntime = time() + $delay; $record->faildelay = $delay; + $record->timestarted = null; + $record->hostname = null; + $record->pid = null; $DB->update_record('task_scheduled', $record); if ($task->is_blocking()) { $task->get_cron_lock()->release(); } $task->get_lock()->release(); - - // Finalise the log output. - logmanager::finalise_log(true); } /** @@ -816,6 +877,34 @@ class manager { $DB->update_record('task_scheduled', $record); } + /** + * Records that a scheduled task is starting to run. + * + * @param scheduled_task $task Task that is starting + * @param int $time Start time (0 = current) + * @throws \dml_exception If the task doesn't exist + */ + public static function scheduled_task_starting(scheduled_task $task, int $time = 0) { + global $DB; + $pid = (int)getmypid(); + $hostname = (string)gethostname(); + + if (!$time) { + $time = time(); + } + + $task->set_timestarted($time); + $task->set_hostname($hostname); + $task->set_pid($pid); + + $classname = self::get_canonical_class_name($task); + $record = $DB->get_record('task_scheduled', ['classname' => $classname], '*', MUST_EXIST); + $record->timestarted = $time; + $record->hostname = $hostname; + $record->pid = $pid; + $DB->update_record('task_scheduled', $record); + } + /** * This function indicates that a scheduled task was completed successfully and should be rescheduled. * @@ -826,6 +915,9 @@ class manager { // Finalise the log output. logmanager::finalise_log(); + $task->set_timestarted(); + $task->set_hostname(); + $task->set_pid(); $classname = self::get_canonical_class_name($task); $record = $DB->get_record('task_scheduled', array('classname' => $classname)); @@ -833,6 +925,9 @@ class manager { $record->lastruntime = time(); $record->faildelay = 0; $record->nextruntime = $task->get_next_scheduled_time(); + $record->timestarted = null; + $record->hostname = null; + $record->pid = null; $DB->update_record('task_scheduled', $record); } @@ -844,6 +939,47 @@ class manager { $task->get_lock()->release(); } + /** + * Gets a list of currently-running tasks. + * + * @param string $sort Sorting method + * @return array Array of scheduled and adhoc tasks + * @throws \dml_exception + */ + public static function get_running_tasks($sort = ''): array { + global $DB; + if (empty($sort)) { + $sort = 'timestarted ASC, classname ASC'; + } + $params = ['now1' => time(), 'now2' => time()]; + + $sql = "SELECT subquery.* + FROM (SELECT concat('s', ts.id) as uniqueid, + ts.id, + 'scheduled' as type, + ts.classname, + (:now1 - ts.timestarted) as time, + ts.timestarted, + ts.hostname, + ts.pid + FROM {task_scheduled} ts + WHERE ts.timestarted IS NOT NULL + UNION ALL + SELECT concat('a', ta.id) as uniqueid, + ta.id, + 'adhoc' as type, + ta.classname, + (:now2 - ta.timestarted) as time, + ta.timestarted, + ta.hostname, + ta.pid + FROM {task_adhoc} ta + WHERE ta.timestarted IS NOT NULL) subquery + ORDER BY " . $sort; + + return $DB->get_records_sql($sql, $params); + } + /** * This function is used to indicate that any long running cron processes should exit at the * next opportunity and restart. This is because something (e.g. DB changes) has changed and diff --git a/lib/classes/task/task_base.php b/lib/classes/task/task_base.php index 05e68a5b36a..bffd73682d7 100644 --- a/lib/classes/task/task_base.php +++ b/lib/classes/task/task_base.php @@ -50,6 +50,15 @@ abstract class task_base { /** @var int $nextruntime - When this task is due to run next */ private $nextruntime = 0; + /** @var int $timestarted - When this task was started */ + private $timestarted = null; + + /** @var string $hostname - Hostname where this task was started and PHP process ID */ + private $hostname = null; + + /** @var int $pid - PHP process ID that is running the task */ + private $pid = null; + /** * Set the current lock for this task. * @param \core\lock\lock $lock @@ -151,4 +160,52 @@ abstract class task_base { * Throw exceptions on errors (the job will be retried). */ public abstract function execute(); + + /** + * Setter for $timestarted. + * @param int $timestarted + */ + public function set_timestarted($timestarted = null) { + $this->timestarted = $timestarted; + } + + /** + * Getter for $timestarted. + * @return int + */ + public function get_timestarted() { + return $this->timestarted; + } + + /** + * Setter for $hostname. + * @param string $hostname + */ + public function set_hostname($hostname = null) { + $this->hostname = $hostname; + } + + /** + * Getter for $hostname. + * @return string + */ + public function get_hostname() { + return $this->hostname; + } + + /** + * Setter for $pid. + * @param int $pid + */ + public function set_pid($pid = null) { + $this->pid = $pid; + } + + /** + * Getter for $pid. + * @return int + */ + public function get_pid() { + return $this->pid; + } } diff --git a/lib/cronlib.php b/lib/cronlib.php index 74a83d5b1d7..4190bf2892d 100644 --- a/lib/cronlib.php +++ b/lib/cronlib.php @@ -237,6 +237,7 @@ function cron_run_adhoc_tasks(int $timenow, $keepalive = 0, $checklimits = true) function cron_run_inner_scheduled_task(\core\task\task_base $task) { global $CFG, $DB; + \core\task\manager::scheduled_task_starting($task); \core\task\logmanager::start_logging($task); $fullname = $task->get_name() . ' (' . get_class($task) . ')'; @@ -295,6 +296,7 @@ function cron_run_inner_scheduled_task(\core\task\task_base $task) { function cron_run_inner_adhoc_task(\core\task\adhoc_task $task) { global $DB, $CFG; + \core\task\manager::adhoc_task_starting($task); \core\task\logmanager::start_logging($task); mtrace("Execute adhoc task: " . get_class($task)); diff --git a/lib/db/install.xml b/lib/db/install.xml index e50236eeb86..31d1bcebfee 100644 --- a/lib/db/install.xml +++ b/lib/db/install.xml @@ -3352,6 +3352,9 @@ + + + @@ -3371,6 +3374,9 @@ + + + @@ -3393,6 +3399,8 @@ + + diff --git a/lib/db/upgrade.php b/lib/db/upgrade.php index bb640d480af..a6e278a40c1 100644 --- a/lib/db/upgrade.php +++ b/lib/db/upgrade.php @@ -2575,5 +2575,51 @@ function xmldb_main_upgrade($oldversion) { upgrade_main_savepoint(true, 2020081400.02); } + if ($oldversion < 2020082200.01) { + // Define fields to be added to task_scheduled. + $table = new xmldb_table('task_scheduled'); + $field = new xmldb_field('timestarted', XMLDB_TYPE_INTEGER, '10', null, null, null, null, 'disabled'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + $field = new xmldb_field('hostname', XMLDB_TYPE_CHAR, '255', null, null, null, null, 'timestarted'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + $field = new xmldb_field('pid', XMLDB_TYPE_INTEGER, '10', null, null, null, null, 'hostname'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + + // Define fields to be added to task_adhoc. + $table = new xmldb_table('task_adhoc'); + $field = new xmldb_field('timestarted', XMLDB_TYPE_INTEGER, '10', null, null, null, null, 'blocking'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + $field = new xmldb_field('hostname', XMLDB_TYPE_CHAR, '255', null, null, null, null, 'timestarted'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + $field = new xmldb_field('pid', XMLDB_TYPE_INTEGER, '10', null, null, null, null, 'hostname'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + + // Define fields to be added to task_log. + $table = new xmldb_table('task_log'); + $field = new xmldb_field('hostname', XMLDB_TYPE_CHAR, '255', null, null, null, null, 'output'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + $field = new xmldb_field('pid', XMLDB_TYPE_INTEGER, '10', null, null, null, null, 'hostname'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + + // Main savepoint reached. + upgrade_main_savepoint(true, 2020082200.01); + } + return true; } diff --git a/lib/tests/task_running_test.php b/lib/tests/task_running_test.php new file mode 100644 index 00000000000..f533938c595 --- /dev/null +++ b/lib/tests/task_running_test.php @@ -0,0 +1,185 @@ +. + +/** + * This file contains unit tests for the 'task running' data. + * + * @package core + * @copyright 2019 The Open University + * @copyright 2020 Mikhail Golenkov + * @license http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later + */ + +namespace core\task; + +defined('MOODLE_INTERNAL') || die(); + +require_once(__DIR__ . '/fixtures/task_fixtures.php'); + +/** + * This file contains unit tests for the 'task running' data. + * + * @copyright 2019 The Open University + * @license http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later + */ +class task_running_testcase extends \advanced_testcase { + + /** + * Test for ad-hoc tasks. + */ + public function test_adhoc_task_running() { + $this->resetAfterTest(); + + // Specify lock factory. The reason is that Postgres locks don't work within a single + // process (i.e. if you try to get a lock that you already locked, it will just let you) + // which is usually OK but not here where we are simulating running two tasks at once in + // the same process. + set_config('lock_factory', '\core\lock\db_record_lock_factory'); + + // Create and queue 2 new ad-hoc tasks. + $task1 = new adhoc_test_task(); + $task1->set_next_run_time(time() - 20); + manager::queue_adhoc_task($task1); + $task2 = new adhoc_test2_task(); + $task2->set_next_run_time(time() - 10); + manager::queue_adhoc_task($task2); + + // Check no tasks are marked running. + $running = manager::get_running_tasks(); + $this->assertEmpty($running); + + // Mark the first task running and check results. Because adhoc tasks are pseudo-randomly + // shuffled, it is safer if we can cope with either of them being first. + $before = time(); + $next1 = manager::get_next_adhoc_task(time()); + $task2goesfirst = get_class($next1) === 'core\task\adhoc_test2_task'; + manager::adhoc_task_starting($next1); + $after = time(); + $running = manager::get_running_tasks(); + $this->assertCount(1, $running); + foreach ($running as $item) { + $this->assertEquals('adhoc', $item->type); + $this->assertEquals($task2goesfirst ? '\core\task\adhoc_test2_task' : '\core\task\adhoc_test_task', + $item->classname); + $this->assertLessThanOrEqual($after, $item->timestarted); + $this->assertGreaterThanOrEqual($before, $item->timestarted); + } + + // Mark the second task running and check results. + $next2 = manager::get_next_adhoc_task(time()); + manager::adhoc_task_starting($next2); + $running = manager::get_running_tasks(); + $this->assertCount(2, $running); + if ($task2goesfirst) { + $item = array_shift($running); + $this->assertEquals('\core\task\adhoc_test2_task', $item->classname); + $item = array_shift($running); + $this->assertEquals('\core\task\adhoc_test_task', $item->classname); + } else { + $item = array_shift($running); + $this->assertEquals('\core\task\adhoc_test_task', $item->classname); + $item = array_shift($running); + $this->assertEquals('\core\task\adhoc_test2_task', $item->classname); + } + + // Second task completes successfully. + manager::adhoc_task_complete($next2); + $running = manager::get_running_tasks(); + $this->assertCount(1, $running); + foreach ($running as $item) { + $this->assertEquals($task2goesfirst ? '\core\task\adhoc_test2_task' : '\core\task\adhoc_test_task', + $item->classname); + } + + // First task fails. + manager::adhoc_task_failed($next1); + $running = manager::get_running_tasks(); + $this->assertCount(0, $running); + } + + /** + * Test for scheduled tasks. + */ + public function test_scheduled_task_running() { + global $DB; + $this->resetAfterTest(); + + // Check no tasks are marked running. + $running = manager::get_running_tasks(); + $this->assertEmpty($running); + + // Disable all the tasks, except two, and set those two due to run. + $DB->set_field_select('task_scheduled', 'disabled', 1, 'classname != ? AND classname != ?', + ['\core\task\session_cleanup_task', '\core\task\file_trash_cleanup_task']); + $DB->set_field('task_scheduled', 'nextruntime', 1, + ['classname' => '\core\task\session_cleanup_task']); + $DB->set_field('task_scheduled', 'nextruntime', 1, + ['classname' => '\core\task\file_trash_cleanup_task']); + $DB->set_field('task_scheduled', 'lastruntime', time() - 1000, + ['classname' => '\core\task\session_cleanup_task']); + $DB->set_field('task_scheduled', 'lastruntime', time() - 500, + ['classname' => '\core\task\file_trash_cleanup_task']); + + // Get the first task and start it off. + $next1 = manager::get_next_scheduled_task(time()); + $before = time(); + manager::scheduled_task_starting($next1); + $after = time(); + $running = manager::get_running_tasks(); + $this->assertCount(1, $running); + foreach ($running as $item) { + $this->assertLessThanOrEqual($after, $item->timestarted); + $this->assertGreaterThanOrEqual($before, $item->timestarted); + $this->assertEquals('\core\task\session_cleanup_task', $item->classname); + } + + // Mark the second task running and check results. We have to change the times so the other + // one comes up first, otherwise it repeats the same one. + $DB->set_field('task_scheduled', 'lastruntime', time() - 1500, + ['classname' => '\core\task\file_trash_cleanup_task']); + + // Make sure that there is a time gap between task to sort them as expected. + sleep(1); + $next2 = manager::get_next_scheduled_task(time()); + manager::scheduled_task_starting($next2); + + // Check default sorting by timestarted. + $running = manager::get_running_tasks(); + $this->assertCount(2, $running); + $item = array_shift($running); + $this->assertEquals('\core\task\session_cleanup_task', $item->classname); + $item = array_shift($running); + $this->assertEquals('\core\task\file_trash_cleanup_task', $item->classname); + + // Check sorting by time ASC. + $running = manager::get_running_tasks('time ASC'); + $this->assertCount(2, $running); + $item = array_shift($running); + $this->assertEquals('\core\task\file_trash_cleanup_task', $item->classname); + $item = array_shift($running); + $this->assertEquals('\core\task\session_cleanup_task', $item->classname); + + // Complete the file trash one. + manager::scheduled_task_complete($next2); + $running = manager::get_running_tasks(); + $this->assertCount(1, $running); + + // Other task fails. + manager::scheduled_task_failed($next1); + $running = manager::get_running_tasks(); + $this->assertCount(0, $running); + } +} diff --git a/lib/upgrade.txt b/lib/upgrade.txt index 60a675eba42..fef4e504ee8 100644 --- a/lib/upgrade.txt +++ b/lib/upgrade.txt @@ -36,6 +36,9 @@ information provided here is intended especially for developers. a callback function instead of an array of options. * Admin setting admin_setting_configselect now supports validating the selection by supplying a callback function. +* The task system has new functions adhoc_task_starting() and scheduled_task_starting() which must + be called before executing a task, and a new function \core\task\manager::get_running_tasks() + returns information about currently-running tasks. === 3.9 === * Following function has been deprecated, please use \core\task\manager::run_from_cli(). diff --git a/version.php b/version.php index bd28dd4e187..0ba90d33d16 100644 --- a/version.php +++ b/version.php @@ -29,7 +29,7 @@ defined('MOODLE_INTERNAL') || die(); -$version = 2020082200.00; // YYYYMMDD = weekly release date of this DEV branch. +$version = 2020082200.01; // YYYYMMDD = weekly release date of this DEV branch. // RR = release increments - 00 in DEV branches. // .XX = incremental changes. $release = '3.10dev (Build: 20200822)';// Human-friendly version name