PHP Performance

Is there a way to gather a log that shows you were certain PHP processes are taking a long time to run?
LVL 7
rgranlundAsked:
Who is Participating?
I wear a lot of hats...

"The solutions and answers provided on Experts Exchange have been extremely helpful to me over the last few years. I wear a lot of hats - Developer, Database Administrator, Help Desk, etc., so I know a lot of things but not a lot about one thing. Experts Exchange gives me answers from people who do know a lot about one thing, in a easy to use platform." -Todd S.

Ray PaseurCommented:
There are some tools you can buy for this.  If you want some free instrumentation, you can use this timer class to record the elapsed time inside a part of a PHP script.  Examples of usage follow line 156.

<?php // demo/class_Stopwatch.php
error_reporting(E_ALL);

// A SCRIPT TIMER FOR ALL OR PART OF A SCRIPT PHP 5+
// MAN PAGE http://php.net/manual/en/function.microtime.php
class StopWatch
{
    protected $a; // START TIME
    protected $s; // STATUS - IF RUNNING
    protected $z; // STOP TIME

    public function __construct()
    {
        $this->a = array();
        $this->s = array();
        $this->z = array();
    }

    // A METHOD TO PROVIDE A FINAL READOUT, IF NEEDED
    public function __destruct()
    {
        $ret = $this->readout();
        if (!$ret) return FALSE;
        echo
          __CLASS__
        . '::'
        . __FUNCTION__
        . '() '
        ;
        echo "<b>$ret</b>";
        echo PHP_EOL;
    }

    // A METHOD TO REMOVE A TIMER
    public function reset($name='TIMER')
    {
        // RESET ALL TIMERS
        if ($name == 'TIMER')
        {
            $this->__construct();
        }
        else
        {
            unset($this->a[$name]);
            unset($this->s[$name]);
            unset($this->z[$name]);
        }
    }

    // A METHOD TO CAPTURE THE START TIME
    public function start($name='TIMER')
    {
        $this->a[$name] = microtime(TRUE);
        $this->z[$name] = $this->a[$name];
        $this->s[$name] = 'RUNNING';
    }

    // A METHOD TO CAPTURE THE END TIME
    public function stop($name='TIMER')
    {
        $ret = NULL;

        // STOP ALL THE TIMERS
        if ($name == 'TIMER')
        {
            foreach ($this->a as $name => $start_time)
            {
                // IF THIS TIMER IS STILL RUNNING, STOP IT
                if ($this->s[$name])
                {
                    $this->s[$name] = FALSE;
                    $this->z[$name] = microtime(TRUE);
                }
            }
        }

        // STOP ONLY ONE OF THE TIMERS
        else
        {
            if ($this->s[$name])
            {
                $this->s[$name] = FALSE;
                $this->z[$name] = microtime(TRUE);
            }
            else
            {
                $ret .= "ERROR: CALL TO STOP() METHOD: '$name' IS NOT RUNNING";
            }
        }

        // RETURN AN ERROR MESSAGE, IF ANY
        return $ret;
    }

    // A METHOD TO READ OUT THE TIMER(S)
    public function readout($name='TIMER', $dec=3, $m=1000, $t = 'ms', $eol=PHP_EOL)
    {
        $str = NULL;

        // GET READOUTS FOR ALL THE TIMERS
        if ($name == 'TIMER')
        {
            foreach ($this->a as $name => $start_time)
            {
                $str .= $name;

                // IF THIS TIMER IS STILL RUNNING UPDATE THE END TIME
                if ($this->s[$name])
                {
                    $this->z[$name] = microtime(TRUE);
                    $str .= " RUNNING ";
                }
                else
                {
                    $str .= " STOPPED ";
                }

                // RETURN A DISPLAY STRING
                $lapse_time = $this->z[$name] - $start_time;
                $lapse_msec = $lapse_time * $m;
                $lapse_echo = number_format($lapse_msec, $dec);
                $str .= " $lapse_echo $t";
                $str .= $eol;
            }
            return $str;
        }

        // GET A READOUT FOR ONLY ONE TIMER
        else
        {
            $str .= $name;

            // IF THIS TIME IS STILL RUNNING, UPDATE THE END TIME
            if ($this->s[$name])
            {
                $this->z[$name] = microtime(TRUE);
                $str .= " RUNNING ";
            }
            else
            {
                $str .= " STOPPED ";
            }

            // RETURN A DISPLAY STRING
            $lapse_time = $this->z[$name] - $this->a[$name];
            $lapse_msec = $lapse_time * $m;
            $lapse_echo = number_format($lapse_msec, $dec);
            $str .= " $lapse_echo $t";
            $str .= $eol;
            return $str;
        }
    }
}


// DEMONSTRATE THE USE -- INSTANTIATE THE STOPWATCH OBJECT
$sw  = new Stopwatch;

// SET A STOPWATCH NAME THAT REFLECTS THE PARTS OF THE SCRIPT WE WANT TO TIME
$g_timer = 'GOOGLE TIMER';

// START A TIMER TO GET ELAPSED TIME FOR A CALL TO GOOGLE
$sw->start($g_timer);

// PERFORM SOME ACTIVITY THAT YOU WANT TO TIME (READS GOOGLE WEB PAGE)
$page = 'https://www.google.com';
$html = file_get_contents($page);

// GET A READOUT OF THE TIMER WHILE IT IS STILL RUNNING
echo nl2br($sw->readout($g_timer));
echo "<br/>" . PHP_EOL;

// PERFORM SOME OTHER ACTIVITY (READS GOOGLE WEB PAGE AGAIN)
$page = 'https://www.google.com';
$html = file_get_contents($page);

// STOP THE TIMER AND GET A READOUT WITH SHORT DECIMALS
$x = $sw->stop($g_timer);
echo nl2br($sw->readout($g_timer, 1));
echo "<br/>" . PHP_EOL;




// START A SECOND TIMER
$y_timer = 'YAHOO TIMER';
$sw->start($y_timer);

// PERFORM SOME OTHER ACTIVITY THAT YOU WANT TO TIME
$page = 'http://yahoo.com/';
$html = file_get_contents($page);

// REPORT THE STOPWATCHES CONTENT (ONE IS STOPPED AND ONE IS STILL RUNNING)
echo nl2br($sw->readout());
echo "<br/>" . PHP_EOL;

// SHOW THE OBJECT
echo "<pre>";
var_dump($sw);
echo "</pre>";

// STOP ALL OF THE STOPWATCHES
$sw->stop();

// REPORT THE STOPWATCHES CONTENT AGAIN
echo nl2br($sw->readout());
echo "<br/>" . PHP_EOL;

// SHOW THE OBJECT
echo "<pre>";
var_dump($sw);
echo "</pre>";



// TRY TO STOP A TIMER THAT IS NOT RUNNING
$x = $sw->stop($g_timer);
var_dump($x);
echo "<br/>" . PHP_EOL;
echo "<br/>" . PHP_EOL;



// START THIS TIMER OVER AGAIN
$sw->start($y_timer);

// PERFORM SOME OTHER ACTIVITY THAT YOU WANT TO TIME
$page = 'http://weather.yahoo.com/';
$html = file_get_contents($page);

// REPORT THE STOPWATCHES CONTENT
echo nl2br($sw->readout());
echo "<br/>" . PHP_EOL;

// SHOW THE OBJECT
echo "<pre>";
var_dump($sw);
echo "</pre>";



// REMOVE ONE OF THE STOPWATCHES
$sw->reset($g_timer);

// REPORT THE STOPWATCHES CONTENT
echo nl2br($sw->readout());
echo "<br/>" . PHP_EOL;

// SHOW THE OBJECT
echo "<pre>";
var_dump($sw);
echo "</pre>";



// REMOVE ALL OF THE STOPWATCHES
$sw->reset();
echo "ALL STOPWATCHES HAVE BEEN REMOVED";

// REPORT THE STOPWATCHES CONTENT (SHOWS NOTHING)
echo nl2br($sw->readout());

// SHOW THE OBJECT
echo "<pre>";
var_dump($sw);
echo "</pre>";

// SHOW THE DESTRUCTOR IN ACTION
$sw->start('Foo');
echo "<pre>";
unset($sw);
echo "</pre>";

Open in new window

0

Experts Exchange Solution brought to you by

Your issues matter to us.

Facing a tech roadblock? Get the help and guidance you need from experienced professionals who care. Ask your question anytime, anywhere, with no hassle.

Start your 7-day free trial
gr8gonzoConsultantCommented:
Yes, there is. It's called code profiling and here is an article on how to do it using the free XDebug extension:

http://www.experts-exchange.com/Programming/Languages/Scripting/PHP/A_12179-PHP-Code-Profiling-and-Analyzing-Performance.html
0
It's more than this solution.Get answers and train to solve all your tech problems - anytime, anywhere.Try it for free Edge Out The Competitionfor your dream job with proven skills and certifications.Get started today Stand Outas the employee with proven skills.Start learning today for free Move Your Career Forwardwith certification training in the latest technologies.Start your trial today
PHP

From novice to tech pro — start learning today.

Question has a verified solution.

Are you are experiencing a similar issue? Get a personalized answer when you ask a related question.

Have a better answer? Share it in a comment.