Random failures of ProgressPrinter

[gndk]

Q	A
ParaTest version	7.0.6
PHPUnit version	10.0.7
PHP version	8.2.3

Summary

I get random failures of ProgressPrinter, both locally and on CI. They only happen when running the tests with paratest, not phpunit itself, so I'm opening the issue here. Unfortunately I could not reliably reproduce it yet. See output below:

php vendor/bin/paratest -c phpunit-unit.xml --runner WrapperRunner
ParaTest v7.0.6 upon PHPUnit 10.0.7 by Sebastian Bergmann and contributors.

Warming cache for static analysis ... [00:00.290]
Processes:     4
Runtime:       PHP 8.2.3 with PCOV 1.0.11
Configuration: phpunit-unit.xml
Random Seed:   1676732627

.............................................................   61 / 1129 (  5%)
.............................................................  122 / 1129 ( 10%)
.............................................................  183 / 1129 ( 16%)
.............................................................  244 / 1129 ( 21%)
.............................................................  305 / 1129 ( 27%)
.............................................................  366 / 1129 ( 32%)
.............................................................  427 / 1129 ( 37%)
.............................................................  488 / 1129 ( 43%)
.............................................................  549 / 1129 ( 48%)
.............................................................  610 / 1129 ( 54%)
.............................................................  671 / 1129 ( 59%)
.............................................................  732 / 1129 ( 64%)
..............................................
In WorkerCrashedException.php line 41:

  The test "PARATEST='1' TEST_TOKEN='1' UNIQUE_TEST_TOKEN='1_63f0e8d46fda6' tests/Unit/Infrastructure/Doctrine/DBAL
  /Types/IdTypeTest.php" failed.

  Exit Code: 255(Unknown error)

  Working directory: /srv/share

  Output:
  ================


  Error Output:
  ================
  PHP Fatal error:  Uncaught ValueError: str_repeat(): Argument #2 ($times) must be greater than or equal to 0 in /
  srv/share/vendor/phpunit/phpunit/src/TextUI/Output/Default/ProgressPrinter/ProgressPrinter.php:256
  Stack trace:
  #0 /srv/share/vendor/phpunit/phpunit/src/TextUI/Output/Default/ProgressPrinter/ProgressPrinter.php(256): str_repe
  at()
  #1 /srv/share/vendor/phpunit/phpunit/src/TextUI/Output/Default/ProgressPrinter/ProgressPrinter.php(195): PHPUnit\
  TextUI\Output\Default\ProgressPrinter\ProgressPrinter->printProgress()
  #2 /srv/share/vendor/phpunit/phpunit/src/TextUI/Output/Default/ProgressPrinter/ProgressPrinter.php(133): PHPUnit\
  TextUI\Output\Default\ProgressPrinter\ProgressPrinter->printProgressForSuccess()
  #3 /srv/share/vendor/phpunit/phpunit/src/TextUI/Output/Default/ProgressPrinter/Subscriber/TestFinishedSubscriber.
  php(22): PHPUnit\TextUI\Output\Default\ProgressPrinter\ProgressPrinter->testFinished()
  #4 /srv/share/vendor/phpunit/phpunit/src/Event/Dispatcher/DirectDispatcher.php(91): PHPUnit\TextUI\Output\Default
  \ProgressPrinter\TestFinishedSubscriber->notify()
  #5 /srv/share/vendor/phpunit/phpunit/src/Event/Dispatcher/DeferringDispatcher.php(45): PHPUnit\Event\DirectDispat
  cher->dispatch()
  #6 /srv/share/vendor/phpunit/phpunit/src/Event/Emitter/DispatchingEmitter.php(843): PHPUnit\Event\DeferringDispat
  cher->dispatch()
  #7 /srv/share/vendor/phpunit/phpunit/src/Framework/TestRunner.php(238): PHPUnit\Event\DispatchingEmitter->testFin
  ished()
  #8 /srv/share/vendor/phpunit/phpunit/src/Framework/TestCase.php(448): PHPUnit\Framework\TestRunner->run()
  #9 /srv/share/vendor/phpunit/phpunit/src/Framework/TestSuite.php(352): PHPUnit\Framework\TestCase->run()
  #10 /srv/share/vendor/phpunit/phpunit/src/Framework/TestSuite.php(352): PHPUnit\Framework\TestSuite->run()
  #11 /srv/share/vendor/brianium/paratest/src/WrapperRunner/ApplicationForWrapperWorker.php(72): PHPUnit\Framework\
  TestSuite->run()
  #12 /srv/share/vendor/brianium/paratest/bin/phpunit-wrapper.php(69): ParaTest\WrapperRunner\ApplicationForWrapper
  Worker->runTest()
  #13 /srv/share/vendor/brianium/paratest/bin/phpunit-wrapper.php(74): {closure}()
  #14 {main}
    thrown in /srv/share/vendor/phpunit/phpunit/src/TextUI/Output/Default/ProgressPrinter/ProgressPrinter.php on li
  ne 256

PHPUnit config:

<?xml version="1.0" encoding="UTF-8"?>
<!-- https://phpunit.readthedocs.io/en/10.0/ -->
<phpunit xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:noNamespaceSchemaLocation="vendor/phpunit/phpunit/phpunit.xsd"
         bootstrap="vendor/autoload.php"
         requireCoverageMetadata="true"
         beStrictAboutOutputDuringTests="true"
         beStrictAboutTodoAnnotatedTests="true"
         beStrictAboutChangesToGlobalState="true"
         executionOrder="random"
         failOnIncomplete="true"
         failOnRisky="true"
         failOnSkipped="true"
         failOnWarning="true"
         colors="true"
         cacheDirectory=".cache/phpunit/unit"
>
    <php>
        <ini name="error_reporting" value="-1"/>
        <server name="APP_ENV" value="test" force="true"/>
        <server name="SHELL_VERBOSITY" value="-1"/>
        <!-- define your env variables for the test in .env.test and not here -->
    </php>

    <testsuites>
        <testsuite name="Unit">
            <directory>tests/Unit</directory>
        </testsuite>
    </testsuites>

    <coverage>
        <include>
            <directory suffix=".php">src</directory>
        </include>
        <report>
            <html outputDirectory="./coverage-unit"/>
            <cobertura outputFile="./cobertura-unit.xml"/>
        </report>
    </coverage>

    <logging>
        <junit outputFile="junit-unit.xml"/>
    </logging>
</phpunit>

[Slamdunk]

Mmm, I see this can happen, but impossible for me to debug and fix it without a reproducible environment.

Can you try to log to a file the content of these 3 variables:

1. \PHPUnit\TextUI\Output\Default\ProgressPrinter\ProgressPrinter::$numberOfTests
2. \PHPUnit\TextUI\Output\Default\ProgressPrinter\ProgressPrinter::$numberOfTestsWidth
3. \PHPUnit\TextUI\Output\Default\ProgressPrinter\ProgressPrinter::$maxColumn

Just after they have been set in \PHPUnit\TextUI\Output\Default\ProgressPrinter\ProgressPrinter::testRunnerExecutionStarted, and post here their value right before you get the error?

[gndk]

Yea, unfortunately very hard to reproduce. Of course it hasn't happened again since I opened the issue 🙄 . I'll try to implement the logging you suggested in a fork to do it "passively".

My suspicion is that it could be related to data providers, because the IdTypeTest.php file that it failed in contains a few tests that each run with a relatively big number of arguments from a data provider.

So maybe the end of the column is calculated wrong in tests with data provider? And with random order set in phpunit config, it only fails in very few cases when the test is in the "wrong" position in the progress printer.

If I have some time in the next few days I'll try to create a reproducer.

[mxsxs2]

Hi,
It always happening in our case.

Here is the output. @Slamdunk I logged those values to the screen you asked for.

Running tests parallel.
ParaTest v7.0.6 upon PHPUnit 10.0.11 by Sebastian Bergmann and contributors.

Warming cache for static analysis ... [00:00.013]
Processes: 8
Runtime: PHP 8.2.3 with Xdebug 3.2.0
Configuration: phpunit.xml

In WorkerCrashedException.php line 41:

The test "PARATEST='1' TEST_TOKEN='1' UNIQUE_TEST_TOKEN='1_63f77c03664e4' tests/php/Feature/AdministrationControllerTest.php" failed.

Exit Code: 255(Unknown error)

Working directory: /var/www/html

Output:

array(3) {
["numberOfTests"]=>
int(2)
["numberOfTestsWidth"]=>
int(1)
["maxColumn"]=>
int(107)
}

Fatal error: Uncaught AssertionError: assert($this->currentTestCase !== null) in /var/www/html/vendor/phpunit/phpunit/src/Logging/JUnit/JunitXmlLogger.php:298

[Slamdunk]

Fatal error: Uncaught AssertionError: assert($this->currentTestCase !== null) in /var/www/html/vendor/phpunit/phpunit/src/Logging/JUnit/JunitXmlLogger.php:298

This is an unrelated error, just fixed in sebastianbergmann/phpunit#5251 (but still unreleased at the time of writing)

[mxsxs2]

@Slamdunk My bad. Thanks!

[gndk]

I had some more errors today, all occurred in the same file, so at least theres hope to reproduce it 🤞

[github-actions]

This issue has gone two months without activity. In another two weeks, I will close it.

But! If you comment or otherwise update it, I will reset the clock, and if you label it Backlog or In Progress, I will leave it alone ... forever!