-
Bug
-
Resolution: Fixed
-
Minor
-
4.0
-
MOODLE_400_STABLE
-
MOODLE_400_STABLE
-
MDL-73076-master -
-
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