Timing your scripts

by Naneau

We all have to optimize, sometimes. Most people hate it, and for good reasons. There’s a real trade-off between code readability and clarity versus optimization. To get information on how your scripts are performing you’ll need to run software like xdebug. That works fine, especially during development.

But sometimes you just want some quick info on how your site is doing. Especially if the code has already been deployed. I often add a little HTML comment to all my pages with the current execution time. It’s by no means a full profiling method, it’s a quick reference that often gives some confirmation if you think something is wrong.

Today I’m going to show you how to do this with the Zend Framework. I have neglected my blog for too long now ;)

1
2
$timeStart = microtime(true);
//ready, set, go!

You need to get a reference point, so on the top of your bootstrap file you have to get the current time in microseconds as a floating point value (that’s what the “true” parameter does).

Now, you must make sure your application can use this value. I personally prefer setting it as a front controller parameter. Like this:

1
2
$frontController->setParam('timeStart', $timeStart);
//the time we started this request

Now, this is where it gets a little complex. See, you only want to add the execution time to HTML output. What I do to achieve this is use a simple plugin (for the front controller). It will check viewRenderer, to see if it is set to render, then append the execution time tot the body of the response.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
<?php
/**
 * ExecutionTime.php
 *
 * @category   Naneau
 * @package    Naneau_Plugin
 * @copyright  Copyright (c) 2007 Maurice Fonk - http://naneau.nl
 * @version    0.2
 */

/** base class */
require_once 'Zend/Controller/Plugin/Abstract.php';

/**
 * Naneau_Controller_Plugin_ExecutionTime
 *
 * a simple plugin to add the current execution time to html pages
 *
 * @category   Naneau
 * @package    Naneau_Plugin
 * @copyright  Copyright (c) 2007 Maurice Fonk - http://naneau.nl
 */
class Naneau_Controller_Plugin_ExecutionTime extends Zend_Controller_Plugin_Abstract {
   
    /**
     * dispatchLoopShutdown hook
     *
     * runs after all controller actions have finished. appends execution time
     *
     * @return void
     */
    public function dispatchLoopShutdown() {
        $viewRenderer = Zend_Controller_Action_HelperBroker::getExistingHelper('viewRenderer');
        //view renderer action helper
        if (!$viewRenderer->getNeverRender()) {
            //viewRenderer is set to render (assuming HTML output)

            $front = Zend_Controller_Front::getInstance();
            //the front controller
            if ($startTime = $front->getParam('timeStart')) {
                //the parameter was set (yay!)
                $totalTime = microtime(true) - $startTime;
                //calculate the time difference
                $this->getResponse()->appendBody("\n<!-- total execution time: $totalTime . //-->");
                //append a comment to the HTML body
            }
        }
    }
}

It can of course be registered with the front controller like so:

1
2
$frontController->registerPlugin(new Naneau_Controller_Plugin_ExecutionTime());
//execution time

Make sure it’s the last plugin registered, otherwise other things will get executed after it, and that may influence the execution time.