Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Performance issue running coverage on Windows #1062

Open
jrfnl opened this issue Feb 7, 2025 · 27 comments
Open

Performance issue running coverage on Windows #1062

jrfnl opened this issue Feb 7, 2025 · 27 comments

Comments

@jrfnl
Copy link
Contributor

jrfnl commented Feb 7, 2025

Q A
PHPUnit version 12.0.1
PHP version 8.4
Installation Method PHAR (but probably Composer to)

Summary

I'm seeing a significant performance slow-down when using PHPUnit 12 for path/branch coverage versus PHPUnit 11 when running on Windows (10).

When running just one test class (filtered down), I see a difference of 3 vs 50 seconds.

The slow-down appears to be at the start, before progress is being shown.

Current behavior

$ phpunit11 -c phpunit10.xml --filter AssertObjectNotEquals

PHPUnit 11.5.7 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: path/to/PHPUnit-Polyfills/phpunit10.xml

.........S.....S.......                                           23 / 23 (100%)

Time: 00:03.563, Memory: 376.00 MB

OK, but some tests were skipped!
Tests: 23, Assertions: 48, Skipped: 2.

Generating code coverage report in HTML format ... done [00:00.741]


Code Coverage Report Summary:
  Classes:  4.55% (1/22)
  Methods:  4.41% (6/136)
  Paths:    5.94% (6/101)
  Branches:    5.00% (6/120)
  Lines:    1.80% (10/555)
$ phpunit12 -c phpunit10.xml --filter AssertObjectNotEquals

PHPUnit 12.0.1 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: path/to/PHPUnit-Polyfills/phpunit10.xml

.........S.....S.......                                           23 / 23 (100%)

Time: 00:50.153, Memory: 370.00 MB

OK, but some tests were skipped!
Tests: 23, Assertions: 48, Skipped: 2.

Generating code coverage report in HTML format ... done [00:00.422]


Code Coverage Report Summary:
  Classes:  4.55% (1/22)
  Methods:  4.41% (6/136)
  Paths:    7.32% (6/82)
  Branches:    6.19% (6/97)
  Lines:    1.80% (10/555)

How to reproduce

If I run with --debug on, it looks like the test suite "hangs" between "Test Passed" and "Test Finished"

Test Runner Execution Started (23 tests)
Test Suite Started (path/to/PHPUnit-Polyfills/phpunit10.xml, 23 tests)
Test Suite Started (PHPUnitPolyfills, 23 tests)
Test Suite Started (Yoast\PHPUnitPolyfills\Tests\Polyfills\AssertObjectNotEqualsTest, 21 tests)
Test Preparation Started (Yoast\PHPUnitPolyfills\Tests\Polyfills\AssertObjectNotEqualsTest::testAssertObjectNotEquals)
Test Prepared (Yoast\PHPUnitPolyfills\Tests\Polyfills\AssertObjectNotEqualsTest::testAssertObjectNotEquals)
Test Passed (Yoast\PHPUnitPolyfills\Tests\Polyfills\AssertObjectNotEqualsTest::testAssertObjectNotEquals)

....hanging....

Test Finished (Yoast\PHPUnitPolyfills\Tests\Polyfills\AssertObjectNotEqualsTest::testAssertObjectNotEquals)
Test Preparation Started (Yoast\PHPUnitPolyfills\Tests\Polyfills\AssertObjectNotEqualsTest::testAssertObjectNotEqualsCustomMethodName)

Reproducible via the https://github.com/Yoast/PHPUnit-Polyfills repo (though I'm still making some updates for PHPUnit 12 compatibility, which will be pulled soonish).

Expected behavior

No significant slow-down in performance.

@jrfnl jrfnl added the type/bug label Feb 7, 2025
@sebastianbergmann sebastianbergmann changed the title PHPUnit 12 | Performance issue running coverage on Windows Performance issue running coverage on Windows Feb 8, 2025
@sebastianbergmann
Copy link
Owner

There have been no changes (that I am aware of) that are specific to branch/path coverage.

From your --debug output (thank you for that!) I assume that it always hangs after the execution of the first test has finished. After "Test Passed" and before "Test Finished" the collection of code coverage data is stopped and the collected data is processed. The first code coverage data is processed during the execution of a test suite there is now additional static analysis performed which could explain the "hanging". However, this static analysis is the same regardless of whether branch/path coverage is enabled or not. The implementation of https://github.com/sebastianbergmann/php-code-coverage/blob/main/src/Target/MapBuilder.php is not optimized and its result is not yet cached, I have this on my TODO for after the release anyway.

Before I go down the wrong rabbit hole, can you please check whether you also get the "hanging" when branch/path coverage is disabled?

@sebastianbergmann sebastianbergmann transferred this issue from sebastianbergmann/phpunit Feb 8, 2025
@sebastianbergmann
Copy link
Owner

@staabm Can you have a look at https://github.com/sebastianbergmann/php-code-coverage/blob/main/src/Target/MapBuilder.php and see if/how this could be optimized? Thanks!

@staabm
Copy link
Contributor

staabm commented Feb 8, 2025

I can have a look after Juliette pushed the phpunit 12 changes for the reproducer

@sebastianbergmann
Copy link
Owner

I can have a look after Juliette pushed the phpunit 12 changes for the reproducer

I think any project can be used to look into the performance of MapBuilder. And the map it builds is the same for PCOV and Xdebug.

@staabm
Copy link
Contributor

staabm commented Feb 8, 2025

I was not yet able to reproduce the slow run on https://github.com/Yoast/PHPUnit-Polyfills (I have no experience with branch coverage):

➜  PHPUnit-Polyfills git:(3.x) ✗ vendor/bin/phpunit -c phpunit10.xml.dist --filter AssertObjectNotEquals --path-coverage
PHPUnit 12.0.1 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.3.16 with Xdebug 3.4.1
Configuration: /Users/staabm/workspace/PHPUnit-Polyfills/phpunit10.xml.dist

WWWWWWWWWSSWWSWSWWWWW..                                           23 / 23 (100%)

Time: 00:00.732, Memory: 158.00 MB

do you think we can trigger the slow path without xdebug beeing loaded (e.g. with pre-recorded information)?

running blackfire and xdebug in the same process usually doesn't work, as these step onto each others feet.

@sebastianbergmann
Copy link
Owner

I think we should wait until Juliette answered my "can you please check whether you also get the "hanging" when branch/path coverage is disabled?" question. I am almost certain that this is not related to branch/path coverage.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

Before I go down the wrong rabbit hole, can you please check whether you also get the "hanging" when branch/path coverage is disabled?

@sebastianbergmann I've just checked and with only line coverage and filtered down to one test class, I see a small, but not a significant slow down.


Logs
$ phpunit11 -c phpunit10.xml --filter AssertObjectNotEquals

PHPUnit 11.5.7 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: path/to/PHPUnit-Polyfills/phpunit10.xml

.........S.....S.......                                           23 / 23 (100%)

Time: 00:00.534, Memory: 52.00 MB

OK, but some tests were skipped!
Tests: 23, Assertions: 48, Skipped: 2.

Generating code coverage report in HTML format ... done [00:00.473]


Code Coverage Report Summary:
  Classes:  4.55% (1/22)
  Methods:  4.41% (6/136)
  Lines:    1.80% (10/555)
$ phpunit12 -c phpunit10.xml --filter AssertObjectNotEquals

PHPUnit 12.0.1 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: path/to/PHPUnit-Polyfills/phpunit10.xml

.........S.....S.......                                           23 / 23 (100%)

Time: 00:01.452, Memory: 54.00 MB

OK, but some tests were skipped!
Tests: 23, Assertions: 48, Skipped: 2.

Generating code coverage report in HTML format ... done [00:00.196]


Code Coverage Report Summary:
  Classes:  4.55% (1/22)
  Methods:  4.41% (6/136)
  Lines:    1.80% (10/555)

When running the full suite with only line coverage, I see no significant difference in the performance.


Logs
$ phpunit11 -c phpunit10.xml

PHPUnit 11.5.7 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: path/to/PHPUnit-Polyfills/phpunit10.xml

...............................................................  63 / 478 ( 13%)
................................................SSSS....SSSS... 126 / 478 ( 26%)
.SSSSSSSS.................................SSSSSSSSSSSS......... 189 / 478 ( 39%)
............................................................... 252 / 478 ( 52%)
............................................................... 315 / 478 ( 65%)
......................S.....S..............S.....S......SSS.... 378 / 478 ( 79%)
SSS............................................................ 441 / 478 ( 92%)
..............................

Time: 00:03.360, Memory: 54.00 MB

OK, but some tests were skipped!
Tests: 471, Assertions: 862, Skipped: 39.

Generating code coverage report in HTML format ... done [00:00.447]


Code Coverage Report Summary:
  Classes:  9.09% (2/22)
  Methods:  5.15% (7/136)
  Lines:    2.88% (16/555)
$ phpunit12 -c phpunit10.xml

PHPUnit 12.0.1 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: path/to/PHPUnit-Polyfills/phpunit10.xml

...............................................................  63 / 478 ( 13%)
................................................SSSS....SSSS... 126 / 478 ( 26%)
.SSSSSSSS.................................SSSSSSSSSSSS......... 189 / 478 ( 39%)
............................................................... 252 / 478 ( 52%)
............................................................... 315 / 478 ( 65%)
......................S.....S..............S.....S......SSS.... 378 / 478 ( 79%)
SSS............................................................ 441 / 478 ( 92%)
..............................

Time: 00:03.985, Memory: 54.00 MB

OK, but some tests were skipped!
Tests: 471, Assertions: 862, Skipped: 39.

Generating code coverage report in HTML format ... done [00:00.203]


Code Coverage Report Summary:
  Classes:  9.09% (2/22)
  Methods:  5.15% (7/136)
  Lines:    2.88% (16/555)

So, for argument's sake, I checked the performance of path/branch coverage when running the full test suite as well, and the slow down is back, so that confirms it's the path/branch coverage which is the source of the slow-down, not the test filtering.

Running the full test suite vs a filtered down test doesn't seem to make a difference in the amount of slow down though.


Logs
$ phpunit11 -c phpunit10.xml

PHPUnit 11.5.7 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: D:\000_GitHub\WordPress_SEO_by_Yoast\PHPUnit-Polyfills\phpunit10.xml

...............................................................  63 / 478 ( 13%)
................................................SSSS....SSSS... 126 / 478 ( 26%)
.SSSSSSSS.................................SSSSSSSSSSSS......... 189 / 478 ( 39%)
............................................................... 252 / 478 ( 52%)
............................................................... 315 / 478 ( 65%)
......................S.....S..............S.....S......SSS.... 378 / 478 ( 79%)
SSS............................................................ 441 / 478 ( 92%)
..............................

Time: 00:46.100, Memory: 376.00 MB

OK, but some tests were skipped!
Tests: 471, Assertions: 862, Skipped: 39.

Generating code coverage report in HTML format ... done [00:00.724]


Code Coverage Report Summary:
  Classes:  9.09% (2/22)
  Methods:  5.15% (7/136)
  Paths:    6.82% (9/132)
  Branches:    8.12% (13/160)
  Lines:    2.88% (16/555)
$ phpunit12 -c phpunit10.xml

PHPUnit 12.0.1 by Sebastian Bergmann and contributors.

Runtime:       PHP 8.4.1 with Xdebug 3.4.1
Configuration: D:\000_GitHub\WordPress_SEO_by_Yoast\PHPUnit-Polyfills\phpunit10.xml

...............................................................  63 / 478 ( 13%)
................................................SSSS....SSSS... 126 / 478 ( 26%)
.SSSSSSSS.................................SSSSSSSSSSSS......... 189 / 478 ( 39%)
............................................................... 252 / 478 ( 52%)
............................................................... 315 / 478 ( 65%)
......................S.....S..............S.....S......SSS.... 378 / 478 ( 79%)
SSS............................................................ 441 / 478 ( 92%)
..............................

Time: 01:43.787, Memory: 370.00 MB

OK, but some tests were skipped!
Tests: 471, Assertions: 862, Skipped: 39.

Generating code coverage report in HTML format ... done [00:00.457]


Code Coverage Report Summary:
  Classes:  9.09% (2/22)
  Methods:  5.15% (7/136)
  Paths:    7.96% (9/113)
  Branches:    9.49% (13/137)
  Lines:    2.88% (16/555)

I can have a look after Juliette pushed the phpunit 12 changes for the reproducer

@staabm The WIP branch I'm using is available, though not yet merged: https://github.com/Yoast/PHPUnit-Polyfills/commits/feature/composer-ci-allow-for-phpunit-12/

Just FYI/I'll figure out some hacky solution - The thing I'm running into is something which was fixed in PHPUnit 11.3.? (non-existent traits not being ignored, but causing a fatal). As this package polyfills a PHPUnit 11.2.0 assertion (assertObjectNotEquals()), the tests need to run on PHPUnit < 11.2 + > 11.2. What with 12 now enforcing CoversTrait for traits and the CoversTrait attribute not being available in PHPUnit < 11.2 AND PHPUnit < 11.3.? not ignoring unknown attributes... the tests won't run on PHPUnit < 11.2, even when not running with code coverage.

I suspect I'll end up creating PHPUnit version specific wrappers for the tests + adding another config file. Nothing to worry about though as this is an edge-case which should not affect "normal" packages.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

I was not yet able to reproduce the slow run on https://github.com/Yoast/PHPUnit-Polyfills (I have no experience with branch coverage):

@staabm In case it helps, this is the exact config I used locally:

<?xml version="1.0" encoding="UTF-8"?>
<phpunit
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:noNamespaceSchemaLocation="https://schema.phpunit.de/10.5/phpunit.xsd"
    backupGlobals="true"
    bootstrap="./tests/bootstrap.php"
    beStrictAboutOutputDuringTests="true"
    beStrictAboutTestsThatDoNotTestAnything="true"
    colors="true"
    cacheDirectory=".cache/phpunit.cache"
    requireCoverageMetadata="true"
    displayDetailsOnTestsThatTriggerErrors="true"
    displayDetailsOnTestsThatTriggerWarnings="true"
    displayDetailsOnTestsThatTriggerNotices="true"
    displayDetailsOnTestsThatTriggerDeprecations="true"
    displayDetailsOnPhpunitDeprecations="true"
    failOnWarning="true"
    failOnNotice="true"
    failOnDeprecation="true"
    failOnPhpunitDeprecation="false"
    >
    <testsuites>
        <testsuite name="PHPUnitPolyfills">
            <directory>./tests/</directory>
        </testsuite>
    </testsuites>

    <source>
        <include>
            <file>phpunitpolyfills-autoload.php</file>
            <directory suffix=".php">./src/</directory>
        </include>
        <exclude>
            <file>src/Polyfills/AssertClosedResource_Empty.php</file>
        </exclude>
    </source>

    <coverage pathCoverage="true">
        <report>
            <text outputFile="php://stdout" showOnlySummary="true"/>
            <html outputDirectory="build/coverage-html" lowUpperBound="35" highLowerBound="90"/>
        </report>
    </coverage>
</phpunit>

@staabm
Copy link
Contributor

staabm commented Feb 8, 2025

which xdebug.mode do you use?

I am still unable to reproduce with

php -v
PHP 8.3.16 (cli) (built: Jan 14 2025 18:25:29) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.3.16, Copyright (c) Zend Technologies
    with Xdebug v3.4.1, Copyright (c) 2002-2025, by Derick Rethans

using vendor/bin/phpunit -c phpunit10.xml.dist --filter AssertObjectNotEquals and your given config

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

which xdebug.mode do you use?

@staabm This the config I'm using for PHP 8.4.1 (which I used for the above tests):

[xdebug]
zend_extension="C:/wamp/bin/php/ext/xdebug/php_xdebug-3.4.1-8.4-ts-vs17-x86_64.dll"

;xdebug.mode allowed are : off develop coverage debug gcstats profile trace
xdebug.mode=coverage
xdebug.output_dir="C:/wamp/tmp"
xdebug.show_local_vars=0
xdebug.log="C:/wamp/logs/xdebug.log"
;xdebug.log_level : 0 Criticals, 1 Connection, 3 Warnings, 5 Communication, 7 Information, 10 Debug	Breakpoint
xdebug.log_level=7
xdebug.profiler_output_name=trace.%H.%t.%p.cgrind
xdebug.use_compression=false

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

For argument's sake just reran the tests with PHP 8.3.14 (same Xdebug config) and got the same results.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

@staabm Another thought, though I can't imagine it would make a difference - I'm running the tests with the PHAR file, while it looks l like you're trying to reproduce with a Composer installed version.

Update: just tested and to my dismay and surprise - I cannot reproduce with a Composer install either. So the PHAR in combination with path/branch coverage is where things are going wrong...

Colour me flabbergasted.

@sebastianbergmann
Copy link
Owner

There seems to be something broken with regard to the static analysis cache when the PHAR is used. Although different, sebastianbergmann/phpunit#6124 seems to point into that direction as well.

@sebastianbergmann
Copy link
Owner

@jrfnl Can you delete your .phpunit.cache directory and see if that works around this issue as well? Thanks!

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

Can you delete your .phpunit.cache directory and see if that works around this issue as well? Thanks!

Done (including deleting various other files, like PHPUnit 9 cache file and code coverage result files) and it unfortunately doesn't make a difference.

@sebastianbergmann
Copy link
Owner

Please test whether the PHPUnit 12.0.2 PHAR solves this issue for you. Thank you!

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

@sebastianbergmann Tested and unfortunately, no luck.

@sebastianbergmann
Copy link
Owner

Thank you for testing. I will (try to) stop working on this until after the weekend. Besides, I have no idea what might be going on here as I looked into the changes between 11.0 and main and am unable to find anything specific to branch/path coverage.

In general, I can only advise against using branch/path coverage "all the time" (as in configured in your XML configuration file). But, of course, that is not a solution to the problem you discovered.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

@sebastianbergmann Sounds like a good plan. Wishing you a relaxing weekend!

Let me know if/when you want me to try additional debug steps. Happy to oblige.

In general, I can only advise against using branch/path coverage "all the time" (as in configured in your XML configuration file). But, of course, that is not a solution to the problem you discovered.

Agreed. The default config for projects I manage is generally set to line coverage. It's only my local override config in which I have path/branch coverage enabled and even then, I normally only run coverage locally when making significant changes. Or, like in this case, when debugging an issue with code coverage ;-)

@sebastianbergmann
Copy link
Owner

Let me know if/when you want me to try additional debug steps.

The only thing I can think of right now would be to use git-bisect to find out which commit in php-code-coverage between 11.0 and 12.0.0 causes the slowdown. However, as this issue seems to only occur when PHPUnit is used from a PHAR this means that for each bisect step a PHAR needs to be built. I do not have a ready-to-use automation to make this convenient :-(

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

🤔 I seem to remember setting up making PHARs available as artifacts for the builds in the PHPUnit repo. I might be able to work something out from that.

@sebastianbergmann
Copy link
Owner

ant phar-snapshot in a checkout of PHPUnit's repository will build a PHAR. You "only" need to make sure that php-code-coverage is installed from a specific revision.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

Good to know, though I've never managed to get ant working on Windows... (and the installation instructions are abysmal). I'll have a try anyway.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

Yeah, that's not going to work. I've managed to get ant running on Windows via Chocolatey now, but the commands to run the tools in build.xml are not compatible with Windows.

BUILD FAILED
path/to/phpunit\build.xml:18: Execute failed: java.io.IOException: Cannot run program "path/to/phpunit\tools\composer" (in directory "path/to/phpunit"): CreateProcess error=193, %1 is not a valid Win32 application

@sebastianbergmann
Copy link
Owner

Sorry, but you need something UNIXy to build PHARs.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

Sorry, but you need something UNIXy to build PHARs.

... for PHPUnit ;-)

Generated some PHARs via GH Actions now with PHPUnit at dev-main and code cov at various commit hashes, but most of those PHARs aren't working as PHPUnit 12 presumes certain changes in the code cov package.

These are the commit hashes I used (from oldest to most recent):

  • "46af700c350468657001c67c9d5c4e6d4f0057a8" ❌
  • "873416b3e559601ade441f0f4ae210d7a13e2711" ❌
  • "9354b267618453a43fa63af72899930e48022fa4" ❌
  • "391889d0b6f626e0379396ed61e2c6ae92beba10" ❌
  • "5ed521f486312c3b1b970da6a6543e641fa32578" ❌
  • "08fbab6175db74f68d528342cbdab254e74fd593" ❌
  • "0f52179519a10d3edab3cf567e909d68d48529ce" 🏃 [Edit: this ran the first time I tried, but not on subsequent runs]
  • "69dde560510151f7d04315fac6c72016cc5d7bc8" 🏃

Only the last two commits I tried yield a working PHAR and both of those have the slow down.

@jrfnl
Copy link
Contributor Author

jrfnl commented Feb 8, 2025

Looked at it with fresh eyes and found another cache file. Deleting that one does fix things and gets rid of the slow-down.

Also, once it's gone, re-running on PHPUnit 11 (which creates the cache anew) and then PHPUnit 12 without clearing the cache in between, re-introduces the issue.

Hope this gets us another step closer.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants