[Summary view]

Differences Between: [Versions 39 and 310]

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