How PHPUnit and phpunit-bridge make false pass tests for Drupal 8

Submitted by Mile23 on Sat, 09/02/2017 - 14:50

Let's do a little bit of a deep dive into PHPUnit, and some subtle interactions between process-isolation and symfony/phpunit-bridge.

Our quest will not be easy, or even not-hard, but do not despair: The rewards will be miniscule. :-) That's because I'm not going to offer solutions to the problems I find here. This is just so you'll understand the problem.

What you'll learn:

  • How PHPUnit process isolation works.
  • Why that means that symfony/phpunit-bridge doesn't work with it.

I'm coming at this from the Drupal 8 world. That means we'll be talking about PHPUnit 4.8.x, but I'm pretty sure these concepts apply to newer versions of PHPUnit.

We'll also be talking about symfony/phpunit-bridge, hereafter referred to as 'phpunit bridge.' It's a handy library for doing a few special mocks but mostly the reason we care about it in Drupal-world is that it registers an error handler and deals with @trigger_error(E_USER_DEPRECATED).

The PHPUnit conundrum.

It might be that you've heard of PHPUnit. It's a nice framework for writing tests in PHP.

What we care about for this little article is that it has a feature: We can run PHPUnit test methods in isolation. Here's a test class. Note here the use of the @runTestsInSeparateProcess annotation which signals PHPUnit to run each test method in a separate process. Note that this is a terrible test and you should never emulate it.

use PHPUnit\Framework\TestCase;

/**
 * @runTestsInSeparateProcesses
 */
class ProcessIsolatedTest extends TestCase
{

  public function setUp() {
    // Our test needs a global and an environmental variable
    // which is why this test is process-isolated.
    global $globalsSuck;
    $globalsSuck = 'Test me.';
    putenv(WHAT_A_HORRIBLE_FIXTURE=$globalsSuck);
  }

  public function testAThing() {
    global $globalsSuck;
    run_high-dependency_code_that_should_not_change_the_global();
    $this->assertEquals(WHAT_A_HORRIBLE_FIXTURE, $globalsSuck);
  }

}

If you are like me, your understanding of this process went a bit like this:

  • The test runner encounters our test class: ProcessIsolatedTest.
  • ?????
  • Process isolation occurs.
  • Test results are available.
  • Profit.

Let's change that confusion to enlightenment.

Go To The Source

If you poke around in PHPUnit_Framework_TestCase::run(), you'll eventually encounter this:

    public function run(PHPUnit_Framework_TestResult $result = null)
    {
        // [...]
        if ($this->runTestInSeparateProcess === true &&
            $this->inIsolation !== true &&
            !$this instanceof PHPUnit_Extensions_SeleniumTestCase &&
            !$this instanceof PHPUnit_Extensions_PhptTestCase) {

So that's our first clue what's happening in PHPUnit when we run the test in isolation. It looks to make sure that the user said to run in a separate process, and then looks to make sure we're not already in a separate process ($this->inIsolation), and some other cases.

What follows tells us a lot about how this isolation process occurs.

The very next thing is:

            $template = new Text_Template(
                __DIR__ . '/../Util/PHP/Template/TestCaseMethod.tpl'
            );

Wait, Text_Template? *.tpl file? Huh?

Yes.

PHPUnit isolates processes by poking values into a PHP template. This template is then sent as input to the forked child process. This occurs per method, which is fine because this allows PHPUnit data providers to work, and also lets us only run setUp() once before run() is called. It also allows us to mark only some methods as needing isolation, using @runInSeparateProcess.

You might be wondering: How can we meaningfully perform setUp() in one process and then run() in another? And that's a good question. The answer is: Most of the class, and optionally globals and environmental variables, are serialized after setUp(), and then unserialized by the template script. This allows us to make a sort of clone of the class within the child process, which means we only have to run setUp() once.

A Concrete Example

Let's look at how this plays out in a Drupal issue: Remove Extension dependency on DRUPAL_ROOT

In this issue, we see that a process-isolated unit test tries to use a class called Extension. When Extension is unserialized for running in isolation, it needs to know the root path of the Drupal installation, and it tries to look in a global: DRUPAL_ROOT. This global does not exist in the child process, so it crashes and burns. And that's as it should be, because we're performing a unit test that shouldn't have a dependency on a global, and because Extension really shouldn't have a dependency on DRUPAL_ROOT when the app.root service exists.

Moving on...

Symfony/PHPUnit-Bridge

The PHPUnit bridge is a great idea. You add @trigger_error(E_USER_DEPRECATED) to your code wherever it's deprecated, and then a special error handler counts up all the deprecations during PHPUnit runs. It also registers a shutdown handler, where all the deprecation info is then output, and optionally fails the test run.

Great, right?

Just two things: 1) It only works if the test is not process-isolated, and 2) Given #1, depending on how you set up @trigger_error(), it might only work during test discovery.

Since process isolation is on our minds, and is really the culprit in both cases, let's tackle that part first.

Symfony Dropped Your Deprecation

PHPUnit bridge works in PHPUnit by registering a test listener. A test listener lets some code respond to events within the PHPUnit test runner. In the case of the bridge, it listens for the start of tests. It does other stuff but we'll concentrate on the startTest event.

The test listener only ever 'hears' the start of the test before run() is called. This means that even if the listener were registered inside the child process (it isn't), it still wouldn't get a startTest event because the test runner is what handles that.

So here's a diagram of our deprecation fail, in pseudo-YAML:

phpunit runner:
  phpunit-bridge listener is registered.
  test:
    phpunit-bridge gets startTest event, registers error and shutdown handlers.
    runner calls run():
      run() forks child process via PHPUnit_Util_PHP::runTestJob().
        - child process runs the test from the template.
        - phpunit-bridge error handler is not registered.
        - Six hundred million @trigger_error() occur but are silenced by the @.
        - exit code is computed. All the tests passed, so return 0 status code.
        - No shutdown handler here.
      runTestJob() gives back a happy test result.
    run() says 'I'm happy too!'
  test claps its hands because it's so happy with the test results.
runner says: Test result: passed.
shutdown handler says: I count 0 deprecations, so EVERYTHING'S FINE.

Hopefully you see that inside the process, no triggered deprecation errors are accounted for, meaning that for all PHPUnit tests which are process-isolated, all results are potentially false passes.

Ruins Your Drupal Plans

Now, in Drupal land, this is a problem, because we have a lot of functional tests. These tests require either a partially booted or fully installed Drupal site, and that's something you want to do in process isolation.

We also have a deprecation process that requires adding @trigger_error(), so that everyone gets the news as quickly as possible by failing tests.

So all test runs involving KernelTestBase, BrowserTestBase and JavascriptTestBase are potentially false passes as of the current moment.

What About That Discovery Thing?

Yes, let's go back to that. This is another way in which the PHPUnit bridge can fail us, for process-isolated tests, specifically for Drupal but probably in other scenarios.

Let's consider the following code. Here's a deprecated interface:

<?php

namespace YourNamespace;

@trigger_error('Do not use this interface.', E_USER_DEPRECATED);

interface DeprecatedInterface {

}

Here's a concrete class which implements that interface:

<?php
namespace YourNamespace;

use YourNamespace\DeprecatedInterface;

class ConcreteClass implements DeprecatedInterface {

  public function doAThing() {
    return 'expected';
  }

}

And here's a test which tests an implementation of that interface:

<?php

namespace YourNamespace\Tests;

use PHPUnit\Framework\TestCase;
use YourNamespace\ConcreteClass;

class ImplementationTest extends TestCase {

  public function testTheImplementation() {
    $concrete = new ConcreteClass();
    $this->assertEquals('expected', $concrete->doAThing());
  }

}

Let's run that test:

$ ./vendor/bin/phpunit test/
PHPUnit 4.8.36 by Sebastian Bergmann and contributors.

Testing test/
.

Time: 218 ms, Memory: 4.00MB

OK (1 test, 1 assertion)

Remaining deprecation notices (1)

Do not use this interface: 1x
    1x in ImplementationTest::testTheImplementation from YourNamespace\Tests

See how PHPUnit bridge told us about the deprecation? When ImplementationTest loaded ConcreteClass, it also loaded DeprecatedInterface, which triggered the deprecation error. You can deduce this from the line 1x in ImplementationTest::testTheImplementation from YourNamespace\Tests.

If we add @runTestInSeparateProcess to ImplementationTest this deprecation message goes away, for reasons we just discovered above. Try it now if you'd like.

Now, let's go run a similar test on Drupal. We'll run a functional test, which means the test is process isolated. Given what just happened, we'd expect that the test run would swallow the deprecation error. But it doesn't...

As of Drupal 8.4.x branch commit 087c5cd541f11b643044d2354c044d3aee2491cb we can do this:

$ SIMPLETEST_BASE_URL=http://localhost:8888/ ./vendor/bin/phpunit -c core/ --testsuite functional --group ban
PHPUnit 4.8.35 by Sebastian Bergmann and contributors.

Testing 
.

Time: 34.61 seconds, Memory: 40.00MB

OK (1 test, 13 assertions)

Remaining deprecation notices (1)

Drupal\system\Tests\Update\UpdatePathTestBase is deprecated in Drupal 8.4.0 and will be removed before Drupal 9.0.0. Use \Drupal\FunctionalTests\Update\UpdatePathTestBase instead. See https://www.drupal.org/node/2896640: 1x
    1x in FunctionalTestSuite::suite from Drupal\Tests\TestSuites

I mention the commit because this is a bug. We're fixing it here.

But what's interesting here is that it wasn't the test method that triggered the error. Check this line:

1x in FunctionalTestSuite::suite from Drupal\Tests\TestSuites

Drupal has a convoluted test discovery system. It defines its own test suite classes so that we can select different types of tests to run using the --testsuite option on the command line.

This deprecation error was triggered by the test discovery system. FunctionalTestSuite makes a list of functional tests it discovers, and then passes it up to its superclass, \PHPUnit_Framework_TestSuite. \PHPUnit_Framework_TestSuite instantiates all the tests in the list in preparation for running them. Then the test runner filters through this big set of instantiated tests based on our --group specification and runs only the ones with a matching @group annotation.

When \PHPUnit_Framework_TestSuite instantiates the tests, it ends up loading Drupal\system\Tests\Update\UpdatePathTestBase once. UpdatePathTestBase is completely unrelated to the ban test we end up running. It is not used by that test, but it still fails our test run, much the same way that DeprecatedInterface failed our test run above.

This is good for us, because when we use the PHPUnit command line tool to discover tests, we still get the benefit of some triggered deprecations, even though the problem of the process isolation swallowing the deprecation errors still remains. And while it's good for us, it also happens by accident.

More And More Kinds Of Fail

Well, if by 'fail' we mean 'false passes.'

I chose --group ban above because it only has one functional test, named IpAddressBlockingTest. Instead of running it as part of a group, let's just specify the pathname to the test class:

$ SIMPLETEST_BASE_URL=http://localhost:8888/ ./vendor/bin/phpunit -c core/ core/modules/ban/tests/src/Functional/IpAddressBlockingTest.php 
PHPUnit 4.8.35 by Sebastian Bergmann and contributors.

Testing Drupal\Tests\ban\Functional\IpAddressBlockingTest
.

Time: 26.41 seconds, Memory: 4.00MB

OK (1 test, 13 assertions)

No deprecation error.

Why is that? Because the test was never instantiated outside of the isolation process. This leads us back to the pseudo-YAML diagram from above, where all those deprecations are swallowed.

So now your question has to be:

Is this a false pass?

And the answer is:

Yes.

So if we run a test that should fail because of unrelated deprecations (which is how Drupal is set up to behave), then we have to either fix this problem, or change our policy.

Let's examine how this is a very real problem for Drupal.

run-tests.sh, AKA The Testbot

DrupalCI runs a script called run-tests.sh in order to run all the tests in Drupal 8.

We do this for a bunch of reasons I won't discuss here, but which will also not change for the forseeable future.

How does run-tests.sh work?

It performs test discovery using a completely different discovery mechanism. Yes, that's right, it doesn't use PHPUnit. But that's OK, because we have to run tests that don't run under PHPUnit.

Next, run-tests.sh figures that since it already found all the PHPUnit-based tests, it can just run them on the command line as file paths.

Like this:

$ SIMPLETEST_BASE_URL=http://localhost:8888/ ./vendor/bin/phpunit -c core/ core/modules/ban/tests/src/Functional/IpAddressBlockingTest.php

Hey, that's just like the false pass one from above, isn't it? It doesn't perform discovery, so the deprecation error is never triggered, so the test never fails for the testbot. That's on top of the problem with PHPUnit bridge, which never triggers errors from the isolation process.

If you're me, you filed an issue about this.

What To Do?

The real solution to this problem is to allow symfony/phpunit-bridge to work in isolation. And I filed an issue about that, too: https://github.com/symfony/symfony/issues/23003

In Drupal-land, we can mark the most egregious false passes as risky. Or we could essentially fork phpunit-bridge.

Any participation in any of those issues is appreciated.

Thanks for reading all the way to the end.