Identifying the slowest tests in PHPUnit

UPDATE 2020-01-10: After the feedback received for this post on Twitter, I decided to create a package for this matter, adding the ability to check the tests in MySQL, SQLite, JSON, CSV or even in the Console itself.

Our team is growing, and as a result of that more people write tests in our app. That means different ways of working, with different performances. Currently our app has almost 900 tests and it tooks about a minute to run them all.
Last week we merged a feature involving some fake Guzzle calls with huge JSONs in them and after that the whole test suite took a minute and a half instead. We identified those tests quickly because the merge was very fresh and my co-worker is already working on them, but that left a question in my head.

How can I check the slowest tests in the entire testsuite? Is there a way to identify them?

Checking out the PHPUnit documentation I found a way to store the tests execution time into an XML file.

phpunit --log-junit phpunit-results.xml

This gives you something like this. For the brevity of this post I'll use the default Laravel tests as an example instead.

<?xml version="1.0" encoding="UTF-8"?>
<testsuites>
  <testsuite name="" tests="2" assertions="2" errors="0" warnings="0" failures="0" skipped="0" time="0.084737">
    <testsuite name="Feature" tests="1" assertions="1" errors="0" warnings="0" failures="0" skipped="0" time="0.079630">
      <testsuite name="Tests\Feature\ExampleTest" file="/Users/lloople/Code/davidllop.com/tests/Feature/ExampleTest.php" tests="1" assertions="1" errors="0" warnings="0" failures="0" skipped="0" time="0.079630">
        <testcase name="testBasicTest" class="Tests\Feature\ExampleTest" classname="Tests.Feature.ExampleTest" file="/Users/lloople/Code/davidllop.com/tests/Feature/ExampleTest.php" line="12" assertions="1" time="0.079630"/>
      </testsuite>
    </testsuite>
    <testsuite name="Unit" tests="1" assertions="1" errors="0" warnings="0" failures="0" skipped="0" time="0.005107">
      <testsuite name="Tests\Unit\ExampleTest" file="/Users/lloople/Code/davidllop.com/tests/Unit/ExampleTest.php" tests="1" assertions="1" errors="0" warnings="0" failures="0" skipped="0" time="0.005107">
        <testcase name="testBasicTest" class="Tests\Unit\ExampleTest" classname="Tests.Unit.ExampleTest" file="/Users/lloople/Code/davidllop.com/tests/Unit/ExampleTest.php" line="12" assertions="1" time="0.005107"/>
      </testsuite>
    </testsuite>
  </testsuite>
</testsuites>

This is almost what I wanted, except that the <testcase> elements are not ordered by the duration time but alphabetically. Also it's hard to find the time in that file if you have more than 800 lines.

My first approach was to modify this file with replaces to create a CSV so I could import it into a MySQL table.

name,class,classname,time
"testBasicTest","Tests\Feature\ExampleTest","Tests.Feature.ExampleTest","0.079630"
"testBasicTest","Tests\Unit\ExampleTest","Tests.Unit.ExampleTest","0.005107"

Creating a table with the same columns and importing this file with SequelPro gave me the ability to sort by the time field and know which tests where taking too long. But this whole process of saving the XML and then modifying it to import into MySQL doesn't looks right to me.

I'm sure there will be a better way to do this, to save the results directly into the database without the human interaction.

After searching for a while on the internet I couldn't find anything about it, so I built my own solution for this matter.

Checking the PHPUnit documentation I found this section about Extending the TestRunner with custom hooks. In other words, I can run a specific code after each test with the hook executeAfterTest.

Following that, I added the extension to my phpunit.xml file

<phpunit>
    <extensions>
        <extension class="Tests\ResultToMysqlExtension" />
    </extensions>
</phpunit>

And created the file tests/ResultToMysqlExtension.php

<?php

namespace Tests;

use Exception;
use PDO;
use PHPUnit\Runner\AfterTestHook;

class ResultToMysqlExtension implements AfterTestHook
{
    protected $connection;

    protected $credentials = [
        'database' => 'phpunit_results',
        'table' => 'default',
        'username' => 'root',
        'password' => '',
        'host' => '127.0.0.1'
    ];

    public function __construct(array $credentials = [])
    {
        $this->credentials = array_merge($this->credentials, $credentials);

        $this->connection = new PDO(
            "mysql:dbname={$this->credentials['database']};host={$this->credentials['host']}", 
            $this->credentials['username'], 
            $this->credentials['password'], 
            [PDO::ATTR_ERRMODE => PDO::ERRMODE_EXCEPTION]
        );
    }

    public function executeAfterTest(string $test, float $time): void
    {
        try {

            $this->insertRecord($test, $time);

        } catch (Exception $e) {

            echo $e->getMessage();

        }
    }

    protected function insertRecord(string $test, float $time): void
    {
        [$class, $method] = explode('::', $test);

        $this->connection
            ->prepare(
                "INSERT INTO `{$this->credentials['table']}` (time, method, class, name) 
                VALUES(:time, :method, :class, :test) 
                ON DUPLICATE KEY UPDATE time = :time;"
            )
            ->execute([
                'time' => $time,
                'method' => $method,
                'class' => $class,
                'test' => $test,
            ]);
    }
}

In order for this to work, you would need to create the database called phpunit_results and the table default with the following structure.

CREATE TABLE default (
    `time` float DEFAULT NULL,
    `name` varchar(255) COLLATE utf8_unicode_ci NOT NULL,
    `method` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
    `class` varchar(255) COLLATE utf8_unicode_ci DEFAULT NULL,
    PRIMARY KEY (`name`)
) ENGINE=MyISAM DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci;

I'm using the nameas a primary key here to be able to override the execution time. This way there will be no duplicated rows after a few tests executions.

If you want, you can override all of this default configuration by modifying the code when copying it, or you can leave the code as it is and use <arguments>in your phpunit.xml file to specify those credentials.

<extensions>
    <extension class="Tests\ResultToMysqlExtension">
        <arguments>
            <array>
                <element key="table">
                    <string>my_project</string>
                </element>
                <element key="password">
                    <string>secret</string>
                </element>
            </array>
        </arguments>
    </extension>
</extensions>

Using this arguments you can keep a table per each project you have, without the need of truncating the results, or customize the database credentials. I left those as the default ones since I'm using Laravel Valet for local development.

After you run your testsuite, the table will be populated, and you're ready to check which are the tests that took the most time to run.

SELECT * FROM table ORDER BY time DESC;

You may also like:

Found a typo? Edit this post.
Special thanks to Dieter for the amazing code of this blog.

Got any hints?
No, I'm afraid not.
However if you search within yourself, then...
Cut it out, ok?
I asked for a hint not the crazy philosophies of a Father Christmas look-a-like.
Heed my words, bold adventurer, and your path will lead to wisdom and..
There's just no reasoning with him...
I'm totally stuck as what to do.
I really wish I could help you but I'm just a clueless old fool.
Never a truer word was spoken.
Still clueless?
I'm afraid so.
Still look like a Father Christmas?
I'm afraid so.
Good.
Calypso from Fleur de Lys Simon The Sorcerer