diff --git a/admin/classes/task_log_table.php b/admin/classes/task_log_table.php index 949e757422eca..673e9a18ca48c 100644 --- a/admin/classes/task_log_table.php +++ b/admin/classes/task_log_table.php @@ -57,6 +57,8 @@ public function __construct(string $filter = '', int $resultfilter = null) { '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 @@ public function query_db($pagesize, $useinitialsbar = true) { $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 f825f46da3550..bd3ad0ed7b50e 100644 --- a/admin/cli/scheduled_task.php +++ b/admin/cli/scheduled_task.php @@ -121,6 +121,8 @@ 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 299603f3f892c..797f2f1ce43df 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_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 4e25171a64723..d1978fd24238c 100644 --- a/lib/classes/task/database_logger.php +++ b/lib/classes/task/database_logger.php @@ -75,6 +75,8 @@ public static function store_log_for_task(task_base $task, string $logpath, bool '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 552cd49eeb135..aebdc44335857 100644 --- a/lib/classes/task/manager.php +++ b/lib/classes/task/manager.php @@ -255,6 +255,9 @@ public static function record_from_scheduled_task($task) { $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 @@ public static function record_from_adhoc_task($task) { $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 @@ public static function adhoc_task_from_record($record) { 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 @@ public static function scheduled_task_from_record($record, $expandr = true) { 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 @@ public static function get_next_scheduled_task($timestart) { */ 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 @@ public static function adhoc_task_failed(adhoc_task $task) { } // 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 @@ public static function adhoc_task_failed(adhoc_task $task) { $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 @@ public static function adhoc_task_complete(adhoc_task $task) { // 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 @@ public static function adhoc_task_complete(adhoc_task $task) { */ 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 @@ public static function scheduled_task_failed(scheduled_task $task) { $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 @@ public static function clear_fail_delay(scheduled_task $task) { $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 @@ public static function scheduled_task_complete(scheduled_task $task) { // 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 @@ public static function scheduled_task_complete(scheduled_task $task) { $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 @@ public static function scheduled_task_complete(scheduled_task $task) { $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 05e68a5b36a87..bffd73682d74e 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 @@ public function get_fail_delay() { * 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 74a83d5b1d755..4190bf2892d6d 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 e50236eeb867c..31d1bcebfeee3 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 d3acfec7d5027..dd0f687c98de4 100644 --- a/lib/db/upgrade.php +++ b/lib/db/upgrade.php @@ -2575,5 +2575,51 @@ function xmldb_main_upgrade($oldversion) { upgrade_main_savepoint(true, 2021052500.02); } + if ($oldversion < 2021052500.04) { + // 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, 2021052500.04); + } + return true; } diff --git a/lib/tests/task_running_test.php b/lib/tests/task_running_test.php new file mode 100644 index 0000000000000..f533938c59517 --- /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 60a675eba426c..fef4e504ee8a6 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 0d1f7ba627a53..7d5bcfe5844a2 100644 --- a/version.php +++ b/version.php @@ -29,7 +29,7 @@ defined('MOODLE_INTERNAL') || die(); -$version = 2021052500.03; // YYYYMMDD = weekly release date of this DEV branch. +$version = 2021052500.04; // YYYYMMDD = weekly release date of this DEV branch. // RR = release increments - 00 in DEV branches. // .XX = incremental changes. $release = '4.0dev (Build: 20200822)'; // Human-friendly version name