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

Random unit test failures related with file information

XMLWordPrintable

    • MOODLE_25_STABLE, MOODLE_26_STABLE, MOODLE_27_STABLE
    • MOODLE_26_STABLE, MOODLE_27_STABLE
    • wip-mdl-45204-m
    • Hide

      Run below without patch, if you reproduce the failure, then try below with patch, else increase repeat.
      vendor/bin/phpunit --stop-on-failure --repeat=1000 core_setuplib_testcase

      Show
      Run below without patch, if you reproduce the failure, then try below with patch, else increase repeat. vendor/bin/phpunit --stop-on-failure --repeat=1000 core_setuplib_testcase

      Along the last days, I've been performing a lot of unit tests runs, in parallel, putting the laptop under stress and I've seen this a bunch of times:

      1) core_setuplib_testcase::test_localcachedir
      Time is lower that allowed start value
      Failed asserting that 1398075623 is equal to 1398075624 or is greater than 1398075624.
       
      /Users/stronk7/git_moodle/integration/lib/phpunit/classes/advanced_testcase.php:396
      /Users/stronk7/git_moodle/integration/lib/tests/setuplib_test.php:162
      /Users/stronk7/git_moodle/integration/lib/phpunit/classes/advanced_testcase.php:80
       
      To re-run:
       vendor/bin/phpunit core_setuplib_testcase lib/tests/setuplib_test.php
      

      More yet, executing the same test alone, N times, I also have been able to reproduce it randomly (like 1 time every 500-600 executions, but my SSD is pretty fast, surely it happens often is slower disks).

      vendor/bin/phpunit --repeat=100 core_setuplib_testcase
      Moodle 2.7beta+ (Build: 20140417), mssql, c8ca0cea7712b6c2aaecaeafaeee8132b293608a
      PHPUnit 3.7.34 by Sebastian Bergmann.
       
      Configuration read from /Users/stronk7/git_moodle/integration/phpunit.xml
       
      ...............................................................  63 / 800 (  7%)
      ............................................................... 126 / 800 ( 15%)
      ............................................................... 189 / 800 ( 23%)
      ............................................................... 252 / 800 ( 31%)
      ............................................................... 315 / 800 ( 39%)
      ............................................................... 378 / 800 ( 47%)
      ............................................................... 441 / 800 ( 55%)
      ............................................................... 504 / 800 ( 63%)
      ......................................F........................ 567 / 800 ( 70%)
      ............................................................... 630 / 800 ( 78%)
      ............................................................... 693 / 800 ( 86%)
      ............................................................... 756 / 800 ( 94%)
      ............................................
       
      Time: 1.36 minutes, Memory: 110.25Mb
       
      There was 1 failure:
       
      1) core_setuplib_testcase::test_localcachedir
      Time is lower that allowed start value
      Failed asserting that 1398075623 is equal to 1398075624 or is greater than 1398075624.
       
      /Users/stronk7/git_moodle/integration/lib/phpunit/classes/advanced_testcase.php:396
      /Users/stronk7/git_moodle/integration/lib/tests/setuplib_test.php:162
      /Users/stronk7/git_moodle/integration/lib/phpunit/classes/advanced_testcase.php:80
       
      To re-run:
       vendor/bin/phpunit core_setuplib_testcase lib/tests/setuplib_test.php
       
      FAILURES!
      Tests: 800, Assertions: 7463, Failures: 1.
      

      The only reason I can imagine is the filemtime() call in test_localcachedir() returning sort of cached (old) data.

      So I've tried adding a clearstatcache() call:

      • at the end of reset_all_data() => random failures continued.
      • at the end of make_localcache_directory(), unconditionally => random failures continued.
      • before the call to filemtime() in test_localcachedir(), global and applied to the .lastpurged file only => random failures continued.

      So it seems that cleaning the caches is not enough and, for some reason the .lastpurged file is older than time(). So in some way... it's truly being created early or filemtime() has a different "rounding" algorithm... something nasty is going there.

      My last attempt was to add to test_localcachedir():

      > unlink($timestampfile);
      $dir = make_localcache_directory('', false);
      ...
      

      And with that I've got > 10000 executions without error. But I'm not entirely happy putting that there.

      So, for your consideration... perhaps we should consider both deleting that file and performing the clearstatcache() call in reset_all_data, or perhaps within make_localcache_directory() or perhaps it's ok to put it there in the test... don't know.

      Ciao

            rajeshtaneja Rajesh Taneja
            stronk7 Eloy Lafuente (stronk7)
            Damyon Wiese Damyon Wiese
            Marina Glancy Marina Glancy
            Mark Nelson Mark Nelson
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved:

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