Uploaded image for project: 'Moodle'
  1. Moodle
  2. MDL-56609

Random failure: core_scheduled_task_testcase::test_get_next_scheduled_task

XMLWordPrintable

    • MOODLE_30_STABLE, MOODLE_31_STABLE
    • MOODLE_310_STABLE, MOODLE_39_STABLE
    • Hide

      Requirements

      1. Be able to change your system clock.
      2. Be able to execute phpunit.

      Trying all different DST and current time cases.

      1. Set your computer to Europe/London timezone (this is not strictly needed, but it's the better way to have the specific times controlled below).
      2. Init phpunit: php admin/tool/phpunit/cli/init.php
      3. Repeat the following steps (#4 and #5) with your system/computer clock set to:
        1. Saturday 20th March 2021 23:00 (1w, 2h before DST begins)
        2. Saturday 27th March 2021 23:00 (2h before DST begins)
        3. Sunday 28th March 2021 00:30 (30m before DST begins)
        4. Sunday 28th March 2021 02:00 (exactly when DST begins)
        5. Sunday 28th March 2021 02:30 (30m after DST begins)
        6. Sunday 28th March 2021 04:00 (2h after DST begins).
        7. Sunday 4th April 2021 04:00 (1w, 2h after DST begins).
        8. Saturday 30th October 2021 23:00 (3h before DST ends)
        9. Sunday 31th October 2021 05:00 (3h after DST ends)
      4. Run vendor/bin/phpunit --filter test_get_next_scheduled_time
      5. Verify that the test passes.

      Note, without the patch applied, in case you are curious the cases 4, 5 and 6 (i.e. the same day, immediately after the DST change happens) are failing. This patch makes them pass (by correctly calculating the expectation).

      Also, note that all the Travis and GHA tests were executed in time (March 28th, DST Begin day) and they passed, that's another way to check the patch fixes the problem happening exclusively that day.

      Show
      Requirements Be able to change your system clock. Be able to execute phpunit. Trying all different DST and current time cases. Set your computer to Europe/London timezone (this is not strictly needed, but it's the better way to have the specific times controlled below). Init phpunit: php admin/tool/phpunit/cli/init.php Repeat the following steps (#4 and #5) with your system/computer clock set to: Saturday 20th March 2021 23:00 (1w, 2h before DST begins) Saturday 27th March 2021 23:00 (2h before DST begins) Sunday 28th March 2021 00:30 (30m before DST begins) Sunday 28th March 2021 02:00 (exactly when DST begins) Sunday 28th March 2021 02:30 (30m after DST begins) Sunday 28th March 2021 04:00 (2h after DST begins). Sunday 4th April 2021 04:00 (1w, 2h after DST begins). Saturday 30th October 2021 23:00 (3h before DST ends) Sunday 31th October 2021 05:00 (3h after DST ends) Run vendor/bin/phpunit --filter test_get_next_scheduled_time Verify that the test passes. Note, without the patch applied, in case you are curious the cases 4, 5 and 6 (i.e. the same day, immediately after the DST change happens) are failing. This patch makes them pass (by correctly calculating the expectation). Also, note that all the Travis and GHA tests were executed in time (March 28th, DST Begin day) and they passed, that's another way to check the patch fixes the problem happening exclusively that day.

      Reusing old issue

      I'm reusing this old issue, which failures we aren't getting anymore, to fix another problem related with test_get_next_scheduled_time() that is happening on Daylight Saving Time Begins dates of Europe/London (like today 28 March 2021).

      I've kept the original issue after the double line, for the records and search-ability, but as said, we haven't got it over the last years (that I remember).

      Problem

      The test_get_next_scheduled_time() test does try with Europe/London timezone, and it performs the test on current day at 01:00 AM. And that works ok for 364 days.

      But there is one day in the year (today, last Sunday of March), when that hour simply doesn't exist, because it's Daylight Saving Time Begins and, at 01:00, the clock changes to 02:00.

      Reproduce

      To reproduce it, just set your computer to Europe/London time, your clock to any time between 02:00 and 23:59, and run the --filter test_get_next_scheduled_time test. It will fail. Change to any other day of the year... and it will work perfectly.

      Explanation:

      That doesn't affect directly to the get_next_scheduled_time() because it will, correctly, return the next 01:00 date (Monday 01:00). But the expectation is wrong, because we are always expecting the next execution to happen 1 day (24h) after the previous one, but the day of Daylight Saving Time Begins, the next execution is only 1 day less 1 hour (23h) after the previous one (because the DST change "eats" the hour between 01:00 and 01:59).

      Note this doesn't affect the Daylight Saving Time Ends (October) because that day, 01:00 exists without problem, and both the get_next_scheduled_time() and the DateInterval expectation (1 day) are correct.

      So this is about to detect when we are in the Daylight Saving Time Begins day... and then change the expectation to be correct (1 day less 1 hour). And then verify that it works for any day of the year, not only for current 364.



      Original issue description

      Following was observed today for the first time on nightly

      1) core_scheduled_task_testcase::test_get_next_scheduled_task
      Failed asserting that core\task\scheduled_test_task Object (...) is an instance of class "\core\task\scheduled_test2_task".
       
      /var/www/html/moodle/lib/tests/scheduled_task_test.php:309
      /var/www/html/moodle/lib/phpunit/classes/advanced_testcase.php:80
       
      To re-run:
       vendor/bin/phpunit core_scheduled_task_testcase lib/tests/scheduled_task_test.php
       
      FAILURES!
      Tests: 5438, Assertions: 69297, Failures: 1, Skipped: 20.
       
      Notice: Trying to get property of non-object in /var/www/html/moodle/lib/classes/string_manager_standard.php on line 135
      PHP Notice:  Trying to get property of non-object in /var/www/html/moodle/lib/classes/string_manager_standard.php on line 135
      PHP Fatal error:  Uncaught exception 'coding_exception' with message 'debug/codingerror
      $a contents: A lock was created but not released at:
      /var/www/html/moodle/lib/classes/task/manager.php on line 458
       
       Code should look like:
       
       $factory = \core\lock\lock_config::get_lock_factory('type');
       $lock = $factory->get_lock(Resource id #2031382);
       $lock->release();  // Locks must ALWAYS be released like this.
       
      ' in /var/www/html/moodle/lib/classes/lock/lock.php:117
      Stack trace:
      #0 [internal function]: core\lock\lock->__destruct()
      #1 {main}
        thrown in /var/www/html/moodle/lib/classes/lock/lock.php on line 117
       
      Fatal error: Uncaught exception 'coding_exception' with message 'debug/codingerror
      $a contents: A lock was created but not released at:
      /var/www/html/moodle/lib/classes/task/manager.php on line 458
       
       Code should look like:
       
       $factory = \core\lock\lock_config::get_lock_factory('type');
       $lock = $factory->get_lock(Resource id #2031382);
       $lock->release();  // Locks must ALWAYS be released like this.
       
      ' in /var/www/html/moodle/lib/classes/lock/lock.php:117
      Stack trace:
      #0 [internal function]: core\lock\lock->__destruct()
      #1 {main}
        thrown in /var/www/html/moodle/lib/classes/lock/lock.php on line 117
      Build step 'Execute shell' marked build as failure
      

            stronk7 Eloy Lafuente (stronk7)
            rajeshtaneja Rajesh Taneja
            Tim Hunt Tim Hunt
            Andrew Lyons Andrew Lyons
            Gladys Basiana Gladys Basiana
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Created:
              Updated:
              Resolved:

                Estimated:
                Original Estimate - Not Specified
                Not Specified
                Remaining:
                Remaining Estimate - 0 minutes
                0m
                Logged:
                Time Spent - 4 hours, 25 minutes
                4h 25m

                  Error rendering 'clockify-timesheets-time-tracking-reports:timer-sidebar'. Please contact your Jira administrators.