Find the slowest PHPUnit tests

We have a PHPUnit test suite that’s taking a while, so I wanted to find out the which tests were taking the longest.

With the help of Google, I discovered the --log-junit phpunit-results.xml command line option to phpunit which creates an XML file with the info I need. Running on Slim‘s codebase, we create the XML file with:

$ ./vendor/bin/phpunit --log-junit phpunit-results.xml
...
Tests: 436, Assertions: 832, PHPUnit Notices: 37.

It looks like this (formatted by me):

$ head -n 7 phpunit-results.xml
<?xml version="1.0" encoding="UTF-8"?>
<testsuites>
  <testsuite 
      name="/Users/rob/Projects/slim/slimphp/Slim/phpunit.xml" 
      tests="436" 
      assertions="832" 
      errors="0" 
      failures="0" 
      skipped="0" 
      time="0.595106">
    <testsuite 
        name="Slim Test Suite" 
        tests="436" 
        assertions="832" 
        errors="0" 
        failures="0" 
        skipped="0" 
        time="0.595106">
      <testsuite 
          name="Slim\Tests\Routing\RouteContextTest" 
          file="/Users/rob/Projects/slim/slimphp/Slim/tests/Routing/RouteContextTest.php" 
          tests="5" 
          assertions="14" 
          errors="0" 
          failures="0" 
          skipped="0" 
          time="0.004264">
        <testcase 
            name="testCanCreateInstanceWithoutRoute" 
            file="/Users/rob/Projects/slim/slimphp/Slim/tests/Routing/RouteContextTest.php" 
            line="43" 
            class="Slim\Tests\Routing\RouteContextTest" 
            classname="Slim.Tests.Routing.RouteContextTest" 
            assertions="4" 
            time="0.002566"/>
        <testcase 
            name="testCanCreateInstanceWithoutBasePathAndThrowExceptionIfGetBasePathIsCalled" 
            file="/Users/rob/Projects/slim/slimphp/Slim/tests/Routing/RouteContextTest.php" 
            line="57" 
            class="Slim\Tests\Routing\RouteContextTest" 
            classname="Slim.Tests.Routing.RouteContextTest" 
            assertions="4" 
            time="0.000505"/>

Each testcase has a time attribute, so I asked my LLM to create some Python to sort by time and list the top 5:

$ python3 -I -c '
import sys, heapq, xml.etree.ElementTree as ET

cases = ET.parse(sys.argv[1]).iter("testcase")
slowest = heapq.nlargest(5, cases, key=lambda c: float(c.get("time", 0)))

for c in slowest:
    print(f"{float(c.get("time", 0)):8.3f}s  {c.get("class")}::{c.get("name")}")
' phpunit-results.xml

For this test, I get:

$ python3 -I -c 'import sys, heapq, xml.etree.ElementTree as ET; print(*(f"{float(c.get("time", 0)):8.3f}s  {c.get("class")}::{c.get("name")}" for c in heapq.nlargest(5, ET.parse(sys.argv[1]).iter("testcase"), key=lambda c: float(c.get("time", 0)))), sep="\n")' phpunit-results.xml 
0.028275 Slim\Tests\AppTest testAnyRoute
0.026482 Slim\Tests\AppTest testInvokeSequentialProcessAfterAddingAnotherRouteArgument
0.020176 Slim\Tests\AppTest testInvokeSequentialProcessToAPathWithOptionalArgsAndWithoutOptionalArgsAndKeepSetedArgs
0.016482 Slim\Tests\MiddlewareDispatcherTest testExecutesMiddlewareLastInFirstOut
0.013571 Slim\Tests\Factory\AppFactoryTest testCreateAppWithContainerUsesContainerDependenciesWhenPresent

Obviously, Slim’s tests are quick, so there’s no much to see here, but for my client’s project, the numbers are larger!