[Summary view]

Differences Between: [Versions 311 and 402] [Versions 400 and 402] [Versions 401 and 402]

   1  <?php
   2  // This file is part of Moodle - http://moodle.org/
   3  //
   4  // Moodle is free software: you can redistribute it and/or modify
   5  // it under the terms of the GNU General Public License as published by
   6  // the Free Software Foundation, either version 3 of the License, or
   7  // (at your option) any later version.
   8  //
   9  // Moodle is distributed in the hope that it will be useful,
  10  // but WITHOUT ANY WARRANTY; without even the implied warranty of
  11  // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  12  // GNU General Public License for more details.
  13  //
  14  // You should have received a copy of the GNU General Public License
  15  // along with Moodle.  If not, see <http://www.gnu.org/licenses/>.
  16  
  17  /**
  18   * This file contains the unit tests for the task logging system.
  19   *
  20   * @package   core
  21   * @category  test
  22   * @copyright 2018 Andrew Nicols <andrew@nicols.co.uk>
  23   * @license   http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later
  24   */
  25  
  26  namespace core\task;
  27  
  28  defined('MOODLE_INTERNAL') || die();
  29  require_once (__DIR__ . '/../fixtures/task_fixtures.php');
  30  
  31  /**
  32   * This file contains the unit tests for the task logging system.
  33   *
  34   * @package   core
  35   * @category  test
  36   * @copyright 2018 Andrew Nicols <andrew@nicols.co.uk>
  37   * @license   http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later
  38   */
  39  class logging_test extends \advanced_testcase {
  40  
  41      /**
  42       * @var \moodle_database The original database prior to mocking
  43       */
  44      protected $DB;
  45  
  46      /**
  47       * Relevant tearDown for logging tests.
  48       */
  49      public function tearDown(): void {
  50          global $DB;
  51  
  52          // Ensure that any logging is always ended.
  53          logmanager::finalise_log();
  54  
  55          if (null !== $this->DB) {
  56              $DB = $this->DB;
  57              $this->DB = null;
  58          }
  59      }
  60  
  61      /**
  62       * When the logmode is set to none, logging should not start.
  63       */
  64      public function test_logmode_none() {
  65          global $CFG;
  66          $this->resetAfterTest();
  67  
  68          $CFG->task_logmode = logmanager::MODE_NONE;
  69  
  70          $initialbufferstate = ob_get_status();
  71  
  72          $task = $this->get_test_adhoc_task();
  73          logmanager::start_logging($task);
  74  
  75          // There will be no additional output buffer.
  76          $this->assertEquals($initialbufferstate, ob_get_status());
  77      }
  78  
  79      /**
  80       * When the logmode is set to all that log capture is started.
  81       */
  82      public function test_start_logmode_all() {
  83          global $CFG;
  84          $this->resetAfterTest();
  85  
  86          $CFG->task_logmode = logmanager::MODE_ALL;
  87  
  88          $initialbufferstate = ob_get_status();
  89  
  90          $task = $this->get_test_adhoc_task();
  91          logmanager::start_logging($task);
  92  
  93          // Fetch the new output buffer state.
  94          $state = ob_get_status();
  95  
  96          // There will be no additional output buffer.
  97          $this->assertNotEquals($initialbufferstate, $state);
  98      }
  99  
 100      /**
 101       * When the logmode is set to fail that log capture is started.
 102       */
 103      public function test_start_logmode_fail() {
 104          global $CFG;
 105          $this->resetAfterTest();
 106  
 107          $CFG->task_logmode = logmanager::MODE_FAILONLY;
 108  
 109          $initialbufferstate = ob_get_status();
 110  
 111          $task = $this->get_test_adhoc_task();
 112          logmanager::start_logging($task);
 113  
 114          // Fetch the new output buffer state.
 115          $state = ob_get_status();
 116  
 117          // There will be no additional output buffer.
 118          $this->assertNotEquals($initialbufferstate, $state);
 119      }
 120  
 121      /**
 122       * When the logmode is set to fail, passing adhoc tests should not be logged.
 123       */
 124      public function test_logmode_fail_with_passing_adhoc_task() {
 125          global $CFG;
 126          $this->resetAfterTest();
 127  
 128          $CFG->task_logmode = logmanager::MODE_FAILONLY;
 129  
 130          $logger = $this->get_mocked_logger();
 131  
 132          $initialbufferstate = ob_get_status();
 133  
 134          $task = $this->get_test_adhoc_task();
 135          logmanager::start_logging($task);
 136  
 137          manager::adhoc_task_complete($task);
 138  
 139          $this->assertEmpty($logger::$storelogfortask);
 140      }
 141  
 142      /**
 143       * When the logmode is set to fail, passing scheduled tests should not be logged.
 144       */
 145      public function test_logmode_fail_with_passing_scheduled_task() {
 146          global $CFG;
 147          $this->resetAfterTest();
 148  
 149          $CFG->task_logmode = logmanager::MODE_FAILONLY;
 150  
 151          $logger = $this->get_mocked_logger();
 152  
 153          $initialbufferstate = ob_get_status();
 154  
 155          $task = $this->get_test_scheduled_task();
 156          logmanager::start_logging($task);
 157  
 158          manager::scheduled_task_complete($task);
 159  
 160          $this->assertEmpty($logger::$storelogfortask);
 161      }
 162  
 163      /**
 164       * When the logmode is set to fail, failing adhoc tests should be logged.
 165       */
 166      public function test_logmode_fail_with_failing_adhoc_task() {
 167          global $CFG;
 168  
 169          $this->resetAfterTest();
 170  
 171          // Mock the database. Marking jobs as failed updates a DB record which doesn't exist.
 172          $this->mock_database();
 173  
 174          $task = $this->get_test_adhoc_task();
 175  
 176          $CFG->task_logmode = logmanager::MODE_FAILONLY;
 177  
 178          $logger = $this->get_mocked_logger();
 179  
 180          logmanager::start_logging($task);
 181          manager::adhoc_task_failed($task);
 182  
 183          $this->assertCount(1, $logger::$storelogfortask);
 184          $this->assertEquals($task, $logger::$storelogfortask[0][0]);
 185          $this->assertTrue($logger::$storelogfortask[0][2]);
 186      }
 187  
 188      /**
 189       * When the logmode is set to fail, failing scheduled tests should be logged.
 190       */
 191      public function test_logmode_fail_with_failing_scheduled_task() {
 192          global $CFG;
 193  
 194          $this->resetAfterTest();
 195  
 196          // Mock the database. Marking jobs as failed updates a DB record which doesn't exist.
 197          $this->mock_database();
 198  
 199          $task = $this->get_test_scheduled_task();
 200  
 201          $CFG->task_logmode = logmanager::MODE_FAILONLY;
 202  
 203          $logger = $this->get_mocked_logger();
 204  
 205          logmanager::start_logging($task);
 206          manager::scheduled_task_failed($task);
 207  
 208          $this->assertCount(1, $logger::$storelogfortask);
 209          $this->assertEquals($task, $logger::$storelogfortask[0][0]);
 210          $this->assertTrue($logger::$storelogfortask[0][2]);
 211      }
 212  
 213      /**
 214       * When the logmode is set to fail, failing adhoc tests should be logged.
 215       */
 216      public function test_logmode_any_with_failing_adhoc_task() {
 217          global $CFG;
 218  
 219          $this->resetAfterTest();
 220  
 221          // Mock the database. Marking jobs as failed updates a DB record which doesn't exist.
 222          $this->mock_database();
 223  
 224          $task = $this->get_test_adhoc_task();
 225  
 226          $CFG->task_logmode = logmanager::MODE_FAILONLY;
 227  
 228          $logger = $this->get_mocked_logger();
 229  
 230          logmanager::start_logging($task);
 231          manager::adhoc_task_failed($task);
 232  
 233          $this->assertCount(1, $logger::$storelogfortask);
 234          $this->assertEquals($task, $logger::$storelogfortask[0][0]);
 235          $this->assertTrue($logger::$storelogfortask[0][2]);
 236      }
 237  
 238      /**
 239       * When the logmode is set to fail, failing scheduled tests should be logged.
 240       */
 241      public function test_logmode_any_with_failing_scheduled_task() {
 242          global $CFG;
 243  
 244          $this->resetAfterTest();
 245  
 246          // Mock the database. Marking jobs as failed updates a DB record which doesn't exist.
 247          $this->mock_database();
 248  
 249          $task = $this->get_test_scheduled_task();
 250  
 251          $CFG->task_logmode = logmanager::MODE_FAILONLY;
 252  
 253          $logger = $this->get_mocked_logger();
 254  
 255          logmanager::start_logging($task);
 256          manager::scheduled_task_failed($task);
 257  
 258          $this->assertCount(1, $logger::$storelogfortask);
 259          $this->assertEquals($task, $logger::$storelogfortask[0][0]);
 260          $this->assertTrue($logger::$storelogfortask[0][2]);
 261      }
 262  
 263      /**
 264       * When the logmode is set to fail, passing adhoc tests should be logged.
 265       */
 266      public function test_logmode_any_with_passing_adhoc_task() {
 267          global $CFG;
 268  
 269          $this->resetAfterTest();
 270  
 271          $this->mock_database();
 272  
 273          $task = $this->get_test_adhoc_task();
 274  
 275          $CFG->task_logmode = logmanager::MODE_ALL;
 276  
 277          $logger = $this->get_mocked_logger();
 278  
 279          logmanager::start_logging($task);
 280          manager::adhoc_task_complete($task);
 281  
 282          $this->assertCount(1, $logger::$storelogfortask);
 283          $this->assertEquals($task, $logger::$storelogfortask[0][0]);
 284          $this->assertFalse($logger::$storelogfortask[0][2]);
 285      }
 286  
 287      /**
 288       * When the logmode is set to fail, passing scheduled tests should be logged.
 289       */
 290      public function test_logmode_any_with_passing_scheduled_task() {
 291          global $CFG;
 292  
 293          $this->resetAfterTest();
 294  
 295          $this->mock_database();
 296  
 297          $task = $this->get_test_scheduled_task();
 298  
 299          $CFG->task_logmode = logmanager::MODE_ALL;
 300  
 301          $logger = $this->get_mocked_logger();
 302  
 303          logmanager::start_logging($task);
 304          manager::scheduled_task_complete($task);
 305  
 306          $this->assertCount(1, $logger::$storelogfortask);
 307          $this->assertEquals($task, $logger::$storelogfortask[0][0]);
 308          $this->assertFalse($logger::$storelogfortask[0][2]);
 309      }
 310  
 311      /**
 312       * Ensure that start_logging cannot be called in a nested fashion.
 313       */
 314      public function test_prevent_nested_logging() {
 315          $this->resetAfterTest();
 316  
 317          $task = $this->get_test_adhoc_task();
 318          logmanager::start_logging($task);
 319  
 320          $this->expectException(\coding_exception::class);
 321          logmanager::start_logging($task);
 322      }
 323  
 324      /**
 325       * Ensure that logging can be called after a previous log has finished.
 326       */
 327      public function test_repeated_usages() {
 328          $this->resetAfterTest();
 329  
 330          $logger = $this->get_mocked_logger();
 331  
 332          $task = $this->get_test_adhoc_task();
 333          logmanager::start_logging($task);
 334          logmanager::finalise_log();
 335  
 336          logmanager::start_logging($task);
 337          logmanager::finalise_log();
 338  
 339          $this->assertCount(2, $logger::$storelogfortask);
 340          $this->assertEquals($task, $logger::$storelogfortask[0][0]);
 341          $this->assertFalse($logger::$storelogfortask[0][2]);
 342          $this->assertEquals($task, $logger::$storelogfortask[1][0]);
 343          $this->assertFalse($logger::$storelogfortask[1][2]);
 344      }
 345  
 346      /**
 347       * Enusre that when finalise_log is called when logging is not active, nothing happens.
 348       */
 349      public function test_finalise_log_no_logging() {
 350          $initialbufferstate = ob_get_status();
 351  
 352          logmanager::finalise_log();
 353  
 354          // There will be no additional output buffer.
 355          $this->assertEquals($initialbufferstate, ob_get_status());
 356      }
 357  
 358      /**
 359       * When log capture is enabled, calls to the flush function should cause log output to be both returned and captured.
 360       */
 361      public function test_flush_on_own_buffer() {
 362          $this->resetAfterTest();
 363  
 364          $logger = $this->get_mocked_logger();
 365  
 366          $testoutput = "I am the output under test.\n";
 367  
 368          $task = $this->get_test_adhoc_task();
 369          logmanager::start_logging($task);
 370  
 371          echo $testoutput;
 372  
 373          $this->expectOutputString($testoutput);
 374          logmanager::flush();
 375  
 376          // Finalise the log.
 377          logmanager::finalise_log();
 378  
 379          $this->assertCount(1, $logger::$storelogfortask);
 380          $this->assertEquals($testoutput, file_get_contents($logger::$storelogfortask[0][1]));
 381      }
 382  
 383      /**
 384       * When log capture is enabled, calls to the flush function should not affect any subsequent ob_start.
 385       */
 386      public function test_flush_does_not_flush_inner_buffers() {
 387          $this->resetAfterTest();
 388  
 389          $logger = $this->get_mocked_logger();
 390  
 391          $testoutput = "I am the output under test.\n";
 392  
 393          $task = $this->get_test_adhoc_task();
 394          logmanager::start_logging($task);
 395  
 396          ob_start();
 397          echo $testoutput;
 398          ob_end_clean();
 399  
 400          logmanager::flush();
 401  
 402          // Finalise the log.
 403          logmanager::finalise_log();
 404  
 405          $this->assertCount(1, $logger::$storelogfortask);
 406  
 407          // The task logger should not have captured the content of the inner buffer.
 408          $this->assertEquals('', file_get_contents($logger::$storelogfortask[0][1]));
 409      }
 410  
 411      /**
 412       * When log capture is enabled, calls to the flush function should not affect any subsequent ob_start.
 413       */
 414      public function test_inner_flushed_buffers_are_logged() {
 415          $this->resetAfterTest();
 416  
 417          $logger = $this->get_mocked_logger();
 418  
 419          $testoutput = "I am the output under test.\n";
 420  
 421          $task = $this->get_test_adhoc_task();
 422          logmanager::start_logging($task);
 423  
 424          // We are going to flush the inner buffer. That means that we should expect the output immediately.
 425          $this->expectOutputString($testoutput);
 426  
 427          ob_start();
 428          echo $testoutput;
 429          ob_end_flush();
 430  
 431          // Finalise the log.
 432          logmanager::finalise_log();
 433  
 434          $this->assertCount(1, $logger::$storelogfortask);
 435  
 436          // The task logger should not have captured the content of the inner buffer.
 437          $this->assertEquals($testoutput, file_get_contents($logger::$storelogfortask[0][1]));
 438      }
 439  
 440      /**
 441       * Get an example adhoc task to use for testing.
 442       *
 443       * @return  adhoc_task
 444       */
 445      protected function get_test_adhoc_task() : adhoc_task {
 446          $task = $this->getMockForAbstractClass(adhoc_task::class);
 447          $task->set_component('core');
 448  
 449          // Mock a lock on the task.
 450          $lock = $this->getMockBuilder(\core\lock\lock::class)
 451              ->disableOriginalConstructor()
 452              ->getMock();
 453          $task->set_lock($lock);
 454  
 455          return $task;
 456      }
 457  
 458      /**
 459       * Get an example scheduled task to use for testing.
 460       *
 461       * @return  scheduled_task
 462       */
 463      protected function get_test_scheduled_task() : scheduled_task {
 464          $task = $this->getMockForAbstractClass(scheduled_task::class);
 465  
 466          // Mock a lock on the task.
 467          $lock = $this->getMockBuilder(\core\lock\lock::class)
 468              ->disableOriginalConstructor()
 469              ->getMock();
 470          $task->set_lock($lock);
 471  
 472          return $task;
 473      }
 474  
 475      /**
 476       * Create and configure a mocked task logger.
 477       *
 478       * @return  logging_test_mocked_logger
 479       */
 480      protected function get_mocked_logger() {
 481          global $CFG;
 482  
 483          // We will modify config for the alternate logging class therefore we mnust reset after the test.
 484          $this->resetAfterTest();
 485  
 486          // Note PHPUnit does not support mocking static functions.
 487          $CFG->task_log_class = logging_test_mocked_logger::class;
 488          logging_test_mocked_logger::test_reset();
 489  
 490          return $CFG->task_log_class;
 491      }
 492  
 493      /**
 494       * Mock the database.
 495       */
 496      protected function mock_database() {
 497          global $DB;
 498  
 499          // Store the old Database for restoration in reset.
 500          $this->DB = $DB;
 501  
 502          $DB = $this->getMockBuilder(\moodle_database::class)
 503              ->getMock();
 504  
 505          $DB->method('get_record')
 506              ->willReturn((object) []);
 507      }
 508  }
 509  
 510  /**
 511   * Mocked logger.
 512   *
 513   * @copyright 2018 Andrew Nicols <andrew@nicols.co.uk>
 514   * @license   http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later
 515   */
 516  class logging_test_mocked_logger implements task_logger {
 517  
 518      /**
 519       * @var bool Whether this is configured.
 520       */
 521      public static $isconfigured = true;
 522  
 523      /**
 524       * @var array Arguments that store_log_for_task was called with.
 525       */
 526      public static $storelogfortask = [];
 527  
 528      /**
 529       * @var bool Whether this logger has a report.
 530       */
 531      public static $haslogreport = true;
 532  
 533      /**
 534       * Reset the test class.
 535       */
 536      public static function test_reset() {
 537          self::$isconfigured = true;
 538          self::$storelogfortask = [];
 539          self::$haslogreport = true;
 540      }
 541  
 542      /**
 543       * Whether the task is configured and ready to log.
 544       *
 545       * @return  bool
 546       */
 547      public static function is_configured() : bool {
 548          return self::$isconfigured;
 549      }
 550  
 551      /**
 552       * Store the log for the specified task.
 553       *
 554       * @param   task_base   $task The task that the log belongs to.
 555       * @param   string      $logpath The path to the log on disk
 556       * @param   bool        $failed Whether the task failed
 557       * @param   int         $dbreads The number of DB reads
 558       * @param   int         $dbwrites The number of DB writes
 559       * @param   float       $timestart The start time of the task
 560       * @param   float       $timeend The end time of the task
 561       */
 562      public static function store_log_for_task(task_base $task, string $logpath, bool $failed,
 563              int $dbreads, int $dbwrites, float $timestart, float $timeend) {
 564          self::$storelogfortask[] = func_get_args();
 565      }
 566  
 567      /**
 568       * Whether this task logger has a report available.
 569       *
 570       * @return  bool
 571       */
 572      public static function has_log_report() : bool {
 573          return self::$haslogreport;
 574      }
 575  
 576      /**
 577       * Get any URL available for viewing relevant task log reports.
 578       *
 579       * @param   string      $classname The task class to fetch for
 580       * @return  \moodle_url
 581       */
 582      public static function get_url_for_task_class(string $classname) : \moodle_url {
 583          return new \moodle_url('');
 584      }
 585  
 586  }