diff --git a/classes/cron_processor.php b/classes/cron_processor.php index b69ed1b..bfdeb1b 100644 --- a/classes/cron_processor.php +++ b/classes/cron_processor.php @@ -28,21 +28,18 @@ * @copyright 2022, Catalyst IT * @license http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later */ -class cron_processor implements processor { +class cron_processor extends processor { /** @var float Timestamp updated after processing each sample */ public $sampletime; - /** @var sample_set A sample set recorded while processing a task */ - public $tasksampleset = null; - - /** @var sample_set A sample set for memory usage recorded while processing a task */ - protected $memoryusagesampleset; - - /** @var int */ - protected $samplems; - - /** @var bool */ - protected static $alreadyprofiling = false; + /** + * Construct the web processor. + */ + public function __construct() { + // Preload config values to avoid DB access during processing. See manager::get_altconnection() for more information. + parent::__construct(); + $this->minduration = (float) get_config('tool_excimer', 'task_min_duration'); + } /** * Initialises the processor @@ -52,18 +49,14 @@ class cron_processor implements processor { public function init(manager $manager) { $this->sampletime = $manager->get_starttime(); - $manager->get_timer()->setCallback(function () use ($manager) { - $this->on_interval($manager); - }); - - // Preload config values to avoid DB access during processing. See manager::get_altconnection() for more information. - $this->samplems = (int) get_config('tool_excimer', 'sample_ms'); + // The callback is triggered when the number of samples reach the maxsamples and when profiler is destroyed. + $manager->get_profiler()->setFlushCallback(function ($log) use ($manager) { + $this->on_interval($log, $manager); + }, $this->maxsamples); \core_shutdown_manager::register_function( function () use ($manager) { - $manager->get_timer()->stop(); $manager->get_profiler()->stop(); - $this->on_interval($manager, true); if ($this->tasksampleset) { $this->process($manager, microtime(true)); } @@ -72,13 +65,21 @@ function () use ($manager) { } /** - * Gets the minimum duration required for a profile to be saved, as seconds. - * - * @return float - * @throws \dml_exception + * Get sampling period of processor + * (used for testing) + * @return int sampling period */ - public function get_min_duration(): float { - return (float) get_config('tool_excimer', 'task_min_duration'); + public function get_sampling_period() { + return $this->samplingperiod; + } + + /** + * Get sample limit of processor + * (used for testing) + * @return int sample_limit + */ + public function get_sample_limit() { + return $this->samplelimit; } /** @@ -92,65 +93,71 @@ public function get_min_duration(): float { * * We then check for a new task with the current sample. * + * @param \ExcimerLog $log * @param manager $manager - * @param bool $isfinal Set to true when this is called during shutdown. */ - public function on_interval(manager $manager, bool $isfinal = false) { + public function on_interval($log, manager $manager) { // We want to prevent doubling up of processing, so skip if an existing process is still executing. // The profile logs will be kept and processed the next time. + self::$logs[] = $log; + $this->logcount += $log->count(); + // Doubling sampling period if it reaches the limit. + if ($this->logcount >= $this->samplelimit) { + $this->on_reach_limit($manager); + $this->logcount = $this->logcount - $this->samplelimit; + } if (self::$alreadyprofiling) { debugging('tool_excimer: starting cron_processor::on_interval when previous call has not yet finished'); - if ($isfinal) { + // The final flush call when profiler is destroyed. + if ($log->count() < $this->samplelimit) { // This should never happen. debugging('tool_excimer: alreadyprofiling is true during final on_interval.'); } return; } self::$alreadyprofiling = true; + foreach (self::$logs as $log) { + $memoryusage = memory_get_usage(); + foreach ($log as $sample) { + $taskname = $this->findtaskname($sample); + $sampletime = $manager->get_starttime() + $sample->getTimestamp(); + + // If there is a task and the current task name is different from the previous, then store the profile. + if ($this->tasksampleset && ($this->tasksampleset->name != $taskname)) { + $profile = $this->process($manager, $this->sampletime); + // Keep an approximate count of each profile. + page_group::record_fuzzy_counts($profile); + $this->tasksampleset = null; + } - $profiler = $manager->get_profiler(); - $log = $profiler->flush(); - $memoryusage = memory_get_usage(); // Record and set initial memory usage at this point. - foreach ($log as $sample) { - $taskname = $this->findtaskname($sample); - $sampletime = $manager->get_starttime() + $sample->getTimestamp(); - - // If there is a task and the current task name is different from the previous, then store the profile. - if ($this->tasksampleset && ($this->tasksampleset->name != $taskname)) { - $profile = $this->process($manager, $this->sampletime); - - // Keep an approximate count of each profile. - page_group::record_fuzzy_counts($profile); - $this->tasksampleset = null; - } - - // If there exists a current task, and the sampleset for it is not created yet, create it. - if ($taskname && ($this->tasksampleset === null)) { - $this->tasksampleset = new sample_set($taskname, $this->sampletime); - $this->memoryusagesampleset = new sample_set($taskname, $this->sampletime); - if ($memoryusage) { // Ensure this only adds the mem usage for the initial base sample due to accuracy. - $this->memoryusagesampleset->add_sample(['sampleindex' => 0, 'value' => $memoryusage]); - $memoryusage = 0; + // If there exists a current task, and the sampleset for it is not created yet, create it. + if ($taskname && ($this->tasksampleset === null)) { + $this->tasksampleset = new sample_set($taskname, $this->sampletime); + $this->memoryusagesampleset = new sample_set($taskname, $this->sampletime); + if ($memoryusage) { // Ensure this only adds the mem usage for the initial base sample due to accuracy. + $this->memoryusagesampleset->add_sample(['sampleindex' => 0, 'value' => $memoryusage]); + $memoryusage = 0; + } } - } - // If the sampleset exists, add the current sample to it. - if ($this->tasksampleset) { - $this->tasksampleset->add_sample($sample); + // If the sampleset exists, add the current sample to it. + if ($this->tasksampleset) { + $this->tasksampleset->add_sample($sample); + + // Add memory usage: + // Note that due to the looping this is probably inaccurate. + $this->memoryusagesampleset->add_sample([ + 'sampleindex' => $this->tasksampleset->total_added() - 1, + 'value' => memory_get_usage(), + ]); + } - // Add memory usage: - // Note that due to the looping this is probably inaccurate. - $this->memoryusagesampleset->add_sample([ - 'sampleindex' => $this->tasksampleset->total_added() + $this->memoryusagesampleset->count() - 1, - 'value' => memory_get_usage(), - ]); + // Instances of task_sample are always created with the previous sample's timestamp. + // So it needs to be saved each loop. + $this->sampletime = $sampletime; } - - // Instances of task_sample are always created with the previous sample's timestamp. - // So it needs to be saved each loop. - $this->sampletime = $sampletime; } - + self::$logs = []; self::$alreadyprofiling = false; } @@ -196,9 +203,10 @@ public function process(manager $manager, float $finishtime): profile { $profile->set('reason', $reasons); $profile->set('finished', (int) $finishtime); $profile->set('memoryusagedatad3', $this->memoryusagesampleset->samples); - $profile->set('flamedatad3', flamed3_node::from_excimer_log_entries($this->tasksampleset->samples)); - $profile->set('numsamples', $this->tasksampleset->count()); - $profile->set('samplerate', $this->tasksampleset->filter_rate() * $this->samplems); + $profile->set('flamedatad3', flamed3_node::from_sample_set_samples($this->tasksampleset->samples)); + $profile->set('numsamples', count($this->tasksampleset->samples)); + $profile->set('numevents', $this->tasksampleset->count()); + $profile->set('samplerate', (int) (($duration * 1000) / $this->tasksampleset->count())); $profile->save_record(); } return $profile; diff --git a/classes/flamed3_node.php b/classes/flamed3_node.php index 19d4be2..74746d2 100644 --- a/classes/flamed3_node.php +++ b/classes/flamed3_node.php @@ -69,18 +69,16 @@ public function add_excimer_trace_tail(array $tail, int $eventcount): void { } /** - * Extracts data from Excimer log entries and converts to a flame node tree, compatible with + * Extracts data from sample set samples and converts to a flame node tree, compatible with * d3-flame-graph. * - * @param iterable $entries + * @param array $samples samples * @return flamed3_node */ - public static function from_excimer_log_entries(iterable $entries): flamed3_node { + public static function from_sample_set_samples(array $samples): flamed3_node { $root = new flamed3_node('root'); - foreach ($entries as $entry) { - $eventcount = $entry->getEventCount(); - $trace = array_reverse($entry->getTrace()); - $root->add_excimer_trace_tail($trace, $eventcount); + foreach ($samples as $sample) { + $root->add_excimer_trace_tail(array_reverse($sample['trace']), $sample['eventcount']); } return $root; } diff --git a/classes/manager.php b/classes/manager.php index 5960440..e1d74b3 100644 --- a/classes/manager.php +++ b/classes/manager.php @@ -43,8 +43,7 @@ class manager { private $processor; /** @var \ExcimerProfiler */ private $profiler; - /** @var \ExcimerTimer */ - private $timer; + /** @var float */ private $starttime; /** @var array */ @@ -113,15 +112,6 @@ public function get_profiler(): \ExcimerProfiler { return $this->profiler; } - /** - * Timer to create events to process samples generated so far. - * - * @return \ExcimerTimer - */ - public function get_timer(): \ExcimerTimer { - return $this->timer; - } - /** * Start time for the script. * @@ -169,29 +159,19 @@ public function __construct(processor $processor) { } /** - * Initialises the manager. Creates and starts the profiler and timer. + * Initialises the manager. Creates and starts the profiler. * * @throws \dml_exception */ public function init() { if (!self::is_testing()) { - script_metadata::init(); - profile_helper::init(); - $sampleperiod = script_metadata::get_sampling_period(); - $timerinterval = script_metadata::get_timer_interval(); - $this->profiler = new \ExcimerProfiler(); $this->profiler->setPeriod($sampleperiod); - - $this->timer = new \ExcimerTimer(); - $this->timer->setPeriod($timerinterval); - $this->starttime = microtime(true); $this->startrusage = getrusage(); $this->profiler->start(); - $this->timer->start(); } } @@ -210,6 +190,8 @@ public function start_processor() { * */ public static function create() { + script_metadata::init(); + profile_helper::init(); if (self::is_cron()) { self::$instance = new manager(new cron_processor()); } else { diff --git a/classes/processor.php b/classes/processor.php index c1ec2f0..03d81e0 100644 --- a/classes/processor.php +++ b/classes/processor.php @@ -33,18 +33,62 @@ * * @package tool_excimer */ -interface processor { +class processor { + /** @var int */ + protected $minduration; + + /** @var sample_set */ + public $tasksampleset; + + /** @var sample_set */ + public $memoryusagesampleset; + + /** @var int */ + protected $samplingperiod; + + /** @var int */ + protected $samplelimit; + + /** @var int */ + protected $maxsamples; + + /** @var int */ + protected $logcount = 0; + + /** @var bool */ + protected static $alreadyprofiling = false; + + /** @var array */ + protected static $logs = []; + + /** + * Construct the processor. + */ + public function __construct() { + // Preload config values to avoid DB access during processing. See manager::get_altconnection() for more information. + $this->samplingperiod = script_metadata::get_sampling_period(); + $this->samplelimit = script_metadata::get_sample_limit(); + $this->maxsamples = script_metadata::get_max_samples(); + } + /** - * Initialises the processor + * Doubling the sampling period when we reach the samples limit * - * @param manager $manager The profiler manager object + * @param manager $manager */ - public function init(manager $manager); + public function on_reach_limit(manager $manager) { + $this->samplingperiod *= 2; + // This will take effect the next time start() is called. + $manager->get_profiler()->setPeriod($this->samplingperiod); + $manager->get_profiler()->start(); + } /** * Gets the minimum duration required for a profile to be saved, as seconds. * * @return float */ - public function get_min_duration(): float; + public function get_min_duration(): float { + return $this->minduration; + } } diff --git a/classes/profile.php b/classes/profile.php index 81902bc..5950273 100644 --- a/classes/profile.php +++ b/classes/profile.php @@ -194,6 +194,7 @@ public function download(): void { * * @param string $json * @return bool|int the id of the imported profile, or false if unsuccessful + * @throws \coding_exception */ public static function import(string $json) { global $DB; @@ -225,7 +226,9 @@ public static function import(string $json) { foreach ($data as $property => $value) { if (isset($value) && !in_array($property, $removeproperties)) { - $profile->set($property, $value); + if (property_exists($profile, $property)) { + $profile->set($property, $value); + } } } @@ -475,6 +478,7 @@ protected static function define_properties(): array { 'versionhash' => ['type' => PARAM_TEXT, 'default' => ''], 'datasize' => ['type' => PARAM_INT, 'default' => 0], 'numsamples' => ['type' => PARAM_INT, 'default' => 0], + 'numevents' => ['type' => PARAM_INT, 'default' => 0], 'samplerate' => ['type' => PARAM_INT, 'default' => 0], 'memoryusagedatad3' => ['type' => PARAM_RAW], 'memoryusagemax' => ['type' => PARAM_INT], diff --git a/classes/sample_set.php b/classes/sample_set.php index 21e9e7f..646d9e6 100644 --- a/classes/sample_set.php +++ b/classes/sample_set.php @@ -30,7 +30,7 @@ class sample_set { /** @var float Starting time of the sample set. */ public $starttime; - /** @var array An array of \ExcimerLogEntry objects. */ + /** @var array An array of sample objects. It could contain memory usage samples or tasks samples */ public $samples = []; /** @var int Sample limit. */ @@ -38,12 +38,6 @@ class sample_set { /** @var int The maximum stack depth. */ public $maxstackdepth = 0; - /** @var int If is R, then only each Rth sample is recorded. */ - private $filterrate = 1; - - /** @var int Internal counter to help with filtering. */ - private $counter = 0; - /** @var int Internal counter of how many samples were added (regardless of how many are currently held). */ private $totaladded = 0; @@ -75,27 +69,29 @@ public function get_stack_depth(): int { * @param array|\ExcimerLogEntry $sample */ public function add_sample($sample) { - $trace = false; - if (count($this->samples) === $this->samplelimit) { - $this->apply_doubling(); - } - $this->counter += 1; - if ($this->counter === $this->filterrate) { - $this->samples[] = $sample; - $this->counter = 0; - } + $ismemory = false; // If this is a log entry, it will count the number of total events // processed instead. // Each time a sample is added, recalculate the maxstackdepth for this set. if ($sample instanceof \ExcimerLogEntry) { - $this->totaladded += $sample->getEventCount(); + $eventcount = $sample->getEventCount(); $trace = $sample->getTrace(); + $this->totaladded += $eventcount; if ($trace) { $this->maxstackdepth = max($this->maxstackdepth, count($trace)); } - return; + $this->samples[] = [ + 'eventcount' => $eventcount, + 'trace' => $trace, + ]; + } else { + $this->samples[] = $sample; + $this->totaladded++; + $ismemory = true; + } + if (count($this->samples) >= $this->samplelimit) { + $this->apply_doubling($ismemory); } - $this->totaladded++; } /** @@ -110,24 +106,55 @@ public function add_many_samples(iterable $samples) { } /** - * Doubles the filter rate, and strips every second sample from the set. + * Merge samples to increase storage * Called when the sample limit is reached. - * - * We have two options here. Either double the sampling period, or apply a filter to record only the - * Nth sample passed to sample_set. By using a filter and keeping the sampling period the same, we avoid - * spilling over into the next task. + * @param bool $ismemory true if the dataset is a memory usage sample set. */ - public function apply_doubling() { - $this->filterrate *= 2; - $this->samples = array_values( - array_filter( - $this->samples, - function ($key) { - return ($key % 2); - }, - ARRAY_FILTER_USE_KEY - ) - ); + public function apply_doubling($ismemory) { + $ismemory ? $this->merge_memory_usage_sample_set() : $this->merge_excimer_sample_set(); + } + + /** + * Merge memory usage sample set + */ + private function merge_memory_usage_sample_set() { + $newsamples = []; + for ($i = 0; $i < count($this->samples); $i += 2) { + // Prevent sample limit is odd. + if ($i == count($this->samples) - 1) { + $newsamples[] = $this->samples[$i]; + } else { + $newsamples[] = [ + 'sampleindex' => $this->samples[$i]['sampleindex'], + 'value' => max($this->samples[$i]['value'], $this->samples[$i + 1]['value']), + ]; + } + } + $this->samples = $newsamples; + } + + /** + * Merge excimer sample set + */ + private function merge_excimer_sample_set() { + $newsamples = []; + for ($i = 0; $i < count($this->samples); $i += 2) { + // Prevent sample limit is odd. + if ($i == count($this->samples) - 1) { + $newsamples[] = $this->samples[$i]; + } else { + if ($this->samples[$i]['eventcount'] >= $this->samples[$i + 1]['eventcount']) { + $trace = $this->samples[$i]['trace']; + } else { + $trace = $this->samples[$i + 1]['trace']; + } + $newsamples[] = [ + 'eventcount' => ceil(($this->samples[$i]['eventcount'] + $this->samples[$i + 1]['eventcount']) / 2), + 'trace' => $trace, + ]; + } + } + $this->samples = $newsamples; } /** @@ -149,21 +176,13 @@ public function total_added() { */ public function count(): int { $count = count($this->samples); - if ($count > 0 && $this->samples[0] instanceof \ExcimerLogEntry) { + if ($count > 0 && array_key_exists("eventcount", $this->samples[0])) { $count = array_reduce($this->samples, function ($acc, $sample) { - $acc += $sample->getEventCount(); + $acc += $sample["eventcount"]; return $acc; }, 0); } - return $count; - } - /** - * Returns the filter rate to calculate the real sampling rate - * - * @return int - */ - public function filter_rate() { - return $this->filterrate; + return $count; } } diff --git a/classes/script_metadata.php b/classes/script_metadata.php index ce2bdd1..cbcf683 100644 --- a/classes/script_metadata.php +++ b/classes/script_metadata.php @@ -72,9 +72,9 @@ class script_metadata { const SAMPLING_PERIOD_DEFAULT = 0.1; /** Minimum timer interval */ - const TIMER_INTERVAL_MIN = 1; + const MAX_SAMPLES_MIN = 1; /** Default timer interval */ - const TIMER_INTERVAL_DEFAULT = 10; + const MAX_SAMPLES_DEFAULT = 1000; /** Maximium stack depth. */ const STACK_DEPTH_LIMIT = 1000; @@ -405,17 +405,17 @@ public static function redact_pluginfile_pathinfo(string $pathinfo): string { } /** - * Get the timer interval from config, and return it as seconds. + * Get the max samples from config. * * @return float * @throws \dml_exception */ - public static function get_timer_interval(): float { - $interval = (float) get_config('tool_excimer', 'long_interval_s'); - if ($interval < self::TIMER_INTERVAL_MIN) { - return self::TIMER_INTERVAL_DEFAULT; + public static function get_max_samples(): float { + $maxsamples = (float) get_config('tool_excimer', 'max_samples'); + if ($maxsamples < self::MAX_SAMPLES_MIN) { + return self::MAX_SAMPLES_DEFAULT; } - return $interval; + return $maxsamples; } /** diff --git a/classes/web_processor.php b/classes/web_processor.php index b12df66..c1e88aa 100644 --- a/classes/web_processor.php +++ b/classes/web_processor.php @@ -26,23 +26,12 @@ * @copyright 2022, Catalyst IT * @license http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later */ -class web_processor implements processor { +class web_processor extends processor { /** @var profile The profile object for the run. */ protected $profile; - /** @var sample_set */ - protected $sampleset; - /** @var sample_set */ - protected $memoryusagesampleset; - - /** @var int */ - protected $minduration; - /** @var int */ - protected $samplems; /** @var bool */ protected $partialsave; - /** @var bool */ - protected static $alreadyprofiling = false; /** @var bool */ protected $hasoverlapped = false; @@ -50,9 +39,8 @@ class web_processor implements processor { * Construct the web processor. */ public function __construct() { - // Preload config values to avoid DB access during processing. See manager::get_altconnection() for more information. + parent::__construct(); $this->minduration = (float) get_config('tool_excimer', 'trigger_ms') / 1000.0; - $this->samplems = (int) get_config('tool_excimer', 'sample_ms'); $this->partialsave = get_config('tool_excimer', 'enable_partial_save'); } @@ -62,102 +50,118 @@ public function __construct() { * @param manager $manager The profiler manager object */ public function init(manager $manager) { + global $ME, $SCRIPT; // Record and set initial memory usage at this point. $memoryusage = memory_get_usage(); - - global $ME, $SCRIPT; - $request = script_metadata::get_normalised_relative_script_path($ME, $SCRIPT); $starttime = (int) $manager->get_starttime(); - $this->sampleset = new sample_set($request, $starttime); + $this->tasksampleset = new sample_set($request, $starttime); // Add sampleset for memory usage - this sets the baseline for the profile. $this->memoryusagesampleset = new sample_set($request, $starttime); $this->memoryusagesampleset->add_sample(['sampleindex' => 0, 'value' => $memoryusage]); $this->profile = new profile(); - $this->profile->add_env($this->sampleset->name); - $this->profile->set('created', $this->sampleset->starttime); + $this->profile->add_env($this->tasksampleset->name); + $this->profile->set('created', $this->tasksampleset->starttime); if ($this->partialsave) { - $manager->get_timer()->setCallback(function () use ($manager) { + // The callback is triggered when the number of samples reach the maxsamples and when profiler is destroyed. + $manager->get_profiler()->setFlushCallback(function ($log) use ($manager) { // Once overlapping has happened once, we prevent all future partial saving. if (!$this->hasoverlapped) { - $this->process($manager, false); + $this->on_interval($log, $manager); } - }); + }, $this->maxsamples); } \core_shutdown_manager::register_function( function () use ($manager) { - $manager->get_timer()->stop(); $manager->get_profiler()->stop(); - - // Keep an approximate count of each profile. - $this->process($manager, true); + if (!$this->partialsave) { + $log = $manager->get_profiler()->flush(); + $this->on_interval($log, $manager); + } + $this->process($manager); page_group::record_fuzzy_counts($this->profile); } ); } /** - * Gets the minimum duration required for a profile to be saved, as seconds. + * Examines a sample generated by the profiler. * - * @return float - */ - public function get_min_duration(): float { - return $this->minduration; - } - - /** - * Process a batch of Excimer logs. + * The logic represents the following: + * + * If a sample is the first of a task, we create a task_samples instance, and add the sample. + * As long as subsequent samples are in the same task, we keep adding them to task_samples. + * When we get to a sample that is not in the same task, we process the task_samples and reset it. + * + * We then check for a new task with the current sample. * + * @param \ExcimerLog $log * @param manager $manager - * @param bool $isfinal - * @throws \dml_exception */ - public function process(manager $manager, bool $isfinal) { + public function on_interval($log, manager $manager) { // We want to prevent overlapping of processing, so skip if an existing process is still executing. // The profile logs will be kept and processed the next time. + self::$logs[] = $log; + $this->logcount += $log->count(); + // Doubling sampling period if it reaches the limit. + if ($this->partialsave && $this->logcount >= $this->samplelimit) { + $this->on_reach_limit($manager); + $this->logcount = $this->logcount - $this->samplelimit; + } if (self::$alreadyprofiling) { $this->hasoverlapped = true; debugging('tool_excimer: starting web_processor::process when previous process has not yet finished'); - if ($isfinal) { + if ($log->count() < $this->samplelimit) { // This should never happen. debugging('tool_excimer: alreadyprofiling is true during final process.'); } return; } self::$alreadyprofiling = true; + foreach (self::$logs as $log) { + $memoryusage = memory_get_usage(); + $this->tasksampleset->add_many_samples($log); + $this->memoryusagesampleset->add_sample([ + 'sampleindex' => $this->tasksampleset->total_added() - 1, + 'value' => $memoryusage, + ]); + } + self::$logs = []; + self::$alreadyprofiling = false; + } - $log = $manager->get_profiler()->flush(); - $this->sampleset->add_many_samples($log); - - $this->memoryusagesampleset->add_sample([ - 'sampleindex' => $this->sampleset->total_added() + $this->memoryusagesampleset->count() - 1, - 'value' => memory_get_usage(), - ]); + /** + * Processes stored samples to create a profile. + * + * @param manager $manager + * @throws \dml_exception + */ + public function process(manager $manager) { $current = microtime(true); $currentrusage = getrusage(); - $this->profile->set('duration', $current - $manager->get_starttime()); + $duration = $current - $manager->get_starttime(); + $this->profile->set('duration', $duration); $cpuduration = helper::get_rusage_timediff($manager->get_startrusage(), $currentrusage); $this->profile->set('usercpuduration', $cpuduration['user']); $this->profile->set('systemcpuduration', $cpuduration['system']); - $this->profile->set('maxstackdepth', $this->sampleset->get_stack_depth()); + $this->profile->set('maxstackdepth', $this->tasksampleset->get_stack_depth()); $reason = $manager->get_reasons($this->profile); if ($reason !== profile::REASON_NONE) { $this->profile->set('reason', $reason); - $this->profile->set('finished', $isfinal ? (int) $current : 0); + $this->profile->set('finished', (int) $current); $this->profile->set('memoryusagedatad3', $this->memoryusagesampleset->samples); - $this->profile->set('flamedatad3', flamed3_node::from_excimer_log_entries($this->sampleset->samples)); - $this->profile->set('numsamples', $this->sampleset->count()); - $this->profile->set('samplerate', $this->sampleset->filter_rate() * $this->samplems); + $this->profile->set('flamedatad3', flamed3_node::from_sample_set_samples($this->tasksampleset->samples)); + $this->profile->set('numsamples', count($this->tasksampleset->samples)); + $this->profile->set('numevents', $this->tasksampleset->count()); + $this->profile->set('samplerate', (int) (($duration * 1000) / $this->tasksampleset->count())); foreach (script_metadata::get_lock_info() as $field => $value) { $this->profile->set($field, $value); } $this->profile->save_record(); } - - self::$alreadyprofiling = false; } } diff --git a/db/install.xml b/db/install.xml index da76d51..1277dff 100755 --- a/db/install.xml +++ b/db/install.xml @@ -32,6 +32,7 @@ + diff --git a/db/upgrade.php b/db/upgrade.php index fae5aac..7f63cc7 100644 --- a/db/upgrade.php +++ b/db/upgrade.php @@ -538,10 +538,15 @@ function xmldb_tool_excimer_upgrade($oldversion) { upgrade_plugin_savepoint(true, 2024082301, 'tool', 'excimer'); } - if ($oldversion < 2025120903) { - // Define field id to be added to tool_excimer_profiles. + if ($oldversion < 2025121000) { $table = new xmldb_table('tool_excimer_profiles'); + // Add 'numevents' field - The number of events taken. + $field = new xmldb_field('numevents', XMLDB_TYPE_INTEGER, '11', true, XMLDB_NOTNULL, null, 0, 'numsamples'); + if (!$dbman->field_exists($table, $field)) { + $dbman->add_field($table, $field); + } + $field = new xmldb_field('usercpuduration', XMLDB_TYPE_NUMBER, '12, 6', null, null, null, null); // Conditionally add field. @@ -557,7 +562,7 @@ function xmldb_tool_excimer_upgrade($oldversion) { } // Excimer savepoint reached. - upgrade_plugin_savepoint(true, 2025120903, 'tool', 'excimer'); + upgrade_plugin_savepoint(true, 2025121000, 'tool', 'excimer'); } return true; diff --git a/lang/en/tool_excimer.php b/lang/en/tool_excimer.php index 8e5b20d..e37b35a 100644 --- a/lang/en/tool_excimer.php +++ b/lang/en/tool_excimer.php @@ -25,33 +25,32 @@ */ $string['adminname'] = 'Excimer profiler'; -$string['pluginname'] = 'Excimer profiler'; -$string['reportname'] = 'Profiler reports'; - -// Admin Tree. -$string['report_slowest'] = 'Slowest profiles'; -$string['report_slowest_grouped'] = 'Slowest scripts'; -$string['report_slowest_web'] = 'Slow web pages'; -$string['report_slowest_other'] = 'Slow tasks / CLI / WS'; -$string['report_session_locks'] = 'Long session locks'; -$string['report_recent'] = 'Recently profiled'; -$string['report_unfinished'] = 'Currently profiling'; -$string['report_page_groups'] = 'Page Group Metadata'; -$string['report_page_slow_course'] = 'Slow by course'; - -// Check API. +$string['allprofilesdeleted'] = 'All profiles have been deleted.'; +$string['approx_count_algorithm'] = 'approximate counting algorithm'; +$string['auto_settings'] = 'Auto profiling settings'; +$string['auto_settings_desc'] = 'Settings related to automatic profiling.'; +$string['cachedef_page_group_metadata'] = 'Excimer page group metadata cache'; +$string['cachedef_request_metadata'] = 'Excimer request metadata cache'; $string['checkslowest'] = 'Excimer profiles'; -$string['checkslowest:none'] = 'No profiles recorded.'; $string['checkslowest:action'] = 'Slowest profiles'; -$string['checkslowest:summary'] = 'Slowest profile is "{$a->request}" at {$a->duration}'; $string['checkslowest:details'] = 'The longest running Excimer profile recorded is for the script/task "{$a->request}" at {$a->duration}.'; +$string['checkslowest:none'] = 'No profiles recorded.'; +$string['checkslowest:summary'] = 'Slowest profile is "{$a->request}" at {$a->duration}'; -// Settings. -$string['here'] = 'here'; -$string['general_settings'] = 'General settings'; -$string['general_settings_desc'] = 'Settings related to all profiles.'; -$string['auto_settings'] = 'Auto profiling settings'; -$string['auto_settings_desc'] = 'Settings related to automatic profiling.'; +$string['deleteallwarning'] = 'This will remove ALL stored profiles. Continue?
Locked profiles will not be removed.'; +$string['deletedcourse'] = 'Deleted course id: {$a}'; +$string['deleteprofile'] = 'Delete profile'; +$string['deleteprofiles_course'] = 'Delete all profiles for course'; +$string['deleteprofiles_course_warning'] = 'This will remove all stored profiles for the course. Continue?
Locked profiles will not be removed.'; +$string['deleteprofiles_filter'] = 'Delete all profiles for this filter'; +$string['deleteprofiles_filter_warning'] = 'This will remove all stored profiles that match this filter. Continue?
Locked profiles will not be removed.'; +$string['deleteprofiles_script'] = 'Delete all profiles for script'; +$string['deleteprofiles_script_warning'] = 'This will remove all stored profiles for the script. Continue?
Locked profiles will not be removed.'; +$string['deleteprofilewarning'] = 'This will remove the profile. Continue?'; +$string['didnotfinish'] = 'Did not finish'; +$string['displaying_month'] = 'Displaying month'; +$string['duration'] = 'duration'; +$string['edit_lock'] = 'Edit lock'; $string['enable_auto'] = 'Enable auto profiling'; $string['enable_auto_desc'] = 'Any page will be automatically profiled if they exceed the miniumum duration.'; $string['enable_fuzzy_count'] = 'Enable fuzzy counting'; @@ -60,142 +59,77 @@ $string['enable_partial_save_desc'] = 'This will save partial profiles of slow web processes every processing interval. This provides information about these processes while they are still running or if a container gets reaped, but the extra writes can be problematic when experiencing large scale database issues.'; -$string['expiry_s'] = 'Log expiry (days)'; -$string['expiry_s_desc'] = 'Remove profiles after this long.'; -$string['num_slowest'] = 'Max to save'; -$string['num_slowest_desc'] = 'Only the N slowest profiles will be kept.'; -$string['period_ms'] = 'Sampling period (milliseconds)'; -$string['period_ms_desc'] = 'Frequency of sampling. Minimum is {$a->min}, maximum is {$a->max}.'; -$string['request_ms'] = 'Minimum request duration (milliseconds)'; -$string['request_ms_desc'] = 'Record a profile only if it runs at least this long.'; -$string['num_slowest_by_page'] = 'Max to save by page'; -$string['num_slowest_by_page_desc'] = 'Only the N slowest profiles will be kept for each script page.'; -$string['noexcimerprofiler'] = 'ExcimerProfiler class does not exist so profiling cannot continue. Please check the installation instructions {$a}.'; -$string['long_interval_s'] = 'Processing interval (seconds)'; -$string['long_interval_s_desc'] = 'Checks the current status of long running tasks every N seconds and processes as required. - This includes saving profiles of finished cron tasks and partial saves of ongoing web processes if enabled.'; -$string['task_min_duration'] = 'Task min duration (seconds)'; -$string['task_min_duration_desc'] = 'For scheduled and ad-hoc tasks, the minimum approx duration, in seconds.'; -$string['samplelimit'] = 'Sample limit'; -$string['samplelimit_desc'] = 'The maximum number of samples that will be recorded. This works by filtering the recording of - samples. Each time the limit is reached, the samples recorded so far are stripped of every second sample. Also, the filter rate - doubles, so that only every Nth sample is recorded at filter rate N. This has the same effect as adjusting the sampling period - so that the total number of samples never exceeds the limit.'; -$string['stacklimit'] = 'Stack limit'; -$string['stacklimit_desc'] = 'The maximum permitted recursion or stack depth before the task is flagged.'; $string['expiry_fuzzy_counts'] = 'Months to keep aproximate count data.'; $string['expiry_fuzzy_counts_desc'] = 'The number of full months worth of data to keep. Leave blank to keep indefinitely.'; -$string['redact_params'] = 'Paramters to be redacted'; -$string['redact_params_desc'] = 'These parameters (one per line) will have their values removed before their profile is saved. - Include in this list, any paramters that are potentially sensitive, such as keys, tokens and nonces. Comments, C style (/\*..\*/) - and bash style (#), and blank lines will be ignored.
- Redacting of parameters {$a} is builtin, and will always be done.'; - -// Tasks. -$string['task_expire_logs'] = 'Expire excimer logs'; -$string['task_purge_fastest'] = 'Purge fastest excimer profiles'; -$string['task_purge_page_groups'] = 'Purge page group approximate count data'; - -// Tabs. -$string['slowest_grouped'] = 'Slowest scripts'; -$string['recent'] = 'Recent'; -$string['slowest'] = 'Slowest'; -$string['tab_slowest_web'] = 'Slow web pages'; -$string['tab_slowest_other'] = 'Slow tasks / CLI / WS'; -$string['tab_session_locks'] = 'Long session locks'; -$string['unfinished'] = 'Unfinished'; -$string['tab_page_groups'] = 'Page Groups'; -$string['tab_page_course'] = 'Courses'; -$string['tab_import'] = 'Import'; - -// Month Selector. -$string['displaying_month'] = 'Displaying month'; -$string['to_current_month'] = 'To current month'; -$string['previous_month'] = 'Previous month'; -$string['next_month'] = 'Next month'; - -// Profile table. -$string['field_id'] = 'ID'; -$string['field_type'] = 'Type'; -$string['field_scripttype'] = 'Script Type'; +$string['expiry_s'] = 'Log expiry (days)'; +$string['expiry_s_desc'] = 'Remove profiles after this long.'; +$string['export_profile'] = 'Export profile'; +$string['field_actions'] = 'Actions'; +$string['field_buffering'] = 'Buffering enabled'; $string['field_contenttype'] = 'Content Type'; $string['field_contenttypecategory'] = 'Content Type (category)'; $string['field_contenttypekey'] = 'Content Type (extension/key)'; $string['field_contenttypevalue'] = 'Content Type (actual value)'; -$string['field_reason'] = 'Reason'; -$string['field_scriptgroup'] = 'Script group'; -$string['field_created'] = 'Created'; -$string['field_finished'] = 'Finished'; -$string['field_userid'] = 'User'; -$string['field_duration'] = 'Duration'; -$string['field_usercpuduration'] = 'User CPU duration'; -$string['field_systemcpuduration'] = 'System CPU duration'; -$string['field_cpuduration'] = 'CPU duration (total)'; -$string['field_request'] = 'Request'; -$string['field_pathinfo'] = 'Pathinfo'; -$string['field_explanation'] = 'Explanation'; -$string['field_parameters'] = 'Parameters'; -$string['field_responsecode'] = 'Code'; -$string['field_sessionid'] = 'Session ID'; -$string['field_referer'] = 'Referer'; $string['field_cookies'] = 'Cookies enabled'; -$string['field_buffering'] = 'Buffering enabled'; -$string['field_numsamples'] = 'Number of samples'; -$string['field_numsamples_value'] = '{$a->samples} samples @ ~{$a->samplerate}ms'; +$string['field_courseid'] = 'Course'; +$string['field_cpuduration'] = 'CPU duration (total)'; +$string['field_created'] = 'Created'; +$string['field_datasize'] = 'Size of profile data'; $string['field_dbreadwrites'] = 'DB reads/writes'; $string['field_dbreplicareads'] = 'DB reads from replica'; -$string['field_datasize'] = 'Size of profile data'; -$string['field_memoryusagemax'] = 'Max Memory Used'; +$string['field_duration'] = 'Duration'; +$string['field_explanation'] = 'Explanation'; +$string['field_finished'] = 'Finished'; +$string['field_fuzzycount'] = 'Approx. count'; +$string['field_fuzzydurationcounts'] = 'Histogram'; +$string['field_fuzzydurationsum'] = 'Approx. total duration (s)'; +$string['field_hostname'] = 'Host name'; +$string['field_id'] = 'ID'; +$string['field_lockheld'] = 'Session held'; +$string['field_lockreason'] = 'Lock reason'; +$string['field_lockwait'] = 'Session wait'; +$string['field_lockwaiturl'] = 'Locking URL'; +$string['field_lockwaiturl_help'] = 'Information about this page may only be available when $CFG->debugsessionlock is set.'; $string['field_maxcreated'] = 'Latest'; -$string['field_mincreated'] = 'Earliest'; $string['field_maxduration'] = 'Slowest'; -$string['field_minduration'] = 'Fastest'; $string['field_maxlockheld'] = 'Longest'; +$string['field_memoryusagemax'] = 'Max Memory Used'; +$string['field_mincreated'] = 'Earliest'; +$string['field_minduration'] = 'Fastest'; $string['field_minlockheld'] = 'Shortest'; -$string['field_requestcount'] = 'Num profiles'; +$string['field_month'] = 'Month'; +$string['field_name'] = 'Name'; +$string['field_numsamples'] = 'Number of samples'; +$string['field_numsamples_value'] = '{$a->samples} samples ({$a->events} events) @ ~{$a->samplerate}ms'; +$string['field_parameters'] = 'Parameters'; +$string['field_pathinfo'] = 'Pathinfo'; $string['field_pid'] = 'Process ID'; -$string['field_hostname'] = 'Host name'; -$string['field_useragent'] = 'User agent'; -$string['field_versionhash'] = 'Version Hash'; -$string['field_usermodified'] = 'User modified'; +$string['field_reason'] = 'Reason'; +$string['field_referer'] = 'Referer'; +$string['field_request'] = 'Request'; +$string['field_requestcount'] = 'Num profiles'; +$string['field_responsecode'] = 'Code'; +$string['field_scriptgroup'] = 'Script group'; +$string['field_scripttype'] = 'Script Type'; +$string['field_sessionid'] = 'Session ID'; +$string['field_systemcpuduration'] = 'System CPU duration'; $string['field_timecreated'] = 'Time created'; $string['field_timemodified'] = 'Time modified'; -$string['field_lockreason'] = 'Lock reason'; -$string['field_courseid'] = 'Course'; -$string['field_lockheld'] = 'Session held'; -$string['field_lockwait'] = 'Session wait'; -$string['field_lockwaiturl'] = 'Locking URL'; -$string['field_lockwaiturl_help'] = 'Information about this page may only be available when $CFG->debugsessionlock is set.'; - -// Page count table. -$string['field_name'] = 'Name'; -$string['field_month'] = 'Month'; -$string['field_fuzzycount'] = 'Approx. count'; -$string['field_fuzzydurationcounts'] = 'Histogram'; -$string['field_fuzzydurationsum'] = 'Approx. total duration (s)'; - -// Note: This is needed as the headers for the profile table are added in a loop. -$string['field_actions'] = 'Actions'; - -// Terminology. -$string['term_profile'] = 'Profile'; - -// Script types. -$string['scripttype_web'] = 'Web'; -$string['scripttype_cli'] = 'CLI'; -$string['scripttype_ajax'] = 'Ajax'; -$string['scripttype_ws'] = 'Service'; -$string['scripttype_task'] = 'Task'; - -// Log reasons. -$string['reason_flameme'] = 'Flame Me'; -$string['reason_auto'] = 'Auto'; -$string['reason_slow'] = 'Slow'; -$string['reason_flameall'] = 'Flame All'; -$string['reason_stack'] = 'Recursion'; -$string['reason_import'] = 'Import'; - -// Lock reason form. +$string['field_type'] = 'Type'; +$string['field_useragent'] = 'User agent'; +$string['field_usercpuduration'] = 'User CPU duration'; +$string['field_userid'] = 'User'; +$string['field_usermodified'] = 'User modified'; +$string['field_versionhash'] = 'Version Hash'; +$string['fuzzydurationrange'] = '{$a->low} - {$a->high}s'; +$string['general_settings'] = 'General settings'; +$string['general_settings_desc'] = 'Settings related to all profiles.'; +$string['here'] = 'here'; +$string['histogram_history'] = 'Histogram history'; +$string['import_error'] = 'Error saving the imported file contents.'; +$string['import_profile'] = 'Import profile'; +$string['import_success'] = 'Profile imported successfully.'; +$string['link'] = 'Direct link'; $string['lock_profile'] = 'Lock Profile'; $string['locked'] = 'Profile is locked'; $string['lockedinfo'] = 'Locked by {$a->user} on {$a->date}'; @@ -203,52 +137,77 @@ $string['lockreason_help'] = 'Submitting text will prevent this profile from being deleted. It will not be purged during cleanup tasks, nor can it be deleted manually (will also be excluded from group deletes). Typically you would provide a reason why you want to keep this profile. Clearing this box will allow the profile to be deleted.'; -$string['profile_updated'] = 'Profile updated'; - -// Time formats. -$string['strftime_datetime'] = '%d %b %Y, %H:%M'; -$string['strftime_monyear'] = '%b %Y'; - -// Privacy. -$string['privacy:metadata:tool_excimer_profiles'] = 'Excimer'; - -// Approx counting. -$string['approx_count_algorithm'] = 'approximate counting algorithm'; -$string['fuzzydurationrange'] = '{$a->low} - {$a->high}s'; - -// Page count. +$string['lockwaitnotification'] = 'The majority of the duration was spent waiting for a session lock, the page may not be slow.'; +$string['max_samples'] = 'Max samples'; +$string['max_samples_desc'] = 'Once the number of collected samples reaches, that batch of samples is processed'; $string['months_to_display'] = 'Months to display'; -$string['histogram_history'] = 'Histogram history'; - -// Import/export profiles. -$string['export_profile'] = 'Export profile'; -$string['import_profile'] = 'Import profile'; -$string['import_success'] = 'Profile imported successfully.'; -$string['import_error'] = 'Error saving the imported file contents.'; +$string['next_month'] = 'Next month'; +$string['no_month_in_page_group_table'] = 'Month value not set in page group table.'; $string['no_profile_file'] = 'No profile file found.'; +$string['noexcimerprofiler'] = 'ExcimerProfiler class does not exist so profiling cannot continue. Please check the installation instructions {$a}.'; +$string['num_slowest'] = 'Max to save'; +$string['num_slowest_by_page'] = 'Max to save by page'; +$string['num_slowest_by_page_desc'] = 'Only the N slowest profiles will be kept for each script page.'; +$string['num_slowest_desc'] = 'Only the N slowest profiles will be kept.'; +$string['period_ms'] = 'Sampling period (milliseconds)'; +$string['period_ms_desc'] = 'Frequency of sampling. Minimum is {$a->min}, maximum is {$a->max}.'; +$string['pluginname'] = 'Excimer profiler'; +$string['previous_month'] = 'Previous month'; +$string['privacy:metadata:tool_excimer_profiles'] = 'Excimer'; $string['profile_file'] = 'Profile file'; - -// Miscellaneous. -$string['cachedef_request_metadata'] = 'Excimer request metadata cache'; -$string['cachedef_page_group_metadata'] = 'Excimer page group metadata cache'; -$string['deleteallwarning'] = 'This will remove ALL stored profiles. Continue?
Locked profiles will not be removed.'; -$string['deleteprofile'] = 'Delete profile'; -$string['deleteprofilewarning'] = 'This will remove the profile. Continue?'; -$string['allprofilesdeleted'] = 'All profiles have been deleted.'; +$string['profile_updated'] = 'Profile updated'; $string['profiledeleted'] = 'Profile has been deleted.'; -$string['deleteprofiles_script_warning'] = 'This will remove all stored profiles for the script. Continue?
Locked profiles will not be removed.'; -$string['deleteprofiles_script'] = 'Delete all profiles for script'; -$string['deleteprofiles_course'] = 'Delete all profiles for course'; -$string['deleteprofiles_course_warning'] = 'This will remove all stored profiles for the course. Continue?
Locked profiles will not be removed.'; $string['profilesdeleted'] = 'Profiles have been deleted'; -$string['didnotfinish'] = 'Did not finish'; -$string['deleteprofiles_filter_warning'] = 'This will remove all stored profiles that match this filter. Continue?
Locked profiles will not be removed.'; -$string['deleteprofiles_filter'] = 'Delete all profiles for this filter'; -$string['edit_lock'] = 'Edit lock'; +$string['reason_auto'] = 'Auto'; +$string['reason_flameall'] = 'Flame All'; +$string['reason_flameme'] = 'Flame Me'; +$string['reason_import'] = 'Import'; +$string['reason_slow'] = 'Slow'; +$string['reason_stack'] = 'Recursion'; +$string['recent'] = 'Recent'; +$string['redact_params'] = 'Paramters to be redacted'; +$string['redact_params_desc'] = 'These parameters (one per line) will have their values removed before their profile is saved. + Include in this list, any paramters that are potentially sensitive, such as keys, tokens and nonces. Comments, C style (/\*..\*/) + and bash style (#), and blank lines will be ignored.
+ Redacting of parameters {$a} is builtin, and will always be done.'; +$string['report_page_groups'] = 'Page Group Metadata'; +$string['report_page_slow_course'] = 'Slow by course'; +$string['report_recent'] = 'Recently profiled'; +$string['report_session_locks'] = 'Long session locks'; +$string['report_slowest'] = 'Slowest profiles'; +$string['report_slowest_grouped'] = 'Slowest scripts'; +$string['report_slowest_other'] = 'Slow tasks / CLI / WS'; +$string['report_slowest_web'] = 'Slow web pages'; +$string['report_unfinished'] = 'Currently profiling'; +$string['reportname'] = 'Profiler reports'; +$string['request_ms'] = 'Minimum request duration (milliseconds)'; +$string['request_ms_desc'] = 'Record a profile only if it runs at least this long.'; +$string['samplelimit'] = 'Sample limit'; +$string['samplelimit_desc'] = 'Each time the limit is reached, the samples recorded so far are stripped of every second sample. Also, the sampling period doubles so that the total number of samples never exceeds the limit.'; $string['samples'] = 'samples'; -$string['duration'] = 'duration'; -$string['no_month_in_page_group_table'] = 'Month value not set in page group table.'; -$string['deletedcourse'] = 'Deleted course id: {$a}'; +$string['scripttype_ajax'] = 'Ajax'; +$string['scripttype_cli'] = 'CLI'; +$string['scripttype_task'] = 'Task'; +$string['scripttype_web'] = 'Web'; +$string['scripttype_ws'] = 'Service'; +$string['slowest'] = 'Slowest'; +$string['slowest_grouped'] = 'Slowest scripts'; +$string['stacklimit'] = 'Stack limit'; +$string['stacklimit_desc'] = 'The maximum permitted recursion or stack depth before the task is flagged.'; +$string['strftime_datetime'] = '%d %b %Y, %H:%M'; +$string['strftime_monyear'] = '%b %Y'; +$string['tab_import'] = 'Import'; +$string['tab_page_course'] = 'Courses'; +$string['tab_page_groups'] = 'Page Groups'; +$string['tab_session_locks'] = 'Long session locks'; +$string['tab_slowest_other'] = 'Slow tasks / CLI / WS'; +$string['tab_slowest_web'] = 'Slow web pages'; +$string['task_expire_logs'] = 'Expire excimer logs'; +$string['task_min_duration'] = 'Task min duration (seconds)'; +$string['task_min_duration_desc'] = 'For scheduled and ad-hoc tasks, the minimum approx duration, in seconds.'; +$string['task_purge_fastest'] = 'Purge fastest excimer profiles'; +$string['task_purge_page_groups'] = 'Purge page group approximate count data'; +$string['term_profile'] = 'Profile'; +$string['to_current_month'] = 'To current month'; +$string['unfinished'] = 'Unfinished'; $string['unknown'] = 'Unknown'; -$string['link'] = 'Direct link'; -$string['lockwaitnotification'] = 'The majority of the duration was spent waiting for a session lock, the page may not be slow.'; diff --git a/profile.php b/profile.php index ed4ceb6..faef6f0 100644 --- a/profile.php +++ b/profile.php @@ -192,6 +192,7 @@ 'tool_excimer', [ 'samples' => number_format($data['numsamples'], 0, $decsep, $thousandssep), + 'events' => number_format($data['numevents'] ?? $data['numsamples'], 0, $decsep, $thousandssep), 'samplerate' => $data['samplerate'], ] ); diff --git a/settings.php b/settings.php index 375eed3..2fc1a89 100644 --- a/settings.php +++ b/settings.php @@ -87,10 +87,10 @@ $settings->add( new admin_setting_configtext( - 'tool_excimer/long_interval_s', - get_string('long_interval_s', 'tool_excimer'), - get_string('long_interval_s_desc', 'tool_excimer'), - '10', + 'tool_excimer/max_samples', + get_string('max_samples', 'tool_excimer'), + get_string('max_samples_desc', 'tool_excimer'), + '1000', PARAM_INT ) ); diff --git a/tests/excimer_testcase.php b/tests/excimer_testcase.php index 2bb5042..46a5c94 100644 --- a/tests/excimer_testcase.php +++ b/tests/excimer_testcase.php @@ -151,11 +151,10 @@ protected function get_profiler_stub(array $stacktraces, float $period = 0, floa * * @param processor $processor * @param \ExcimerProfiler $profiler - * @param \ExcimerTimer $timer * @param float $starttime * @return \ExcimerProfiler|mixed|\PHPUnit\Framework\MockObject\MockObject */ - protected function get_manager_stub(processor $processor, \ExcimerProfiler $profiler, \ExcimerTimer $timer, float $starttime) { + protected function get_manager_stub(processor $processor, \ExcimerProfiler $profiler, float $starttime) { $stub = $this->getMockBuilder(manager::class) ->setConstructorArgs([$processor]) @@ -163,8 +162,6 @@ protected function get_manager_stub(processor $processor, \ExcimerProfiler $prof $stub->method('get_profiler') ->willReturn($profiler); - $stub->method('get_timer') - ->willReturn($timer); $stub->method('get_starttime') ->willReturn($starttime); $stub->method('get_reasons') @@ -172,4 +169,31 @@ protected function get_manager_stub(processor $processor, \ExcimerProfiler $prof return $stub; } + + /** + * Parse log entry to sample + * + * @param \ExcimerLogEntry $entry + * @return array + */ + protected function from_log_entry_to_sample($entry) { + return [ + "eventcount" => $entry->getEventCount(), + "trace" => $entry->getTrace(), + ]; + } + + /** + * Parse log to samples + * + * @param \ExcimerLog $log + * @return array + */ + protected function from_log_to_samples($log) { + $samples = []; + foreach ($log as $entry) { + $samples[] = $this->from_log_entry_to_sample($entry); + } + return $samples; + } } diff --git a/tests/tool_excimer_cron_processor_test.php b/tests/tool_excimer_cron_processor_test.php index 3552a6c..e0480e9 100644 --- a/tests/tool_excimer_cron_processor_test.php +++ b/tests/tool_excimer_cron_processor_test.php @@ -43,6 +43,7 @@ protected function setUp(): void { * @covers \tool_excimer\cron_processor::findtaskname */ public function test_findtaskname(): void { + script_metadata::init(); $processor = new cron_processor(); $entry = $this->get_log_entry_stub(['c::a', 'b', 'c']); $taskname = $processor->findtaskname($entry); @@ -68,8 +69,6 @@ public function test_on_interval(): void { script_metadata::init(); $processor = new cron_processor(); - $timer = new \ExcimerTimer(); - $started = 100.0; $period = 50.0; @@ -79,9 +78,13 @@ public function test_on_interval(): void { $profiler = $this->get_profiler_stub([ ['c::a', 'b', 'c'], ], $period); - $manager = $this->get_manager_stub($processor, $profiler, $timer, $started); + $log = $this->get_log_stub([ + ['c::a', 'b', 'c'], + ], $period); + + $manager = $this->get_manager_stub($processor, $profiler, $started); - $processor->on_interval($manager); + $processor->on_interval($log, $manager); $this->assertEquals($started + ($period * 1), $processor->sampletime); $this->assertNull($processor->tasksampleset); @@ -92,9 +95,14 @@ public function test_on_interval(): void { ['run_inner_scheduled_task', 'max::execute', 'read::john'], ['run_inner_scheduled_task', 'max::execute'], ], $period, ($period * 1)); + $log = $this->get_log_stub([ + ['a', 'b'], + ['run_inner_scheduled_task', 'max::execute', 'read::john'], + ['run_inner_scheduled_task', 'max::execute'], + ], $period, ($period * 1)); - $manager = $this->get_manager_stub($processor, $profiler, $timer, $started); - $processor->on_interval($manager); + $manager = $this->get_manager_stub($processor, $profiler, $started); + $processor->on_interval($log, $manager); $this->assertEquals($started + ($period * 4), $processor->sampletime); // There should be a current sample set being recorded. @@ -109,9 +117,14 @@ public function test_on_interval(): void { ['run_inner_adhoc_task', 'simle::execute'], ['a', 'b'], ], $period, ($period * 4)); - - $manager = $this->get_manager_stub($processor, $profiler, $timer, $started); - $processor->on_interval($manager); + $log = $this->get_log_stub([ + ['run_inner_scheduled_task', 'max::execute'], + ['a', 'b'], + ['run_inner_adhoc_task', 'simle::execute'], + ['a', 'b'], + ], $period, ($period * 4)); + $manager = $this->get_manager_stub($processor, $profiler, $started); + $processor->on_interval($log, $manager); $this->assertEquals($started + ($period * 8), $processor->sampletime); // There should not be a current sample set. @@ -134,4 +147,47 @@ public function test_on_interval(): void { $this->assertEquals($period * 1, $records[1]->duration); $this->assertEquals(1, $records[1]->numsamples); } + + + /** + * Tests cron_processor::on_interval(). + * + * @covers \tool_excimer\cron_processor::on_reach_limit + */ + public function test_on_reach_limit(): void { + $this->preventResetByRollback(); + set_config('sample_ms', 10, 'tool_excimer'); + set_config('samplelimit', 2, 'tool_excimer'); + script_metadata::init(); + $processor = new cron_processor(); + + $started = 100.0; + $period = 50.0; + $profiler = $this->get_profiler_stub([ + ['a', 'b'], + ['run_inner_scheduled_task', 'max::execute', 'read::john'], + ['run_inner_scheduled_task', 'max::execute'], + ['run_inner_scheduled_task', 'max::execute', 'read::john'], + ['run_inner_scheduled_task', 'max::execute'], + ], $period, ($period * 1)); + $log = $this->get_log_stub([ + ['a', 'b'], + ['run_inner_scheduled_task', 'max::execute', 'read::john'], + ['run_inner_scheduled_task', 'max::execute'], + ['run_inner_scheduled_task', 'max::execute', 'read::john'], + ['run_inner_scheduled_task', 'max::execute'], + ], $period, ($period * 1)); + + $manager = $this->get_manager_stub($processor, $profiler, $started); + + $processor->init($manager); + $this->assertEquals(0.01, $processor->get_sampling_period()); + $this->assertEquals(2, $processor->get_sample_limit()); + + $processor->on_interval($log, $manager); + $this->assertEquals(0.02, $processor->get_sampling_period()); + + $processor->on_interval($log, $manager); + $this->assertEquals(0.04, $processor->get_sampling_period()); + } } diff --git a/tests/tool_excimer_flamed3_node_test.php b/tests/tool_excimer_flamed3_node_test.php index f134eed..cd2d36a 100644 --- a/tests/tool_excimer_flamed3_node_test.php +++ b/tests/tool_excimer_flamed3_node_test.php @@ -97,18 +97,18 @@ public function test_add_excimer_trace_tail(): void { /** * Tests flamed3_node::from_excimer_log_entries * - * @covers \tool_excimer\flamed3_node::from_excimer_log_entries + * @covers \tool_excimer\flamed3_node::from_sample_set_samples */ public function test_from_excimer_log_entries(): void { - $entries = [ - $this->get_log_entry_stub(['c::a', 'b', 'c']), - $this->get_log_entry_stub(['c::a', 'd', 'e']), - $this->get_log_entry_stub(['m', 'n', 'e']), - $this->get_log_entry_stub(['M::m', 'n', 'e']), - $this->get_log_entry_stub(['M::m', 'l;12']), + $samples = [ + $this->from_log_entry_to_sample($this->get_log_entry_stub(['c::a', 'b', 'c'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['c::a', 'd', 'e'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['m', 'n', 'e'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['M::m', 'n', 'e'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['M::m', 'l;12'])), ]; - $node = flamed3_node::from_excimer_log_entries($entries); + $node = flamed3_node::from_sample_set_samples($samples); $this->assertEquals(5, $node->value); $this->assertEquals(3, count($node->children)); $this->assertEquals('c::a', $node->children[0]->name); @@ -131,19 +131,19 @@ public function test_from_excimer_log_entries(): void { /** * Test from log entries counts. * - * @covers \tool_excimer\flamed3_node::from_excimer_log_entries + * @covers \tool_excimer\flamed3_node::from_sample_set_samples */ public function test_from_excimer_log_entries_counts(): void { $entries = [ - $this->get_log_entry_stub(['c::a', 'b']), - $this->get_log_entry_stub(['c::a', 'b']), - $this->get_log_entry_stub(['c::a', 'd']), - $this->get_log_entry_stub(['m']), - $this->get_log_entry_stub(['m']), - $this->get_log_entry_stub(['m']), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['c::a', 'b'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['c::a', 'b'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['c::a', 'd'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['m'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['m'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['m'])), ]; - $node = flamed3_node::from_excimer_log_entries($entries); + $node = flamed3_node::from_sample_set_samples($entries); $this->assertEquals(6, $node->value); $this->assertEquals(2, count($node->children)); diff --git a/tests/tool_excimer_profile_helper_test.php b/tests/tool_excimer_profile_helper_test.php index 7c3868e..d8db37e 100644 --- a/tests/tool_excimer_profile_helper_test.php +++ b/tests/tool_excimer_profile_helper_test.php @@ -101,6 +101,34 @@ public function quick_save( return $profile->save_record(); } + + /** + * Parse log entry to sample + * + * @param \ExcimerLogEntry $entry + * @return array + */ + protected function from_log_entry_to_sample($entry) { + return [ + "eventcount" => $entry->getEventCount(), + "trace" => $entry->getTrace(), + ]; + } + + /** + * Parse log to samples + * + * @param \ExcimerLog $log + * @return array + */ + protected function from_log_to_samples($log) { + $samples = []; + foreach ($log as $entry) { + $samples[] = $this->from_log_entry_to_sample($entry); + } + return $samples; + } + /** * Tests the functionality to keep only the N slowest profiles. * @@ -116,7 +144,7 @@ public function test_n_slowest_kept(): void { $sortedtimes = $times; sort($sortedtimes); $this->assertGreaterThan($sortedtimes[0], $sortedtimes[1]); // Sanity check. - $node = flamed3_node::from_excimer_log_entries($log); + $node = flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)); // Non-auto saves should have no impact, so chuck a few in to see if it gums up the works. $this->quick_save('mock', $node, profile::REASON_FLAMEME, 2.345); @@ -175,7 +203,7 @@ public function test_n_slowest_kept_with_locks(): void { $sortedtimes = $times; sort($sortedtimes); $this->assertGreaterThan($sortedtimes[0], $sortedtimes[1]); // Sanity check. - $node = flamed3_node::from_excimer_log_entries($log); + $node = flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)); foreach ($times as $time) { $this->quick_save('mock', $node, profile::REASON_SLOW, $time, 0, 'X'); @@ -214,7 +242,7 @@ public function test_n_slowest_kept_per_group(): void { $sortedtimes = $times; sort($sortedtimes); $this->assertGreaterThan($sortedtimes[0], $sortedtimes[1]); // Sanity check. - $node = flamed3_node::from_excimer_log_entries($log); + $node = flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)); // Non-auto saves should have no impact, so chuck a few in to see if it gums up the works. $this->quick_save('a', $node, profile::REASON_FLAMEME, 2.345); @@ -267,7 +295,13 @@ public function test_purge_old_profiles(): void { $this->assertEquals(0, profile_helper::get_num_profiles()); $expectedcount = 0; foreach ($times as $time) { - $this->quick_save('mock', flamed3_node::from_excimer_log_entries($log), profile::REASON_FLAMEME, 0.2, $time); + $this->quick_save( + 'mock', + flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)), + profile::REASON_FLAMEME, + 0.2, + $time + ); $this->assertEquals(++$expectedcount, profile_helper::get_num_profiles()); } @@ -300,7 +334,14 @@ public function test_purge_old_profiles_with_lock(): void { $expectedcount = count($times); foreach ($times as $time) { - $this->quick_save('mock', flamed3_node::from_excimer_log_entries($log), profile::REASON_FLAMEME, 0.2, $time, 'X'); + $this->quick_save( + 'mock', + flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)), + profile::REASON_FLAMEME, + 0.2, + $time, + 'X' + ); } profile_helper::purge_profiles_before_epoch_time($cutoff1); @@ -331,7 +372,12 @@ public function test_reasons_being_removed(): void { foreach (profile::REASONS as $reason) { $allthereasons |= $reason; } - $id = $this->quick_save('mock', flamed3_node::from_excimer_log_entries($log), $allthereasons, 2.345); + $id = $this->quick_save( + 'mock', + flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)), + $allthereasons, + 2.345 + ); $profile = $DB->get_record(profile::TABLE, ['id' => $id]); // Fetch profile from DB and confirm it matches for all the reasons, and @@ -367,7 +413,14 @@ public function test_reasons_being_removed_with_lock(): void { foreach (profile::REASONS as $reason) { $allthereasons |= $reason; } - $id = $this->quick_save('mock', flamed3_node::from_excimer_log_entries($log), $allthereasons, 2.345, 0, 'X'); + $id = $this->quick_save( + 'mock', + flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)), + $allthereasons, + 2.345, + 0, + 'X' + ); $profile = $DB->get_record(profile::TABLE, ['id' => $id]); // Fetch profile from DB and confirm it matches for all the reasons, and @@ -399,7 +452,7 @@ private function mock_profile_insertion_with_duration(float $duration) { // Divide by 1000 required, as microtime(true) returns the value in seconds. $reason = $manager->get_reasons($profile); if ($reason !== profile::REASON_NONE) { - $profile->set('flamedatad3', flamed3_node::from_excimer_log_entries($profiler->getLog())); + $profile->set('flamedatad3', flamed3_node::from_sample_set_samples($this->from_log_to_samples($profiler->getLog()))); $profile->set('reason', $reason); // Won't show DB writes count since saves are stored via another DB connection. diff --git a/tests/tool_excimer_profile_test.php b/tests/tool_excimer_profile_test.php index c65feff..a164e57 100644 --- a/tests/tool_excimer_profile_test.php +++ b/tests/tool_excimer_profile_test.php @@ -50,6 +50,34 @@ protected function busy_function2() { usleep(100); } + + /** + * Parse log entry to sample + * + * @param \ExcimerLogEntry $entry + * @return array + */ + protected function from_log_entry_to_sample($entry) { + return [ + "eventcount" => $entry->getEventCount(), + "trace" => $entry->getTrace(), + ]; + } + + /** + * Parse log to samples + * + * @param \ExcimerLog $log + * @return array + */ + protected function from_log_to_samples($log) { + $samples = []; + foreach ($log as $entry) { + $samples[] = $this->from_log_entry_to_sample($entry); + } + return $samples; + } + /** * Quick & dirty profile generator * @@ -93,7 +121,7 @@ public function quick_save(string $request, flamed3_node $node, int $reason, flo /** * Tests flamedata * - * @covers \tool_excimer\flamed3_node::from_excimer_log_entries + * @covers \tool_excimer\flamed3_node::from_sample_set_samples * @covers \tool_excimer\profile::get_flamedatad3json * @throws \coding_exception */ @@ -102,7 +130,7 @@ public function test_set_flamedata(): void { $log = $this->quick_log(10); $sampleset = new sample_set('name', 0); $sampleset->add_many_samples($log); - $node = flamed3_node::from_excimer_log_entries($sampleset->samples); + $node = flamed3_node::from_sample_set_samples($sampleset->samples); $nodejson = json_encode($node); $compressed = gzcompress($nodejson); $size = strlen($compressed); @@ -130,7 +158,7 @@ public function test_save(): void { $sampleset = new sample_set('name', 0); $sampleset->add_many_samples($log); - $node = flamed3_node::from_excimer_log_entries($sampleset->samples); + $node = flamed3_node::from_sample_set_samples($sampleset->samples); $flamedatad3json = json_encode($node); $numsamples = $node->value; $datasize = strlen(gzcompress($flamedatad3json)); @@ -178,7 +206,7 @@ public function test_partial_save(): void { $this->preventResetByRollback(); $log = $this->quick_log(1); // TODO change to use stubs. - $node = flamed3_node::from_excimer_log_entries($log); + $node = flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)); $flamedatad3json = json_encode($node); $reason = profile::REASON_SLOW; $created = 56; @@ -211,7 +239,7 @@ public function test_partial_save(): void { $this->assertEquals(getmypid(), $record->get('pid')); $log = $this->quick_log(2); - $node = flamed3_node::from_excimer_log_entries($log); + $node = flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)); $flamedatad3json = json_encode($node); $duration = 2.123; $usercpuduration = 1.2; @@ -257,7 +285,12 @@ public function test_reasons_are_being_stored(): void { foreach (profile::REASONS as $reason) { $allthereasons |= $reason; } - $id = $this->quick_save('mock', flamed3_node::from_excimer_log_entries($log), $allthereasons, 2.345); + $id = $this->quick_save( + 'mock', + flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)), + $allthereasons, + 2.345 + ); $record = $DB->get_record(profile::TABLE, ['id' => $id]); // Fetch profile from DB and confirm it matches for all the reasons. @@ -281,7 +314,12 @@ public function test_save_course(): void { // Trigger a log. $log = $this->quick_log(0); - $id = $this->quick_save('mock', flamed3_node::from_excimer_log_entries($log), profile::REASON_NONE, 2.345); + $id = $this->quick_save( + 'mock', + flamed3_node::from_sample_set_samples($this->from_log_to_samples($log)), + profile::REASON_NONE, + 2.345 + ); // Ensure the courseid was recorded correctly. $record = $DB->get_record(profile::TABLE, ['id' => $id]); diff --git a/tests/tool_excimer_sample_set_test.php b/tests/tool_excimer_sample_set_test.php index 8041b0a..c21bbae 100644 --- a/tests/tool_excimer_sample_set_test.php +++ b/tests/tool_excimer_sample_set_test.php @@ -37,9 +37,9 @@ final class tool_excimer_sample_set_test extends excimer_testcase { */ public function test_add_sample(): void { $samples = [ - $this->get_log_entry_stub(['a']), - $this->get_log_entry_stub(['b']), - $this->get_log_entry_stub(['c']), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['a'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['b'])), + $this->from_log_entry_to_sample($this->get_log_entry_stub(['c'])), ]; $set = new sample_set('a', 0, 1024); @@ -50,79 +50,89 @@ public function test_add_sample(): void { } /** - * Tests the effect of filtering while adding samples. + * Tests the effect of merging memory usage sample set while adding samples. * * @covers \tool_excimer\sample_set::add_many_samples * @covers \tool_excimer\sample_set::apply_doubling + * @covers \tool_excimer\sample_set::merge_memory_usage_sample_set */ - public function test_filtering(): void { + public function test_merge_memory_usage_sample_set(): void { $samples = [ - $this->get_log_entry_stub(['a']), - $this->get_log_entry_stub(['b']), - $this->get_log_entry_stub(['c']), - $this->get_log_entry_stub(['d']), + ['sampleindex' => 0, 'value' => 100000], + ['sampleindex' => 1, 'value' => 200000], + ['sampleindex' => 2, 'value' => 300000], + ['sampleindex' => 3, 'value' => 400000], + ['sampleindex' => 5, 'value' => 350000], ]; - // This is every 2nd element of $samples. $expected1 = [ - $samples[1], - $samples[3], + ['sampleindex' => 0, 'value' => 200000], + ['sampleindex' => 2, 'value' => 400000], + ['sampleindex' => 5, 'value' => 350000], ]; - // This is every 4th element of $samples. - $expected2 = [$samples[3]]; - $set = new sample_set('a', 0, 1024); + $expected2 = [ + ['sampleindex' => 0, 'value' => 400000], + ['sampleindex' => 5, 'value' => 350000], + ]; - // Each time this is called, the filter rate is doubled. - $set->apply_doubling(); + $expected3 = [ + ['sampleindex' => 0, 'value' => 400000], + ]; - // Filter rate should be 2, thus, only every 2nd sample should be recorded in sample set. + $set = new sample_set('a', 0, 1024); $set->add_many_samples($samples); - // Only every 2nd sample should be recorded in sample set. + $set->apply_doubling(true); $this->assertEquals($expected1, $set->samples); - $set = new sample_set('a', 0, 1024); - $set->apply_doubling(); - $set->apply_doubling(); - - // Filter rate should be 4, thus, only every 4th sample should be recorded in sample set. - $set->add_many_samples($samples); - + $set->apply_doubling(true); $this->assertEquals($expected2, $set->samples); + + $set->apply_doubling(true); + $this->assertEquals($expected3, $set->samples); } /** - * Tests stripping existing samples when calling apply_doubling. + * Tests the effect of merging memory usage sample set while adding samples. * * @covers \tool_excimer\sample_set::add_many_samples * @covers \tool_excimer\sample_set::apply_doubling + * @covers \tool_excimer\sample_set::merge_trace_sample_set */ - public function test_stripping(): void { + public function test_merge_trace_sample_set(): void { $samples = [ - $this->get_log_entry_stub(['a']), - $this->get_log_entry_stub(['b']), - $this->get_log_entry_stub(['c']), - $this->get_log_entry_stub(['d']), + $this->get_log_entry_stub(['a'], 0, 10), + $this->get_log_entry_stub(['b'], 0, 100), + $this->get_log_entry_stub(['c'], 0, 100), + $this->get_log_entry_stub(['d'], 0, 20), + $this->get_log_entry_stub(['e'], 0, 50), ]; - // This is $samples ofter being stripped once. $expected1 = [ - $samples[1], - $samples[3], + ['eventcount' => 55, 'trace' => [['function' => 'b']]], + ['eventcount' => 60, 'trace' => [['function' => 'c']]], + ['eventcount' => 50, 'trace' => [['function' => 'e']]], ]; - // This is $samples ofter being stripped twice. - $expected2 = [$samples[3]]; - $set = new sample_set('a', 0, 1024); + $expected2 = [ + ['trace' => [['function' => 'c']], 'eventcount' => 58], + ['trace' => [['function' => 'e']], 'eventcount' => 50], + ]; + $expected3 = [ + ['trace' => [['function' => 'c']], 'eventcount' => 54], + ]; + + $set = new sample_set('a', 0, 1024); $set->add_many_samples($samples); - // Every 2nd sample should be stripped after doubling. - $set->apply_doubling(); + $set->apply_doubling(false); $this->assertEquals($expected1, $set->samples); - // Half of the samples should be stripped again, leaving every 4th from the original. - $set->apply_doubling(); + $set->apply_doubling(false); $this->assertEquals($expected2, $set->samples); + + $set->apply_doubling(false); + $this->assertEquals($expected3, $set->samples); } /** @@ -132,33 +142,27 @@ public function test_stripping(): void { */ public function test_automatic_doubling_when_adding_samples(): void { $samples1 = [ - $this->get_log_entry_stub(['a']), - $this->get_log_entry_stub(['b']), - $this->get_log_entry_stub(['c']), - $this->get_log_entry_stub(['d']), - $this->get_log_entry_stub(['e']), - $this->get_log_entry_stub(['f']), + $this->get_log_entry_stub(['a'], 0, 10), + $this->get_log_entry_stub(['b'], 0, 100), + $this->get_log_entry_stub(['c'], 0, 100), + $this->get_log_entry_stub(['d'], 0, 20), + $this->get_log_entry_stub(['e'], 0, 50), ]; - // This is every second element of $samples1. $expected1 = [ - $samples1[1], - $samples1[3], - $samples1[5], + ['eventcount' => 55, 'trace' => [['function' => 'b']]], + ['eventcount' => 60, 'trace' => [['function' => 'c']]], + ['eventcount' => 50, 'trace' => [['function' => 'e']]], ]; $samples2 = [ - $this->get_log_entry_stub(['g']), - $this->get_log_entry_stub(['h']), - $this->get_log_entry_stub(['i']), - $this->get_log_entry_stub(['j']), - $this->get_log_entry_stub(['k']), - $this->get_log_entry_stub(['l']), + $this->get_log_entry_stub(['g'], 0, 10), + $this->get_log_entry_stub(['h'], 0, 20), + $this->get_log_entry_stub(['i'], 0, 10), ]; - // This is every 4th element of $sample1 + $sample2. + $expected2 = [ - $samples1[3], - $samples2[1], - $samples2[5], + ['eventcount' => 44, 'trace' => [['function' => 'c']]], + ['eventcount' => 15, 'trace' => [['function' => 'h']]], ]; $set = new sample_set('a', 0, 4); @@ -170,7 +174,7 @@ public function test_automatic_doubling_when_adding_samples(): void { $set->add_many_samples($samples2); - // By this point apply_doubling should have been invoked a second time. + // By this point apply_doubling should have been invoked two more times. $this->assertEquals($expected2, $set->samples); } diff --git a/version.php b/version.php index 37331da..87fd23f 100644 --- a/version.php +++ b/version.php @@ -25,8 +25,8 @@ defined('MOODLE_INTERNAL') || die(); -$plugin->version = 2025120903; -$plugin->release = 2025120903; +$plugin->version = 2025121000; +$plugin->release = 2025121000; $plugin->requires = 2023100900; // Moodle 4.3. $plugin->supported = [403, 405]; $plugin->component = 'tool_excimer';