Who wound the clock?

In the past, PHPUnit, more precisely the phpunit/php-timer component it depends on, used to call microtime(true) at the point in time the output shown below is printed.

microtime(true) returns the number of seconds since the Unix epoch with microsecond granularity. Since PHP sets the superglobal variable $_SERVER['REQUEST_TIME_FLOAT'] to the number of seconds since the Unix epoch with microsecond granularity at the beginning of a script's execution, you can use microtime(true) - $_SERVER['REQUEST_TIME_FLOAT'] to get the time since the script execution started.

Over the years, there have been repeated bug reports that PHPUnit either does not show or shows a wrong elapsed time at the end. Often PHP would print the following error message:

The code of phpunit/php-timer tries to access the variable $_SERVER['REQUEST_TIME_FLOAT'] . However, since that is not set the error shown above will occur.

Just because $_SERVER['REQUEST_TIME_FLOAT'] is set by PHP at the beginning of script execution does not mean that it is not variable. Nothing prevents the test code or the production code from using statements such as unset($_SERVER['REQUEST_TIME_FLOAT']); to delete the variable.

If a statement like unset($_SERVER['REQUEST_TIME_FLOAT']); is really necessary, you can annotate this test with @backupGlobals enabled . This annotation instructs PHPUnit to create a copy of all global and superglobal variables before the test is run and to use this backup to restore the original values afterwards.

Some time ago I changed the code of phpunit/php-timer so that an exception is raised when $_SERVER['REQUEST_TIME_FLOAT'] is not set. Of course this does not solve the actual problem, but it is at least cleaner than the PHP notice that was triggered before. Of course, now I started receiving bug reports that PHPUnit throws this exception at the end.

Recently there have been bug reports which are caused by $_SERVER['REQUEST_TIME_FLOAT'] not containing a value of type float . This happens when either the test code or the production code set $_SERVER['REQUEST_TIME_FLOAT'] to an invalid value. I have therefore extended the code of phpunit/php-timer to throw an exception if $_SERVER['REQUEST_TIME_FLOAT'] contains a value that is not of type float .

But what happens if test code or production code set $_SERVER['REQUEST_TIME_FLOAT'] to a value that has the correct type ( float ), but does not represent the actual current time? phpunit/php-timer cannot detect this and will calculate the elapsed time incorrectly. The same applies if test code or production code change the actual system time.

It was time to realize that "looking at the clock", especially through a superglobal variable such as $_SERVER['REQUEST_TIME_FLOAT'] is not a good idea. By the way, this does not only apply to showing the elapsed time at the end of the test suite's execution, but also to measuring how long individual tests take. This information is, for instance, reported in the TestDox output or in the XML logfiles.

So if we cannot trust $_SERVER['REQUEST_TIME_FLOAT'] and microtime() then how are we supposed to measure time? The answer is hrtime() .

hrtime() was introduced in PHP 7.3. The current version of PHPUnit requires PHP 7.3: perfect! I am allowed to use hrtime() .

PHPUnit 9.2, which was released today, now uses phpunit/php-timer in version 4.0 which has been rewritten from scratch. PHPUnit no longer uses $_SERVER['REQUEST_TIME_FLOAT'] and microtime() .

Instead, hrtime() is called once when the CLI test runner starts. hrtime() is called again at the end of the test run. The difference between the two return values of hrtime() is the elapsed time that is printed. Before and after each test, hrtime() is called. The difference between these two return values of hrtime() is the duration of the respective test.