PHP microtime benchmark function time comparisons

Question

I am currently using this function to benchmark some php scripts, the script gets the microtime it takes to execute, and writes it to a log on the server, but the problem i am having is that i have no idea what are some decent times. the script is below followed by some of my times, can anyone give me an idea on what kind of times i want to be within the range of?

PLACE AT THE BEGINNING OF THE PAGE

global $start_time; $start_time = microtime();

PLACE AT THE END OF THE PAGE

global $start_time;
$ra_start = explode(' ', $start_time);
$ra_end = explode(' ', microtime());
$cpu_time = ($ra_end[1]+$ra_end[0]) - ($ra_start[1]+$ra_start[0]);
$f = fopen('/home/mcbeav/cpu_usage.log', 'a', 1);
// time seconds request by_ip
fwrite($f, date('m-d-Y H:m')."\t".$cpu_time."\t".$_SERVER['SERVER_NAME']."\t".$_SERVER['PHP_SELF']."\t".$_SERVER['REMOTE_ADDR']."\n");
fclose($f);

RESULTS FOR THE SAME PAGE

0.10285401344299
0.021783828735352
0.018580913543701
0.042204856872559

Answer 1

it depends on what you are doing. is a lot happening?

Here is a benchmarking class I made a long time ago. You make markers where ever in your code (start, end, etc) with a static method, then print out a report at the bottom of your page with another static method. also keeps track of memory usage. this is somewhat messy since it uses static methods. The better thing might be to profile your code using XDebug:

<?php

    // time and memory benchmarking library
    class benchmark {

        // benchmark marker array
        protected static $benchmark_markers = array();
        // benchmark total duration
        protected static $total_duration = 0;

        // prevents new implimentation
        protected function __construct() {}

        // create new benchmark marker
        public static function create_benchmark_marker($marker_name) {
            $current_time = self::get_microtime();
            // get duration since last marker
            $duration = 0;
            if (self::$benchmark_markers) {
                $last_time = end(self::$benchmark_markers);
                $duration = $current_time - $last_time['end_time'];
            }
            // add to total duration
            self::$total_duration += $duration;
            // add benchmark marker to static array
            self::$benchmark_markers[] = array('name' => $marker_name, 'end_time' => $current_time, 'duration' => $duration, 'memory' => memory_get_usage());
        }

        // report benchmarking
        public static function print_report() {
            self::print_report_head();
            // output each marker line
            foreach (self::$benchmark_markers as $marker_values) {
                if ($marker_values['duration']) {
                    self::print_marker($marker_values, $last_marker_name);
                }
                $last_marker_name = $marker_values['name'];
            }
            self::print_report_foot();
        }

        // get high-precision microtime
        protected static function get_microtime() {
            return preg_replace('/^0(.+?) (.+?)$/', '$2$1', microtime());
        }

        protected static function print_report_head() {
            echo '<table style="clear: both; border-style: none; border-spacing: 1px; background-color: #ccc; font-family: Arial, Helvetica, sans-serif; font-size: 12px;">
                <tr>
                <th style="background-color: #ddd;">Benchmark Range</th>
                <th style="background-color: #ddd;">Seconds</th>
                <th style="background-color: #ddd;">% of Total</th>
                <th style="background-color: #ddd;">Memory Usage</th>
                </tr>';
        }

        protected static function print_marker($marker_values, $last_marker_name) {
            echo '<tr>
                <td style="background-color: #eee;">' . $last_marker_name . ' -> ' . $marker_values['name'] . '</td>
                <td style="text-align: right; background-color: #eee;">' . round($marker_values['duration'], 6) . '</td>
                <td style="text-align: right; background-color: #eee;">' . round(($marker_values['duration'] / self::$total_duration) * 100, 2) . '%</td>
                <td style="text-align: right; background-color: #eee;">' . number_format($marker_values['memory']) . '</td>
                </tr>';
        }

        protected static function print_report_foot() {
            echo '<tr>
                <td style="background-color: #eee;">Total/Peak</td>
                <td style="text-align: right; background-color: #eee;">' . round(self::$total_duration, 6) . '</td>
                <td style="text-align: right; background-color: #eee;">100%</td>
                <td style="text-align: right; background-color: #eee;">' . number_format(memory_get_peak_usage()) . '</td>
                </tr>
                </table>';
        }
    }
?>

Answer 2

Though I am not sure I got your question right, everything is starting from 0.0 is okay. So, you have to watch the ascipt running 0,1 more closely

just to refactor your code a bit to make it less ancient-looking.

//at the beginning
$start_time = microtime(1);

/at the end
$cpu_time = microtime(1) - $start_time;
$data = date('m-d-Y H:m')."\t".$cpu_time."\t".$_SERVER['SERVER_NAME']."\t".$_SERVER['PHP_SELF']."\t".$_SERVER['REMOTE_ADDR']."\n");
file_put_contents('/home/mcbeav/cpu_usage.log',$data,FILE_APPEND);

Answer 3

You can use microtime(TRUE); and get a whole number back, these days. No need for explode() and addition.

Regarding your times, you should be looking at fairly low execution times for a script like this (assuming this is all the script is actually doing). However, execution may take some more time depending on the I/O load on the system. Judging from the given script, and the execution time, I'm guessing the system you're trying to do this on might be doing a fair bit of I/O work and there's not much you can do to improve it from your PHP script.