[4.4] Dramatic increase in memory consumption for tests after updating to 4.4

[ndench]

Symfony version(s) affected: 4.4.2

Description
When we update to 4.4, my tests go from this:

Time: 7.7 minutes, Memory: 295.00 MB 
 
OK (1878 tests, 8872 assertions) 

To this:

Time: 30.83 minutes, Memory: 9.03 GB

There was 1 error:

1) Hyra\Tests\Integration\Tasks\Command\WorkerCommandTest::testExecute
proc_open(): fork failed - Cannot allocate memory

vendor/symfony/console/Terminal.php:157
vendor/symfony/console/Terminal.php:143
vendor/symfony/console/Terminal.php:109
vendor/symfony/console/Terminal.php:92
vendor/symfony/console/Terminal.php:33
vendor/symfony/console/Style/SymfonyStyle.php:51
src/Tasks/Command/WorkerCommand.php:59
vendor/symfony/console/Command/Command.php:255
vendor/symfony/console/Tester/CommandTester.php:76
tests/Integration/Tasks/Command/WorkerCommandTest.php:59
 
-- 
 
There was 1 failure: 
 
1) Hyra\Tests\Functional\Negotiate\Download\DealContractFileUrlTest::testTenantsDownloadsContractWithCoverSheetAttachedInReview 
Failed asserting that 500 is identical to 200. 
 
tests/Functional/Negotiate/Download/DealContractFileUrlTest.php:118 
 
ERRORS! 
Tests: 1876, Assertions: 8852, Errors: 1, Failures: 1. 

At first, we thought that #34567 would fix it, but that was released a while back and it did not make a difference. Another possibly related issue would be #25964.

I've been unable to track down the actual issue, and can't seem to break down the problem into a reproducer on a blank Symfony installation. However, here is everything I've been able to figure out:

• Only seems to be an issue for tests extending WebTestCase and booting the kernel
• Running a single WebTestCase test uses marginally higher memory, but not by much
• Running multiple WebTestCase tests causes the memory usage to grow much faster
• Examples:
  • 1 test uses 40.5MB on 4.3 but 42.5MB on 4.4
  • 8 tests uses 48.5MB on 4.3 but 86.5MB on 4.4
  • 19 tests uses 54.5MB on 4.3 but 158.5 MB on 4.4
• Blackfire profile running a test subset on 4.3
• Blackfire profile running a test subset on 4.4
• Blackfire comparison

How to reproduce
We can't get a bug reproducer working, however these are the steps I've taken:

• composer update symfony/*
• Run tests like normal php vendor/bin/phpunit

Additional context

• To rule out problems with other package upgrades we locked Symfony to 4.3 using extra.symfony.require: "4.3.*" in composer.json then ran a composer update. Then with extra.symfony.require: "^4.2.0" ran composer update symfony/*
• Initially we was using symfony/phpunit-bridge, but ruled out an issue with that by uninstalling it and using phpunit/phpunit directly
• We're using the LiipFunctionalTestBundle and the LiipTestFixturesBundle and loading fixtures in the WebTestCase
• We are using the TestContainer to access services in tests
• The test subset I'm running does not use the PhpUnit setUp functions

[nicolas-grekas]

What's the size of the getTest_PrivateServicesLocator.php file in both cases?

[ndench]

On 4.3:

$ find var/cache/test -name '*getTest_PrivateServicesLocator*'
var/cache/test/ContainerBD2p2vw/getTest_PrivateServicesLocatorService.php
$ wc var/cache/test/ContainerBD2p2vw/getTest_PrivateServicesLocatorService.php
  2799  12616 314868 var/cache/test/ContainerBD2p2vw/getTest_PrivateServicesLocatorService.php

On 4.4:

$ find var/cache/test -name '*getTest_PrivateServicesLocator*'
var/cache/test/Container0ZTN0ux/getTest_PrivateServicesLocatorService.php
$ wc var/cache/test/Container0ZTN0ux/getTest_PrivateServicesLocatorService.php
  2849  12841 319815 var/cache/test/Container0ZTN0ux/getTest_PrivateServicesLocatorService.php

[dmaicher]

Maybe its related to those changes in KernelTestCase?

https://github.com/symfony/symfony/compare/4.3..4.4#diff-87a8cc91fd08f09a8a3c0b37d7ddf177

[allcode]

Just as a confirmation; we've run into the same memory issue when upgrading (the framework bundle) from 4.3 to 4.4.2
The whole test suite uses about 240MB with 4.3 and after upgrading to 4.4.2 it runs out of memory (4GB) half way through the functional test suite. The problem is solved when we do not reboot the kernel before each request. We're still in the process of finding out the exact cause.

Edit: The hint by @dmaicher was indeed the solution for us (thanks!). Before, our tests did not reset the kernel container after shutdown. With 4.4, you must reset the container.

[ndench]

@allcode do you mean you made your tests call static::ensureKernelShutdown()?

I tried that and it made no difference.

[allcode]

@ndench Our functional test suite does not extend KernelTestCase, but uses the same strategy. We had to add a $container->reset() after $kernel->shutdown() to solve the issue. If you're extending KernelTestCase of symfony/framework-bundle 4.4, then this should already happen.
I still think it's likely the issue is with container state. You should debug your test suite and make sure the container is reset after each test. Perhaps the issue is with LiipFunctionalTestBundle
WebTestCase resetting the container before shutting down the kernel, or your tests overriding the tearDown() method without calling the parent?

[xabbuh]

@ndench Does #35164 (comment) help?

[ndench]

Sorry @allcode @xabbuh missed the response.

All our non-unit tests (eg. functional, integration, etc) extend KernelTestCase, which calls ensureKernelShutdown() in the doTearDown() method. I've stepped through the code and verified that the method is actually called and it does three things:

1. Shutdown the kernel
2. Reset the $kernelContainer
3. Set both $kernelContainer and $container to null

I then tried two things:

1. Call ensureKernelShutdown() in our tearDown() method (this did nothing because it exits early if the kernel is already shut down)
2. Reset the $container (this also made no difference because TestContainer::reset() is an empty method)

Yes I've made sure our tearDown method calls the parent, additionally, we did not have a tearDown method before. I created it specifically to call ensureKernelShutdown() and $container->reset().

Looking at the LiipFunctionalTestBundle's tearDown() method, it stores a reference to any container used in the tests and resets them, then calls the parent. Is it a problem that it's resetting the container before the kernel is being shut down?

[ndench]

Does anyone have any ideas on where to look to solve this?
Happy to submit a PR but I have no idea where to even start.
This issue is holding us to 4.3 which is no longer getting bug fixes 😬

[dmaicher]

@ndench in one of my larger project with lots of functional and kernel testcases I use this phpunit listener to free up memory from members in test classes after the test:

class PHPUnitTestCleanUpListener implements TestListener
{
    use TestListenerDefaultImplementation;

    public function endTest(Test $test, float $time): void
    {
        if (!$test instanceof KernelTestCase) {
            return;
        }

        self::stripProperties($test);
    }

    private static function stripProperties(object $target): void
    {
        $refl = new \ReflectionObject($target);
        foreach ($refl->getProperties() as $prop) {
            if (!$prop->isStatic() && 0 !== \strncmp($prop->getDeclaringClass()->getName(), 'PHPUnit_', 8)) {
                $prop->setAccessible(true);
                $prop->setValue($target, null);
            }
        }
    }
}

Its a bit of a hack but for me this reduced memory usage significantly and improved the performance quite a bit.

Maybe give it a try. This does not really solve the problem but it hides the symptoms 😄 🙈

EDIT: source is this blog post that I stumbled across: https://tomnewby.net/posts/speed-up-phpunit-1-weird-trick/

[ndench]

@dmaicher funny story, Tom Newby is actually my colleague and wrote that blog post after the last time we had issues with PHPUnit and memory consumption 😂. It's served us very well for a while now, but it's not helping after the upgrade to 4.4.

[ndench]

I just tried updating to the latest version of 4.4 again and am receiving the same issue.
Does anyone have any ideas on how I can debug this further?

[nicolas-grekas]

I would happily have a look but I'd need a reproducer for sure.

[ndench]

Thanks @nicolas-grekas, I'm I bit stuck about where to start. I'll need to spend some more time breaking it down in our codebase but hopefully I can get a reproducer in a clean Symfony install for you. If you have any pointers or gut feels for where to start looking it would be much appreciated.

[ndench]

I've been trying to create a reproducer for this.

I though that it was caused by the LiipFunctionalTest bundle and the use of fixtures in integration tests. So I started with a base Symfony install, added a few entities, fixtures (including the LiipFunctionalTestBundle) and essentially copied over some tests from my project. But they didn't get the memory blow out when upgrading to 4. So now I have no idea where to look next.

To try track it down further, I've installed the oldest version of the 4.4.0 branch that I can, 4.4.0-BETA1 like so:

--- a/composer.json
+++ b/composer.json
@@ -35,23 +35,23 @@
-        "symfony/asset": "^4.0",
-        "symfony/console": "^4.0",
+        "symfony/asset": "4.4.0-BETA1",
+        "symfony/console": "4.4.0-BETA1",
         "symfony/debug-pack": "^1.0.4",
-        "symfony/expression-language": "^4.0",
+        "symfony/expression-language": "4.4.0-BETA1",
         "symfony/flex": "^1.0",
-        "symfony/form": "^4.0",
-        "symfony/framework-bundle": "^4.0",
+        "symfony/form": "4.4.0-BETA1",
+        "symfony/framework-bundle": "4.4.0-BETA1",
         "symfony/monolog-bundle": "^3.1",
         "symfony/orm-pack": "^1.0.5",
-        "symfony/process": "^4.0",
-        "symfony/security-bundle": "^4.0",
+        "symfony/process": "4.4.0-BETA1",
+        "symfony/security-bundle": "4.4.0-BETA1",
         "symfony/serializer-pack": "^1.0.1",
         "symfony/swiftmailer-bundle": "^3.1",
-        "symfony/validator": "^4.0",
-        "symfony/web-link": "^4.0",
-        "symfony/workflow": "^4.0",
-        "symfony/yaml": "^4.0"
+        "symfony/validator": "4.4.0-BETA1",
+        "symfony/web-link": "4.4.0-BETA1",
+        "symfony/workflow": "4.4.0-BETA1",
+        "symfony/yaml": "4.4.0-BETA1"
     },
     "require-dev": {
@@ -72,8 +72,8 @@
-        "symfony/browser-kit": "^4.0",
-        "symfony/css-selector": "^4.0",
+        "symfony/browser-kit": "4.4.0-BETA1",
+        "symfony/css-selector": "4.4.0-BETA1",
         "symfony/dotenv": "^4.2.0",
         "symfony/maker-bundle": "^1.0",
         "symfony/profiler-pack": "^1.0.3",
@@ -123,7 +123,7 @@
         "symfony": {
             "id": "01C557KGKVJGP76W8CRRW45KYC",
             "allow-contrib": false,
-            "require": "^4.3"
+            "require": "4.4.0-BETA1"
         }

and the issue still exists. However the issue does not exist on the latest version of the 4.3 branch. That leads me to believe me the issue was introduced in one of the commits on the 4.4 branch, prior to the 4.0.0-BETA1 tag.

Is there a way I can install from a given commit hash prior to that tag? Or another way I can track down this issue and create a good reproducer?

[derrabus]

@ndench

Is there a way I can install from a given commit hash prior to that tag? Or another way I can track down this issue and create a good reproducer?

Checkout the symfony/symfony repository via git. It contains a script called link that replaces all of Symfony's composer packages in your project with symlinks to your local Symfony repository. This allows you to test your application against specific commit hashes. You could then use git bisect to identify the commit that caused your memory leak.

[ndench]

@derrabus that's exactly what I was after, thanks for pointing that out 👍

[tomtomau]

Hi there, we've used blackfire to create traces on a cut down test suite that only runs two tests. This is the minimum to replicate the issue with memory usage jumping from 134MB to 204MB after upgrading to 4.4.0-BETA1 (using the beta to minimise the diff).

Trace from 4.3.11
Trace from 4.4.0-BETA1
Blackfire compare

We're not 100% sure on how best to interpret the blackfire results, but observations:

In 4.3.11, the second test run has very low memory usage compared to the first test (as expected), in comparison to 4.4.0-BETA1 that shows the second test using the same amount of memory. This would then scale out across all our tests to blow up.

---

When we do a compare, we're not sure how best to interpret the results. It appears like it's perhaps an issue with the TraceableEventDispatcher, but that said, there doesn't seem to have been many significant changes from 4.3.11 to 4.4.0-BETA1 that would indicate this would be where to start looking.

Does anyone have any suggestion on how to interpret this? Desperate for any ideas at this point 😅

[xabbuh]

Could you share the application and the tests behind these profiles?

[stof]

Can you check again now that #36460 is merged ? It fixed a memory leak (but it looks like it also affected other versions, so it might not be the one relevant here)

[ndench]

@xabbuh I'm happy to add you (and anyone else) as a collaborator onto the project, and to give a quick rundown of how to reproduce the error. Unfortunately the project isn't open source so I can't open it up to everyone. The project is contained in a publicly available vagrant box, so it will be easy to get set up. Let me know if you'd like to do this?

@stof thanks for pointing out #36460, I gave it a shot by pulling the latest 4.4 branch locally and using the link script in the root of the repo. Unfortunately it does not fix our issue.

Additionally, after running a git bisect, it appears that #34078 is the root cause. Maybe our tests are booting the kernel multiple times and it's not being shut down?

[dmaicher]

@ndench as written via Symfony Slack I would be interested to help debug/profile this further 😊 Sounds like a challenge 😄

[dmaicher]

@ndench I had a look at your tests and (like you also found out) its related to the Liip\FunctionalTestBundle\Test\WebTestCase you are using.

The getContainer method boots a new kernel that is never shutdown anywhere: https://github.com/liip/LiipFunctionalTestBundle/blob/master/src/Test/WebTestCase.php#L228

Also the container that is reset inside tearDown is Symfony's TestContainer that is not actually resetting anything anymore since https://github.com/symfony/symfony/pull/34078/files#diff-ca33e3189d79b860cb883635e1f11c36R122

So this call
https://github.com/liip/LiipFunctionalTestBundle/blob/master/src/Test/WebTestCase.php#L437

does not reset anything and I suspect there are some cyclic references or so and PHP's garbage collection cannot clean-up everything?

Some simple fix for your BaseWebTestCase that extends Liip\FunctionalTestBundle\Test\WebTestCase:

use Liip\FunctionalTestBundle\Test\WebTestCase;
use Symfony\Component\DependencyInjection\ContainerInterface;
use Symfony\Component\HttpKernel\KernelInterface;

abstract class BaseWebTestCase extends WebTestCase
{
    /**
     * @var KernelInterface
     */
    private static $localKernel;

    protected function tearDown(): void
    {
        if (self::$localKernel !== null) {
            self::$localKernel->shutdown();
        }

        parent::tearDown();
    }

    /**
     * override from Liip\FunctionalTestBundle\Test\WebTestCase to allow garbage collection
     */
    protected function getContainer(): ContainerInterface
    {
        if (self::$localKernel === null) {
            self::$localKernel = self::createKernel();
        }

        self::$localKernel->boot();

        return self::$localKernel->getContainer()->get('test.service_container');
    }
}

this brings down memory consumption to roughly the same level as with Symfony 4.3 and on my machine this even speeds up your functional tests by more than 1 minute 😄

This should be reported on Liip\FunctionalTestBundle and be fixed I guess

[ndench]

Thanks @dmaicher, really appreciate your help! I've submitted a PR to the TestFixturesBundle (liip/LiipTestFixturesBundle#62). And we're now successfully running Symfony 4.4 which halved the time our tests take to run 🎉