[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() {
  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  
 445          // Mock a lock on the task.
 446          $lock = $this->getMockBuilder(\core\lock\lock::class)
 447              ->disableOriginalConstructor()
 448              ->getMock();
 449          $task->set_lock($lock);
 450  
 451          return $task;
 452      }
 453  
 454      /**
 455       * Get an example scheduled task to use for testing.
 456       *
 457       * @return  \core\task\scheduled_task
 458       */
 459      protected function get_test_scheduled_task() : \core\task\scheduled_task {
 460          $task = $this->getMockForAbstractClass(\core\task\scheduled_task::class);
 461  
 462          // Mock a lock on the task.
 463          $lock = $this->getMockBuilder(\core\lock\lock::class)
 464              ->disableOriginalConstructor()
 465              ->getMock();
 466          $task->set_lock($lock);
 467  
 468          return $task;
 469      }
 470  
 471      /**
 472       * Create and configure a mocked task logger.
 473       *
 474       * @return  \core\task\task_logger
 475       */
 476      protected function get_mocked_logger() {
 477          global $CFG;
 478  
 479          // We will modify config for the alternate logging class therefore we mnust reset after the test.
 480          $this->resetAfterTest();
 481  
 482          // Note PHPUnit does not support mocking static functions.
 483          $CFG->task_log_class = \task_logging_test_mocked_logger::class;
 484          \task_logging_test_mocked_logger::test_reset();
 485  
 486          return $CFG->task_log_class;
 487      }
 488  
 489      /**
 490       * Mock the database.
 491       */
 492      protected function mock_database() {
 493          global $DB;
 494  
 495          // Store the old Database for restoration in reset.
 496          $this->DB = $DB;
 497  
 498          $DB = $this->getMockBuilder(\moodle_database::class)
 499              ->getMock();
 500  
 501          $DB->method('get_record')
 502              ->willReturn((object) []);
 503      }
 504  }
 505  
 506  /**
 507   * Mocked logger.
 508   *
 509   * @copyright 2018 Andrew Nicols <andrew@nicols.co.uk>
 510   * @license   http://www.gnu.org/copyleft/gpl.html GNU GPL v3 or later
 511   */
 512  class task_logging_test_mocked_logger implements \core\task\task_logger {
 513  
 514      /**
 515       * @var bool Whether this is configured.
 516       */
 517      public static $isconfigured = true;
 518  
 519      /**
 520       * @var array Arguments that store_log_for_task was called with.
 521       */
 522      public static $storelogfortask = [];
 523  
 524      /**
 525       * @var bool Whether this logger has a report.
 526       */
 527      public static $haslogreport = true;
 528  
 529      /**
 530       * Reset the test class.
 531       */
 532      public static function test_reset() {
 533          self::$isconfigured = true;
 534          self::$storelogfortask = [];
 535          self::$haslogreport = true;
 536      }
 537  
 538      /**
 539       * Whether the task is configured and ready to log.
 540       *
 541       * @return  bool
 542       */
 543      public static function is_configured() : bool {
 544          return self::$isconfigured;
 545      }
 546  
 547      /**
 548       * Store the log for the specified task.
 549       *
 550       * @param   \core\task\task_base   $task The task that the log belongs to.
 551       * @param   string      $logpath The path to the log on disk
 552       * @param   bool        $failed Whether the task failed
 553       * @param   int         $dbreads The number of DB reads
 554       * @param   int         $dbwrites The number of DB writes
 555       * @param   float       $timestart The start time of the task
 556       * @param   float       $timeend The end time of the task
 557       */
 558      public static function store_log_for_task(\core\task\task_base $task, string $logpath, bool $failed,
 559              int $dbreads, int $dbwrites, float $timestart, float $timeend) {
 560          self::$storelogfortask[] = func_get_args();
 561      }
 562  
 563      /**
 564       * Whether this task logger has a report available.
 565       *
 566       * @return  bool
 567       */
 568      public static function has_log_report() : bool {
 569          return self::$haslogreport;
 570      }
 571  
 572      /**
 573       * Get any URL available for viewing relevant task log reports.
 574       *
 575       * @param   string      $classname The task class to fetch for
 576       * @return  \moodle_url
 577       */
 578      public static function get_url_for_task_class(string $classname) : \moodle_url {
 579          return new \moodle_url('');
 580      }
 581  
 582  }