From 373ffe586c62ca763ad271f42f67cbf18a48f494 Mon Sep 17 00:00:00 2001 From: Matthew Hilton Date: Mon, 18 Nov 2024 08:33:09 +1000 Subject: [PATCH] [#203] Improve error log ping unit tests --- classes/lib.php | 22 +++++++++++++++------- tests/lib_test.php | 38 ++++++++++++++++++++++---------------- version.php | 4 ++-- 3 files changed, 39 insertions(+), 25 deletions(-) diff --git a/classes/lib.php b/classes/lib.php index fb48b19..7ec7893 100644 --- a/classes/lib.php +++ b/classes/lib.php @@ -105,8 +105,13 @@ public static function record_cache_checked(int $valueincache, int $valueindb, s * Handles error logging pinging. This happens on a regular schedule e.g. every 30 mins. * This is used in conjunction with external monitoring services to monitor if the error log is fresh * (or alternatively if it is stale, because the logs are not coming through anymore). + * @param int|null $time if null uses current time, else you can pass in a time here (usually for unit tests) */ - public static function process_error_log_ping() { + public static function process_error_log_ping(?int $time = null) { + if (is_null($time)) { + $time = time(); + } + $lastpinged = get_config('tool_heartbeat', 'errorloglastpinged') ?: 0; $errorperiod = get_config('tool_heartbeat', 'errorlog'); @@ -115,17 +120,20 @@ public static function process_error_log_ping() { return; } - if (($lastpinged + $errorperiod) < time()) { + if (empty($lastpinged) || ($lastpinged + $errorperiod) < $time) { // Update the last pinged time. - set_config('errorloglastpinged', time(), 'tool_heartbeat'); + set_config('errorloglastpinged', $time, 'tool_heartbeat'); // Log to error_log. - $now = userdate(time()); + $now = userdate($time); $period = format_time($errorperiod); - // @codingStandardsIgnoreStart - error_log("Heartbeat error log test $now, next test expected in $period"); - // @codingStandardsIgnoreEnd + // Don't error log during unit tests. + if (!PHPUNIT_TEST) { + // @codingStandardsIgnoreStart + error_log("Heartbeat error log test $now, next test expected in $period"); + // @codingStandardsIgnoreEnd + } } } } diff --git a/tests/lib_test.php b/tests/lib_test.php index 9858aa3..3692f0a 100644 --- a/tests/lib_test.php +++ b/tests/lib_test.php @@ -57,25 +57,33 @@ public function process_error_log_ping_provider(): array { 'no period set - disabled' => [ 'errorloglastpinged' => null, 'errorlog' => null, - 'expectedtimebefore' => null, + 'expectedtime' => null, + 'testtime' => 1, ], 'only period set' => [ 'errorloglastpinged' => null, 'errorlog' => 1 * MINSECS, - // Update to latest time. - 'expectedtimebefore' => time() + 10, + // No last ping, so should update to the current time. + 'expectedtime' => 1, + 'testtime' => 1, ], 'period has passed, time should change' => [ 'errorloglastpinged' => 1, 'errorlog' => 1 * MINSECS, - // Update to latest time. - 'expectedtimebefore' => time() + 10, + // Test time is > last pinged + error log period, + // so should set to the current time. + 'expectedtime' => 100, + // 100 seconds is > 1 min. + 'testtime' => 100, ], 'period not passed yet, time unchanged' => [ - 'errorloglastpinged' => time(), + 'errorloglastpinged' => 1, 'errorlog' => 1 * MINSECS, - // Remain unchanged, i.e. exactly equal. - 'expectedtimebefore' => time(), + // Test time is < last linged + error log period, + // so should leave it unchanged. + 'expectedtime' => 1, + // 30 seconds is < 1 min. + 'testtime' => 30, ], ]; } @@ -85,25 +93,23 @@ public function process_error_log_ping_provider(): array { * * @param int|null $errorloglastpinged next error value to set * @param int|null $errorlog error log value to set - * @param bool $expectrun + * @param int|null $expectedtime the time expected to be set + * @param int $testtime time to use for unit test (so it is deterministic) * @dataProvider process_error_log_ping_provider */ - public function test_process_error_log_ping(?int $errorloglastpinged, ?int $errorlog, ?int $expectedtimebefore) { + public function test_process_error_log_ping(?int $errorloglastpinged, ?int $errorlog, ?int $expectedtime, int $testtime) { $this->resetAfterTest(true); set_config('errorloglastpinged', $errorloglastpinged, 'tool_heartbeat'); set_config('errorlog', $errorlog, 'tool_heartbeat'); - lib::process_error_log_ping(); + lib::process_error_log_ping($testtime); $valueafter = get_config('tool_heartbeat', 'errorloglastpinged'); // Assert the time was not set at all. - if (is_null($expectedtimebefore)) { + if (is_null($expectedtime)) { $this->assertFalse($valueafter); } else { - // New value should have set current time as the last pinged time. - // We use less than and add some buffer in the test cases to account - // for tests that might happen over a few seconds. - $this->assertLessThanOrEqual($expectedtimebefore, $valueafter); + $this->assertEquals($expectedtime, $valueafter); } } } diff --git a/version.php b/version.php index 4ae0b96..c73d402 100644 --- a/version.php +++ b/version.php @@ -24,8 +24,8 @@ defined('MOODLE_INTERNAL') || die(); -$plugin->version = 2024111400; -$plugin->release = 2024111400; // Match release exactly to version. +$plugin->version = 2024111800; +$plugin->release = 2024111800; // Match release exactly to version. $plugin->requires = 2020061500; // Support for 3.9 and above, due to the Check API. $plugin->supported = [39, 404]; $plugin->component = 'tool_heartbeat';