Write your own code profiler in php


I often find myself saying, “Yes, you can do that in PHP.” When I was challenged with writing a code profiler in PHP, I thought I would choke on those words. However, I discovered that it’s both possible and incredibly useful to write your own code profiler in PHP. So, I’d like to share my findings about how to write a code profiler, what pitfalls you will encounter, and offer you some working code to get you started. You may have used a code profiler such as xdebug or xhprof before. These profilers require you to load a PHP extension.

Profiling Without Extensions
If you were not able to load any new extensions into your environment, you would not be able to use classic profiling tools like xdebug. What’s the best way to solve that problem?

Scriptable Profiling
Consider the use case of a custom profiler. For example, in WordPress, plugins are confined to a known set of files.

plugin-file-listing

The “my-plugin” plugin is entirely contained within the wp-content/plugins/my-plugin folder.

We found it incredibly useful to have a profiler that knew the difference between a WordPress plugin, a WordPress theme, and the WordPress core based on what was happening in the code or where the function was defined.

Or, perhaps you’d like your profiler to automatically capture the function arguments every timeDbAdapter::query() is called and log them to a file. You can do this with a custom profiler.

Writing the Profiler
PHP has an internal function called register_tick_function() that lets you call a function whenever a tickable event occurs. A tickable event is a low level parser operation. Generally, this is one tick per statement, but there are exceptions. You can read more on the PHP documentation site

declare(ticks=1);
register_tick_function('do_profile');

func_one();

function do_profile() {
	$bt = debug_backtrace();
	if (count($bt) <=1) {
		return;
	}
	$frame = $bt[1];
	unset($bt);
	$function = $frame['function'];
	echo __FUNCTION__ . ' :: ' . $function . PHP_EOL;
}

function func_one() {
	echo __FUNCTION__ . PHP_EOL;
	func_two();
}

function func_two() {
	echo __FUNCTION__ . PHP_EOL;
	func_three();
}

function func_three() {
	echo __FUNCTION__ . PHP_EOL;
}

Note: declare(ticks=1); is mandatory. This code tells PHP to call the tick function for a tickable event.

Here’s the output for the above code:

func_one
do_profile :: func_one
func_two
do_profile :: func_two
func_three
do_profile :: func_three
do_profile :: func_two
do_profile :: func_one

You can see in the output that the tick function is called when the function is pushed onto the call stack, and again when the function is popped off of the call stack. Notice that echo is not captured.

Timing Code
Here’s a very simple example of a working profiler. It’s the same code as above, with one important enhancement: do_profile keeps track of the functions and how much runtime was spent in each function. This information is stored in the global $profile array.

Instead of each function printing its name, the functions pause (or sleep) for a specified amount of time. To get a quick overview of the accuracy of the profiler, let’s compare the profiler results with the amount of time we programmed the functions to sleep.

declare(ticks=1);
register_tick_function('do_profile');

$profile = array();
$last_time = microtime(true);

func_one();
show_profile();

function do_profile() {
    global $profile, $last_time;
    $bt = debug_backtrace();
    if (count($bt) <= 1) {
        return ;
    }
    $frame = $bt[1];
    unset($bt);
    $function = $frame['function'];
    if (!isset($profile[$function])) {
        $profile[$function] = 0;
    }
    $profile[$function] += (microtime(true) - $last_time);
    $last_time = microtime(true);
}

function show_profile() {
    global $profile;
    print_r($profile);
}

function func_one() {
    usleep(50 * 1000);
    func_two();
}

function func_two() {
    usleep(500 * 1000);
    func_three();
}

function func_three() {
    usleep(5000 * 1000);
}

After running the above code, here’s the output:

Array (
    [func_one] => 0.050179958343506
    [func_two] => 0.50016498565674
    [func_three] => 5.0001859664917
)

These results match the programmed pauses that were placed in the code.

At this point, I hope your mind is swarming with possibilities. You may have some questions like, “How well does this scale to large projects?” or “Does it really work across platforms?” or “How reliable are these numbers?” or “What’s the performance penalty?”

Check out the P3 Plugin for WordPress. Go Daddy released a performance tool for WordPress (shown below), using this exact technology and it has been used successfully by thousands of customers across dozens of server configurations. This method isn’t perfect (I’ll discuss some known issues later), but it’s perfectly usable.

screenshot-2

P3 Profiler Results

A Workable Solution
Things get complex from here on out. There are many types of callable functions in PHP that are detected using debug_backtrace(), such as includes, object calls, static method calls, function calls, and anonymous functions. There are also slight variations in the arguments for debug_backtrace() between PHP versions.

The SimpleProfiler class below should get you started on your own custom PHP profiling solution. It’s very similar to what we’re using in P3.

SimpleProfiler.class.php

/**
 * A very simple php code profiler. No extensions required.
 *
 * Example usage:
 * <code>
 * declare(ticks=1);
 * require_once('./SimpleProfiler.class.php');
 * SimpleProfiler::start_profile();
 * // your code here
 * SimpleProfiler::stop_profile();
 * print_r(SimpleProfiler::get_profile());
 * </code>
 *
 * Consider combining with auto_prepend_file and auto_append_file
 *
 * @package SimpleProfiler
 * @author Kurt Payne
 * @copyright 2012 Go Daddy
 * @license http://www.gnu.org/licenses/gpl-3.0.txt GPLv3
 * @version Release: 1.0
 * @link http://inside.godaddy.com/write-code-profiler-php
 */
class SimpleProfiler {

    /**
     * Profile information
     * [file] => (
     *     [function] => runtime in microseconds
     * )
     * @access protected
     * @var array
     */
    protected static $_profile = array();

    /**
     * Remember the last time a tickable event was encountered
     * @access protected
     * @var float
     */
    protected static $_last_time = 0;

    /**
     * Return profile information
     * [file] => (
     *     [function] => runtime in microseconds
     * )
     * @access public
     * @return array
     */
    public static function get_profile() {
        return self::$_profile;
    }

    /**
     * Attempt to disable any detetected opcode caches / optimizers
     * @access public
     * @return void
     */
    public static function disable_opcode_cache() {
        if ( extension_loaded( 'xcache' ) ) {
            @ini_set( 'xcache.optimizer', false ); // Will be implemented in 2.0, here for future proofing
            // XCache seems to do some optimizing, anyway.
            // The recorded number of ticks is smaller with xcache.cacher enabled than without.
        } elseif ( extension_loaded( 'apc' ) ) {
            @ini_set( 'apc.optimization', 0 ); // Removed in APC 3.0.13 (2007-02-24)
            apc_clear_cache();
        } elseif ( extension_loaded( 'eaccelerator' ) ) {
            @ini_set( 'eaccelerator.optimizer', 0 );
            if ( function_exists( 'eaccelerator_optimizer' ) ) {
                @eaccelerator_optimizer( false );
            }
            // Try setting eaccelerator.optimizer = 0 in a .user.ini or .htaccess file
        } elseif (extension_loaded( 'Zend Optimizer+' ) ) {
            @ini_set('zend_optimizerplus.optimization_level', 0);
        }
    }

    /**
     * Start profiling
     * @access public
     * @return void
     */
    public static function start_profile() {
        if (0 === self::$_last_time) {
            self::$_last_time = microtime(true);
            self::disable_opcode_cache();
        }
        register_tick_function(array(__CLASS__, 'do_profile'));
    }

    /**
     * Stop profiling
     * @access public
     * @return void
     */
    public static function stop_profile() {
        unregister_tick_function(array(__CLASS__, 'do_profile'));
    }

    /**
     * Profile.
     * This records the source class / function / file of the current tickable event
     * and the time between now and the last tickable event. This information is
     * stored in self::$_profile
     * @access public
     * @return void
     */
    public static function do_profile() {

        // Get the backtrace, keep the object in case we need to reflect
        // upon it to find the original source file
        if ( version_compare( PHP_VERSION, '5.3.6' ) < 0 ) {
            $bt = debug_backtrace( true );
        } elseif ( version_compare( PHP_VERSION, '5.4.0' ) < 0 ) {
            $bt = debug_backtrace( DEBUG_BACKTRACE_IGNORE_ARGS | DEBUG_BACKTRACE_PROVIDE_OBJECT );
        } else {
            // Examine the last 2 frames
            $bt = debug_backtrace( DEBUG_BACKTRACE_IGNORE_ARGS | DEBUG_BACKTRACE_PROVIDE_OBJECT, 2 );
        }

        // Find the calling function $frame = $bt[0];
        if ( count( $bt ) >= 2 ) {
            $frame = $bt[1];
        }

        // If the calling function was a lambda, the original file is stored here.
        // Copy this elsewhere before unsetting the backtrace
        $lambda_file = @$bt[0]['file'];

        // Free up memory
        unset( $bt );

        // Include/require
        if ( in_array( strtolower( $frame['function'] ), array( 'include', 'require', 'include_once', 'require_once' ) ) ) {
            $file = $frame['args'][0];

        // Object instances
        } elseif ( isset( $frame['object'] ) && method_exists( $frame['object'], $frame['function'] ) ) {
            try {
                $reflector = new ReflectionMethod( $frame['object'], $frame['function'] );
                $file = $reflector->getFileName();
            } catch ( Exception $e ) {
            }

        // Static method calls
        } elseif ( isset( $frame['class'] ) && method_exists( $frame['class'], $frame['function'] ) ) {
            try {
                $reflector = new ReflectionMethod( $frame['class'], $frame['function'] );
                $file = $reflector->getFileName();
            } catch ( Exception $e ) {
            }

        // Functions
        } elseif ( !empty( $frame['function'] ) && function_exists( $frame['function'] ) ) {
            try {
                $reflector = new ReflectionFunction( $frame['function'] );
                $file = $reflector->getFileName();
            } catch ( Exception $e ) {
            }

        // Lambdas / closures
        } elseif ( '__lambda_func' == $frame['function'] || '{closure}' == $frame['function'] ) {
            $file = preg_replace( '/\(\d+\)\s+:\s+runtime-created function/', '', $lambda_file );

        // File info only
        } elseif ( isset( $frame['file'] ) ) {
            $file = $frame['file'];

        // If we get here, we have no idea where the call came from.
        // Assume it originated in the script the user requested.
        } else {
            $file = $_SERVER['SCRIPT_FILENAME'];
        }

        // Function
        $function = $frame['function'];
        if (isset($frame['object'])) {
            $function = get_class($frame['object']) . '::' . $function;
        }

        // Create the entry for the file
        if (!isset(self::$_profile[$file])) {
            self::$_profile[$file] = array();
        }

        // Create the entry for the function
        if (!isset(self::$_profile[$file][$function])) {
            self::$_profile[$file][$function] = 0;
        }

        // Record the call
        self::$_profile[$file][$function] += (microtime(true) - self::$_last_time);
        self::$_last_time = microtime(true);
    }
}

Known Issues
This approach does have some limitations and we’ve learned every single one of them through trial and error. The following are things that will bite you!

  1. You can only profile using tickable events. The PHP manual defines a tick as:

    An event that occurs for every N low-level tickable statements executed by the parser… Not all statements are tickable. Typically, condition expressions and argument expressions are not tickable.

  2. This means some code won’t generate a callback to your tick function. For example, PHP internal function calls are not tickable. Functions that only return a value and do not perform any other operations will not generate any tick events. For example:
    declare(ticks=1);
    register_tick_function('do_profile');
    
    $profile = array();
    $last_time = microtime(true);
    
    func_one();
    show_profile();
    
    function do_profile() { ... }
    
    function show_profile() { ... }
    
    function func_one() {
        usleep(10 * 1000);
        func_two();
    }
    
    function func_two() {
        return true;
    }

    This profile will not show any calls to “func_two” in the output.

  3. Extensions that cache / optimize opcode can impact your results. After much trial and error and testing, here’s what we found (Your mileage may vary, so feedback is welcome.):
    • eaccelerator – The optimizer impacted results, but the cache did not.
      Workaround 1 – Disable the optimizer by setting eaccelerator.optimizer = 0 in .user.ini or .htaccess
      Workaround 2 – Put your app in eaccelerator’s allowed admin path and calleaccelerator_optimizer(false);.
    • Xcache – The FAQ states that an optimizer is coming in version 2. In our testing, we found that the number of tickable events was reduced with Xcache 1.3.x installed, compared to no opcode cache / optimizer extension. There is no workaround available.
    • Zend Optimizer+ – This impacted our results.
      Workaround – Set zend_optimizerplus.optimization_level = 0 in .user.ini or .htaccess. This value can also be changed via ini_set().
    • APC – There is no optimizer as of 3.0.13. The opcode cache impacted results.
      Workaround – Call apc_clear_cache() before you start profiling. This will empty your entire opcode cache every time you start profiling. Be judicious!Note: Opcode cache and optimizers are generally safe and good for performance. This section offers advice on how to disable opcode caches and optimizers for a special use case. Proceed with caution.
    • The tick function (called do_profile above) will be called for every tickable event. For a large application, this means your profiler function can be called thousands of times. Every optimization counts here. If you’re writing targeted profiling code (i.e., “Look for this certain element in the backtrace.”), you will want to invest some time in optimizing it. I will admit that I’ve used xdebug to find performance issues in early versions of P3.
      profile cat
    • Other php code can interfere with your code. If an engineer re-declares the tick directive, there’s nothing you can do about it.
      // This will disable profiling via register_tick_function
      declare (ticks=0);
    • If a piece of code unregisters your tick function, then you’re equally out of luck.
    • There is a warning that register_tick_function() is not compatible with multi-threaded Web servers and PHP versions older than 5.3. See the documentation on php.net for more details.

Conclusion
I am constantly surprised by the amazing things that can be accomplished with PHP. When we first set out to make P3, I wasn’t sure how we were going to do it. This was a fascinating problem to solve. We couldn’t have done this without the feedback we’ve received from the WordPress community. I hope to post more about the development of P3 in the future.

Advertisements

PHPUnit: process isolation and “constant already defined”


This weekend, some WordPress core devs ported the unit tests over to a new phpunit compatible runner. I was very excited about this, particularly because the tests I maintain define a constant (DOING_AJAX) which can impact other tests.  Using process isolation should remove this impact, although at a performance cost.  I used the @runTestsInSeparateProcesses annotation, but the tests failed.  PHPUnit was restoring the global state (e.g. before the test split into a separate process) and it looked like this:

1.) Define all of the constants that were already defined
2.) Include the included files

This is the wrong process for the WordPress framework though. The included files were responsible for defining the constants. When they are included, they generate notices for defining constants that are already defined (by PHPUnit).

We all put our heads together and came up with a fix (props nacin) by hijacking PHPUnit_Framework_TestCase::prepareTemplate().

class MyTestCase extends PHPUnit_Framework_TestCase {

	/**
	 * Define constants after requires/includes
	 * @param Text_Template $template
	 * @return void
	 */
	public function prepareTemplate( Text_Template $template ) {
		$template->setVar( array(
			'constants'    => '',
			'zz_constants' => PHPUnit_Util_GlobalState::getConstantsAsString()
		));
		parent::prepareTemplate( $template );
	}
}

Yes, this is hacky, and PHPUnit warns that prepareTemplate() was deprecated in 3.4.0. But when we looked, there were no other solutions, except disabling process isolation.

Use register_tick_function to profile your code


Okay, so your code is slow.  Why?  Is it your webservice call?  Or a new plugin you installed?  Is it your database calls?  File I/O?  You need a profiler.  A profiler gives you the ability to trace the performance of your code through every function call and create an overview of your system’s performance over a certain time period and helps you make intelligent decisions about where to look for problems.

Code profilers like xdebug and xhprof are essential tools to have for diagnosing performance bottlenecks.  I highly recommend you check them out.  If you have access to installing these extensions on your system, you can probably stop reading here.

But what if you’re in an environment where you can’t install an extension? Luckily, php has a built-in function called register_tick_function that gives you a way to hook in to every user function that’s called.  With this, you can write a profiler yourself.

Here’s some sample code to show you what I mean:

declare(ticks=1);
register_tick_function('do_profile');

a();

function do_profile() {
    $bt = debug_backtrace();
    if (count($bt) <= 1) {
         return;
    }
    $frame = $bt[1];
    unset($bt);
    $function = $frame['function'];
    echo __FUNCTION__ . ' :: ' . $function . PHP_EOL;
}

function a() {
    echo __FUNCTION__ . PHP_EOL;
    b();
}

function b() {
    echo __FUNCTION__ . PHP_EOL;
    c();
}

function c() {
    echo __FUNCTION__ . PHP_EOL;
}

And the output:

a
do_profile :: a
b
do_profile :: b
c
do_profile :: c
do_profile :: b
do_profile :: a

You’ll see in the output that the tick function is being called when the function is called, and again when the function is removed from the stack.

This can be incredibly useful if you attach a timer to it.

Note:  the declare(ticks=1); line is mandatory, it tells php to call your tick handler for every function.  You can change this to declare(ticks=10); to call the tick handler every tenth function if that fits your needs.

Here’s a very simple example of a working profiler. It’s practically the same code as above, but with a timer attached and a shutdown handler to show you the profile when the script is done:

declare(ticks=1);
register_tick_function('do_profile');
register_shutdown_function('show_profile');

$profile = array();
$last_time = microtime(true);

a();

function do_profile() {
    global $profile, $last_time;
    $bt = debug_backtrace();
    if (count($bt) <= 1) {
        return ;
    }
    $frame = $bt[1];
    unset($bt);
    $function = $frame['function'];
    if (!isset($profile[$function])) {
        $profile[$function] = array(
            'time'  => 0,
            'calls' => 0
        );
    }
    $profile[$function]['calls']++;
    $profile[$function]['time'] += (microtime(true) - $last_time);
    $last_time = microtime(true);
}

function show_profile() {
    global $profile;
    print_r($profile);
}

function a() {
    usleep(50 * 1000);
    b();
}

function b() {
    usleep(500 * 1000);
    c();
}

function c() {
    usleep(5000 * 1000);
}

And the output hopefully matches what you would expect:

Array
(
    [a] => Array
        (
            [time] => 0.0511748790741
            [calls] => 2
        )

    [b] => Array
        (
            [time] => 0.500598907471
            [calls] => 2
        )

    [c] => Array
        (
            [time] => 5.00052690506
            [calls] => 1
        )

)

The timing matches what we set in each function. The calls, though, is a bit off, since the tick handler can be called twice for each function. Just note that when you’re interpreting the results.

You can really amp this up to get some good info, though.  Check this out:

P3 Profiler Timeline

If you want to see how it’s done, or see how well it works, give the P3 Plugin for WordPress a look.

Caveats

The tick function is a user function.  This means that whenever php calls a user function it will call your tick function first, but since your  tick function is itself a user function, it will also have the tick function called for it.  It stops after one level of recursion.  Be sure to check for that in your code!

Ticks will not be called on php internal functions.  If your app is having problems due to I/O or an extension, you won’t be able to get the same granularity with a tick function as with an extension based profiler.

Bytecode optimizers will cause you problems.  Function calls will happen, but they won’t be sent through the tick function.  Not exactly sure why on this, but here’s what I’ve got so far:

  • eaccelerator – optimization definitely causes problems
    • disable method 1 – set eaccelerator.optimizer to false
    • disable method 2 – if your app is in eaccelerator’s admin path, call eaccelerator_optimizer(false);
  • xcache – the documentation says there is no optimizer until version 2.0, but experimentation shows some missing function calls, no solution yet
  • zend optimizer+ –  some problems – you can turn this off by setting zend_optimizerplus.optimization_level to 0
  • apc – optimization was removed in 3.0.13 – no problems found
  • wincache – no problems found
  • ioncube – no problems found
  • zend guard loader – no problems found

There’s a warning that this function is not compatible with multi-threaded web servers and php < 5.3.  See the documentation on php.net for more details

Remember to optimize the tick function!  It will be called hundreds or thousands of times in your app, so milliseconds will add up!  If you have a slight mistake in your timing here, it will cause a big shift in your results.

How to Unit Test pcntl_fork()


At some point, many php developers turn to the pcntl functions in php to write a daemon, or server, or simulate threading.

But how do you unit test this with complete code coverage?  Here’s the sample code we’ll be testing:

// @codeCoverageIgnoreStart
if (!defined('TEST_MODE')) {
	define('TEST_MODE', false);
}
// @codeCoverageIgnoreEnd
function start_process() {
	$pid = pcntl_fork();
	if (-1 == $pid) {
		die('Error forking');
	} elseif ($pid > 0)  {
		do {
			echo "Parent - " . getmypid() . "\n";
			sleep(1);
		} while (!TEST_MODE);
	} else {
		echo "Child - " . getmypid() . "\n";
		die();
	}
}

We’ll need to overcome a few big challenges in testing this code:

  • PHPUnit will not re-assemble code-coverage results from across different processes.  This test must remain in one process.  (I’ve tried to find a reference for this, but I can’t … PHPUnit is moving towards parallelized tests, but isn’t there yet)
  • Any calls to die() or exit() will end the test prematurely.
  • The call to sleep(1) will take 1 second of wall time in the test.  That can add up quickly if you have lots of test cases.
  • There isn’t a reliable way to make fork() return -1 to test the error handling branch of the code.

We need to engage some black arts php extensions to make this happen.  An installation guide follows, and the post ends with a complete listing of the unit test.

Disclaimer

These extensions are meant for testing.  These are for your dev or test servers.  Please do not install these on your production servers unless you’re really positive that you want to have them available in your production environment!

Test Helpers

First we’ll need the test_helpers.so extension.  This will let you substitute a callback for any calls to die or exit.

This is a zend_extension, it must be loaded in the correct order, so this one may take some trial and error to get working properly with other zend extensions like xdebug and ioncube.  You can find the extension on github:  https://github.com/sebastianbergmann/php-test-helpers

Once you’ve downloaded and unzipped the package and are in the folder, you can install with:

$ pecl install package.xml

Then add this to your php.ini file:

zend_extension=/path/to/your/php/modules/test_helpers.so

And when you type php -m at the command line, you should see “test_helpers” listed as a Zend Module and a PHP Module.

Runkit

Runkit is a really fun extension that lets you rewrite functions at runtime, execute code in a sandbox, run lint checks on files without spawning a separate process, and other tasks that you probably shouldn’t be doing.  I’ve caused many segfaults in php with runkit.  It doesn’t come with too many safety guards, so be careful with it (see the disclaimer about not running this in production).  You can find the latest version on github here:  https://github.com/zenovich/runkit/

Once you’ve downloaded and unzipped the package and are in the folder, you can install with:

$ pecl install package.xml

Then add this to your php.ini file:

extension=runkit.so

And when you type php -m at the command line, you should see “runkit” listed as a PHP Module.  One last thing, make sure to change this configuration setting for runkit so you can change internal php functions:

runkit.internal_override = 1

The Unit Test

I will skip the guided tour of the evolution of this unit test and jump straight to the finished product.  Here’s a full unit test of the forking code above with 100% coverage.

Note: In the original file, there are ignore coverage wrappers around the code that turns off test mode. Usually this flag is not in a conditional block, it’s set by the application’s framework and is based on the environment + configuration file.  To keep things simple, I’ve chosen to demonstrate this method using a constant.

class ForkTest extends PHPUnit_Framework_TestCase {

	/**
	 * Calls to our mock functions
	 * @var array
	 */
	public static $mock_calls = array(
		'sleep'      => 0,
		'pcntl_fork' => 0,
		'_die'       => 0
	);

	/**
	 * Constructor
	 * Check for necessary php extensions
	 */
	public function __construct() {
		if (!extension_loaded('test_helpers')) {
			echo "These unit tests require the test_helpers extension.  For more information, please visit:\n";
			echo "https://github.com/sebastianbergmann/php-test-helpers\n";
			exit(1);
		}
		if (!extension_loaded('runkit')) {
			echo "These unit tests require the runkit extension.  For more information, please visit:\n";
			echo "https://github.com/zenovich/runkit/\n";
			exit(1);
		}
		parent::__construct();
		define('TEST_MODE', true);
	}

	/**
	 * Setup
	 */
    protected function setUp() {

		// Disable exit / die functionality
		set_exit_overload(array(__CLASS__, '_die'));

		// Sleep quicker (seconds -> milliseconds)
		runkit_function_copy('sleep', '__backup_sleep');
		runkit_function_redefine('sleep', '$sec', 'ForkTest::sleep($sec);');

		// Reset mock calls
		foreach ( array_keys(self::$mock_calls) as $key ) {
			self::$mock_calls[$key] = 0;
		}

		// Get the system under test
		require_once('./fork.php');
    }

	/**
	 * Tear down
	 */
	protected function tearDown() {

		// Restore exit/die functionality
		unset_exit_overload();

		// Restore the original sleep() function
		runkit_function_remove('sleep');
		runkit_function_copy('__backup_sleep', 'sleep');
		runkit_function_remove('__backup_sleep');
	}

	/**
	 * Test the parent path of pcntl_fork()
	 */
    public function testParent() {

		// Force pcntl_fork to return 1 (meaning parent)
		runkit_function_copy('pcntl_fork', '__backup_pcntl_fork');
		runkit_function_redefine('pcntl_fork', '', 'return ForkTest::pcntl_fork(1);');

		// Baseline assertions
		$this->assertEquals(self::$mock_calls['sleep'],      0);
		$this->assertEquals(self::$mock_calls['pcntl_fork'], 0);
		$this->assertEquals(self::$mock_calls['_die'],       0);

		// Call forking code
		start_process();

		// Stuff happened
		$this->assertEquals(self::$mock_calls['sleep'],      1);
		$this->assertEquals(self::$mock_calls['pcntl_fork'], 1);
		$this->assertEquals(self::$mock_calls['_die'],       0);

		// Retore original pcntl_fork functionality
		runkit_function_remove('pcntl_fork');
		runkit_function_copy('__backup_pcntl_fork', 'pcntl_fork');
		runkit_function_remove('__backup_pcntl_fork');
    }

	/**
	 * Test the child path of pcntl_fork()
	 */
    public function testChild() {

		// Force pcntl_fork to return 0 (meaning child)
		runkit_function_copy('pcntl_fork', '__backup_pcntl_fork');
		runkit_function_redefine('pcntl_fork', '', 'return ForkTest::pcntl_fork(0);');

		// Baseline assertions
		$this->assertEquals(self::$mock_calls['sleep'],      0);
		$this->assertEquals(self::$mock_calls['pcntl_fork'], 0);
		$this->assertEquals(self::$mock_calls['_die'],       0);

		// Call forking code
		start_process();

		// Stuff happened
		$this->assertEquals(self::$mock_calls['sleep'],      0);
		$this->assertEquals(self::$mock_calls['pcntl_fork'], 1);
		$this->assertEquals(self::$mock_calls['_die'],       1);

		// Retore original pcntl_fork functionality
		runkit_function_remove('pcntl_fork');
		runkit_function_copy('__backup_pcntl_fork', 'pcntl_fork');
		runkit_function_remove('__backup_pcntl_fork');
    }

	/**
	 * Test the error path of pcntl_fork
	 */
    public function testCouldNotFork() {

		// Force pcntl_fork to return -1 (meaning could not fork)
		runkit_function_copy('pcntl_fork', '__backup_pcntl_fork');
		runkit_function_redefine('pcntl_fork', '', 'return ForkTest::pcntl_fork(-1);');

		// Baseline assertions
		$this->assertEquals(self::$mock_calls['sleep'],      0);
		$this->assertEquals(self::$mock_calls['pcntl_fork'], 0);
		$this->assertEquals(self::$mock_calls['_die'],       0);

		// Call forking code
		start_process();

		// Stuff did not happen
		$this->assertEquals(self::$mock_calls['sleep'],      0);
		$this->assertEquals(self::$mock_calls['pcntl_fork'], 1);
		$this->assertEquals(self::$mock_calls['_die'],       1);

		// Retore original pcntl_fork functionality
		runkit_function_remove('pcntl_fork');
		runkit_function_copy('__backup_pcntl_fork', 'pcntl_fork');
		runkit_function_remove('__backup_pcntl_fork');
    }

	/**
	 * Pretend to fork
	 * @param int $return_value
	 * @return int
	 */
	public static function pcntl_fork($return) {
		self::$mock_calls[__FUNCTION__]++;
		return $return;
	}

	/**
	 * Mock sleep function
	 * Sleep a little bit (seconds -> millisecond)
	 * @param int $sec
	 */
	public static function sleep($sec) {
		self::$mock_calls[__FUNCTION__]++;
		usleep($sec * 1000);
	}

	/**
	 * Mock die function
	 * @return bool
	 */
	public static function _die() {
		self::$mock_calls[__FUNCTION__]++;
		return false;
	}
}

And the proof:

[root@server1 forktest]# phpunit --coverage-html=/var/www/html/coverage/ ForkTest.php
PHPUnit 3.6.4 by Sebastian Bergmann.

.Parent - 25260
.Child - 25260
.

Time: 0 seconds, Memory: 5.75Mb

OK (3 tests, 18 assertions)

Generating code coverage report, this may take a moment.
Code Coverage Report

Code Coverage Report

Visual PHP Unit + WordPress Unit Tests


I saw VisualPHPUnit and was immediately interested.  This provided a very nice visual wrapper to PHPUnit without full blown continuous integration, and kept a history of your test passes / fails.

VisualPHPUnit

VisualPHPUnit is a wrapper for PHPUnit.  It expects that your tests are compatible with PHPUnit’s command line test runner already.

Could this work with WordPress’ Unit Tests?  After some investigation, I’m sad to report that, no, it can’t.  VisualPHPUnit makes several assumptions that are incompatible with WordPress’ test suite.  These are not bad assumptions, just incompatible ones.

  • Include the bootstrap before the PHPUnit library.  This causes problems because the bootstrap cannot reference PHPUnit (e.g. extending PHPUnit_Framework_TestCase).
  • Always include the PHPUnit library.  This causes problems because the bootstrap may have already included PHPUnit (to solve the above problem).  Code like this would solve the issue:
    if( !function_exists( 'phpunit_autoload' ) ) {
    require_once( 'PHPUnit/Autoload.php' );
    }
  • Each test case (a class) is assumed to be in a single file, and named accordingly.  WordPress sometimes groups multiple test cases together in a single file.  A good example of this is test_includes_formatting.php.

Why don’t I submit these issues to VisualPHPUnit?  These aren’t bugs.  They are incompatibilities between how VisualPHPUnit expects things to be done, and how WordPress’ Unit Test do things.  Changing these items in VisualPHPUnit could break compatibility with other projects.

Why don’t WordPress’ unit tests conform to PHPUnit’s structure?

WordPress was also released in 2003, which was before test-driven-development really took off in the php world.  Having a testable app requires a certain design.

Also, WordPress wasn’t written from scratch.  WordPress started as a fork of B2/cafelog.  It wasn’t a greenfield design.

Why doesn’t WordPress just fix their unit tests now?

The core dev team wants a more testable app, and they are working to retrofit unit tests into WordPress, but this is a big challenge.

There are situations in WordPress which are difficult to test, but work perfectly fine.  The dev team is left with a difficult choice:  Rewrite a functioning piece of code to be more testable, but possibly introduce new bugs, or leave it alone and put off a new test framework a little longer.

You can actually see some discussion about this on ticket 17749.