<?php /********************************************************************************\ * Copyright (C) Carl Taylor (cjtaylor@adepteo.com) * * Copyright (C) Torben Nehmer (torben@nehmer.net) for Code Cleanup * * Licensed under the BSD license upon request * \********************************************************************************/ /// Enable multiple timers to aid profiling of performance over sections of code /** * Execution time profiler. * @package sapphire * @subpackage misc */ class Profiler { var $description; var $startTime; var $endTime; var $initTime; var $cur_timer; var $stack; var $trail; var $trace; var $count; var $running; protected static $inst; /** * Initialise the timer. with the current micro time */ function Profiler( $output_enabled=false, $trace_enabled=false) { $this->description = array(); $this->startTime = array(); $this->endTime = array(); $this->initTime = 0; $this->cur_timer = ""; $this->stack = array(); $this->trail = ""; $this->trace = ""; $this->count = array(); $this->running = array(); $this->initTime = $this->getMicroTime(); $this->output_enabled = $output_enabled; $this->trace_enabled = $trace_enabled; $this->startTimer('unprofiled'); } // Public Methods static function init() { if(!self::$inst) self::$inst = new Profiler(true,true); } static function mark($name, $level2 = "", $desc = "") { if($level2 && $_GET['debug_profile'] > 1) $name .= " $level2"; if(!self::$inst) self::$inst = new Profiler(true,true); self::$inst->startTimer($name, $desc); } static function unmark($name, $level2 = "", $desc = "") { if($level2 && $_GET['debug_profile'] > 1) $name .= " $level2"; if(!self::$inst) self::$inst = new Profiler(true,true); self::$inst->stopTimer($name, $desc); } static function show($showTrace = false) { if(!self::$inst) self::$inst = new Profiler(true,true); echo "<div style=\"position: absolute; z-index: 100000; top: 20px; left: 20px; background-color: white; padding: 20px; border: 1px #AAA solid; height: 80%; overflow: auto;\">"; echo "<p><a href=\"#\" onclick=\"this.parentNode.parentNode.style.display = 'none'; return false;\">(Click to close)</a></p>"; self::$inst->printTimers(); if($showTrace) self::$inst->printTrace(); echo "</div>"; } /** * Start an individual timer * This will pause the running timer and place it on a stack. * @param string $name name of the timer * @param string optional $desc description of the timer */ function startTimer($name, $desc="" ){ $this->trace.="start $name\n"; $n=array_push( $this->stack, $this->cur_timer ); $this->__suspendTimer( $this->stack[$n-1] ); $this->startTime[$name] = $this->getMicroTime(); $this->cur_timer=$name; $this->description[$name] = $desc; if (!array_key_exists($name,$this->count)) $this->count[$name] = 1; else $this->count[$name]++; } /** * Stop an individual timer * Restart the timer that was running before this one * @param string $name name of the timer */ function stopTimer($name){ $this->trace.="stop $name\n"; $this->endTime[$name] = $this->getMicroTime(); if (!array_key_exists($name, $this->running)) $this->running[$name] = $this->elapsedTime($name); else $this->running[$name] += $this->elapsedTime($name); $this->cur_timer=array_pop($this->stack); $this->__resumeTimer($this->cur_timer); } /** * measure the elapsed time of a timer without stoping the timer if * it is still running */ function elapsedTime($name){ // This shouldn't happen, but it does once. if (!array_key_exists($name,$this->startTime)) return 0; if(array_key_exists($name,$this->endTime)){ return ($this->endTime[$name] - $this->startTime[$name]); } else { $now=$this->getMicroTime(); return ($now - $this->startTime[$name]); } }//end start_time /** * Measure the elapsed time since the profile class was initialised * */ function elapsedOverall(){ $oaTime = $this->getMicroTime() - $this->initTime; return($oaTime); }//end start_time /** * print out a log of all the timers that were registered * */ function printTimers($enabled=false) { if($this->output_enabled||$enabled){ $TimedTotal = 0; $tot_perc = 0; ksort($this->description); print("<pre>\n"); $oaTime = $this->getMicroTime() - $this->initTime; echo"============================================================================\n"; echo " PROFILER OUTPUT\n"; echo"============================================================================\n"; print( "Calls Time Routine\n"); echo"-----------------------------------------------------------------------------\n"; while (list ($key, $val) = each ($this->description)) { $t = $this->elapsedTime($key); $total = $this->running[$key]; $count = $this->count[$key]; $TimedTotal += $total; $perc = ($total/$oaTime)*100; $tot_perc+=$perc; // $perc=sprintf("%3.2f", $perc ); $lines[ sprintf( "%3d %3.4f ms (%3.2f %%) %s\n", $count, $total*1000, $perc, $key) ] = $total; } arsort($lines); foreach($lines as $line => $total) { echo $line; } echo "\n"; $missed=$oaTime-$TimedTotal; $perc = ($missed/$oaTime)*100; $tot_perc+=$perc; // $perc=sprintf("%3.2f", $perc ); printf( " %3.4f ms (%3.2f %%) %s\n", $missed*1000,$perc, "Missed"); echo"============================================================================\n"; printf( " %3.4f ms (%3.2f %%) %s\n", $oaTime*1000,$tot_perc, "OVERALL TIME"); echo"============================================================================\n"; print("</pre>"); } } function printTrace( $enabled=false ) { if($this->trace_enabled||$enabled){ print("<pre>"); print("Trace\n$this->trace\n\n"); print("</pre>"); } } /// Internal Use Only Functions /** * Get the current time as accuratly as possible * */ function getMicroTime(){ $tmp=explode(' ', microtime()); $rt=$tmp[0]+$tmp[1]; return $rt; } /** * resume an individual timer * */ function __resumeTimer($name){ $this->trace.="resume $name\n"; $this->startTime[$name] = $this->getMicroTime(); } /** * suspend an individual timer * */ function __suspendTimer($name){ $this->trace.="suspend $name\n"; $this->endTime[$name] = $this->getMicroTime(); if (!array_key_exists($name, $this->running)) $this->running[$name] = $this->elapsedTime($name); else $this->running[$name] += $this->elapsedTime($name); } } ?>