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

Random "test_completion_criteria_duration" failure on slow envs.

XMLWordPrintable

    • 1
    • Team Omega 4.1 Sprint 0.1, Team Omega 4.1 Sprint 0.2

      This is is happening randomly @ CIs, specifically with Oracle. Also, have been able to reproduce it locally.

      Link: https://ci.moodle.org/view/B%20-%20master/job/W.01.05%20-%20PHPUnit%20-%20Oracle/1346/

      core_completion\core_completion_criteria_testcase::test_completion_criteria_duration
      Failed asserting that null matches expected 1620086400.
       
      /var/www/html/completion/tests/completion_criteria_test.php:128
      /var/www/html/lib/phpunit/classes/advanced_testcase.php:80
      

      Debugging the execution a little bit... it seems that, whenever the \core\task\completion_regular_task first run happens too late... then the user1 completion is calculated (normally none is in those first runs). And then, when the second run happens, the user2 completion is not calculated. To say it with other words, this is the output of a failing test(with the expectOutputRegex line commented out:

      Running completion_criteria_date->cron()
      Running completion_criteria_activity->cron()
      Running completion_criteria_duration->cron()
      Running completion_criteria_grade->cron()
      Running completion_criteria_course->cron()
      Aggregating completions
      Aggregating completions for user 3 in course 2
      Marking complete
      Running completion_criteria_date->cron()
      Running completion_criteria_activity->cron()
      Running completion_criteria_duration->cron()
      Running completion_criteria_grade->cron()
      Running completion_criteria_course->cron()
      Aggregating completions
       
       
      Time: 00:06.351, Memory: 585.00 MB
       
      There was 1 failure:
       
      1) core_completion\core_completion_criteria_testcase::test_completion_criteria_duration
      Failed asserting that null matches expected 1620086400.
      

      And this is the execution of a passing test:

      Running completion_criteria_date->cron()
      Running completion_criteria_activity->cron()
      Running completion_criteria_duration->cron()
      Running completion_criteria_grade->cron()
      Running completion_criteria_course->cron()
      Aggregating completions
      Running completion_criteria_date->cron()
      Running completion_criteria_activity->cron()
      Running completion_criteria_duration->cron()
      Running completion_criteria_grade->cron()
      Running completion_criteria_course->cron()
      Aggregating completions
      Aggregating completions for user 3 in course 2
      Marking complete
      Aggregating completions for user 4 in course 2
      Marking complete
       
       
      Time: 00:03.678, Memory: 585.00 MB

      You can see how the completions are calculated differently in the failing one (and it was a slow one, needing 6 seconds to complete) and the passing one (only 3 seconds).

      So it seems to be some timing problem reproducible when the 1st run happens "too late". Test shouldn't be dependent of that.

      Only detected with 4.0dev (and started ~ beginning of November 2021), but other branches may be affected (not verified).

      Ciao

            lameze Simey Lameze
            stronk7 Eloy Lafuente (stronk7)
            Paul Holden Paul Holden
            Sara Arjona (@sarjona) Sara Arjona (@sarjona)
            CiBoT CiBoT
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved:

                Estimated:
                Original Estimate - 0 minutes
                0m
                Remaining:
                Remaining Estimate - 0 minutes
                0m
                Logged:
                Time Spent - 2 days, 2 hours, 23 minutes
                2d 2h 23m

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