X-Git-Url: http://git.cyclocoop.org/?a=blobdiff_plain;f=includes%2Fprofiler%2FSectionProfiler.php;h=2c36b68c1579bc8e690bdec2d07a958694f53cbe;hb=2721bc43dfc1ea6a3af678c63bdd3a06b2795cc2;hp=89eebbe27baaac2fc4a3f6c2d35f8072cc2b016e;hpb=df45c62a3486f809370e5da4efef100855971bba;p=lhc%2Fweb%2Fwiklou.git diff --git a/includes/profiler/SectionProfiler.php b/includes/profiler/SectionProfiler.php index 89eebbe27b..2c36b68c15 100644 --- a/includes/profiler/SectionProfiler.php +++ b/includes/profiler/SectionProfiler.php @@ -28,6 +28,10 @@ * @since 1.25 */ class SectionProfiler { + /** @var array Map of (mem,real,cpu) */ + protected $start; + /** @var array Map of (mem,real,cpu) */ + protected $end; /** @var array List of resolved profile calls with start/end data */ protected $stack = array(); /** @var array Queue of open profile calls with start data */ @@ -37,11 +41,13 @@ class SectionProfiler { protected $collated = array(); /** @var bool */ protected $collateDone = false; + /** @var bool Whether to collect the full stack trace or just aggregates */ protected $collateOnly = true; - /** @var array Cache of a standard broken collation entry */ protected $errorEntry; + /** @var callable Cache of a profile out callback */ + protected $profileOutCallback; /** * @param array $params @@ -49,6 +55,9 @@ class SectionProfiler { public function __construct( array $params = array() ) { $this->errorEntry = $this->getErrorEntry(); $this->collateOnly = empty( $params['trace'] ); + $this->profileOutCallback = function ( $profiler, $section ) { + $profiler->profileOutInternal( $section ); + }; } /** @@ -59,9 +68,7 @@ class SectionProfiler { $this->profileInInternal( $section ); $that = $this; - return new ScopedCallback( function() use ( $that, $section ) { - $that->profileOutInternal( $section ); - } ); + return new ScopedCallback( $this->profileOutCallback, array( $that, $section ) ); } /** @@ -89,18 +96,15 @@ class SectionProfiler { * - %cpu : percent real time * - memory : memory used (bytes) * - %memory : percent memory used + * - min_real : min real time in a call (ms) + * - max_real : max real time in a call (ms) */ public function getFunctionStats() { $this->collateData(); - $totalCpu = 0.0; - $totalReal = 0.0; - $totalMem = 0; - foreach ( $this->collated as $fname => $data ) { - $totalCpu += $data['cpu']; - $totalReal += $data['real']; - $totalMem += $data['memory']; - } + $totalCpu = max( $this->end['cpu'] - $this->start['cpu'], 0 ); + $totalReal = max( $this->end['real'] - $this->start['real'], 0 ); + $totalMem = max( $this->end['memory'] - $this->start['memory'], 0 ); $profile = array(); foreach ( $this->collated as $fname => $data ) { @@ -113,6 +117,8 @@ class SectionProfiler { '%cpu' => $totalCpu ? 100 * $data['cpu'] / $totalCpu : 0, 'memory' => $data['memory'], '%memory' => $totalMem ? 100 * $data['memory'] / $totalMem : 0, + 'min_real' => 1000 * $data['min_real'], + 'max_real' => 1000 * $data['max_real'] ); } @@ -125,11 +131,25 @@ class SectionProfiler { '%cpu' => 100, 'memory' => $totalMem, '%memory' => 100, + 'min_real' => 1000 * $totalReal, + 'max_real' => 1000 * $totalReal ); return $profile; } + /** + * Clear all of the profiling data for another run + */ + public function reset() { + $this->start = null; + $this->end = null; + $this->stack = array(); + $this->workStack = array(); + $this->collated = array(); + $this->collateDone = false; + } + /** * @return array Initial collation entry */ @@ -138,7 +158,9 @@ class SectionProfiler { 'cpu' => 0.0, 'real' => 0.0, 'memory' => 0, - 'count' => 0 + 'count' => 0, + 'min_real' => 0.0, + 'max_real' => 0.0 ); } @@ -169,6 +191,8 @@ class SectionProfiler { $entry['real'] += $elapsedReal; $entry['memory'] += $memChange > 0 ? $memChange : 0; $entry['count']++; + $entry['min_real'] = min( $entry['min_real'], $elapsedReal ); + $entry['max_real'] = max( $entry['max_real'], $elapsedReal ); } /** @@ -177,12 +201,25 @@ class SectionProfiler { * @param string $functionname */ public function profileInInternal( $functionname ) { + // Once the data is collated for reports, any future calls + // should clear the collation cache so the next report will + // reflect them. This matters when trace mode is used. + $this->collateDone = false; + + $cpu = $this->getTime( 'cpu' ); + $real = $this->getTime( 'wall' ); + $memory = memory_get_usage(); + + if ( $this->start === null ) { + $this->start = array( 'cpu' => $cpu, 'real' => $real, 'memory' => $memory ); + } + $this->workStack[] = array( $functionname, count( $this->workStack ), - $this->getTime( 'time' ), - $this->getTime( 'cpu' ), - memory_get_usage() + $real, + $cpu, + $memory ); } @@ -217,17 +254,25 @@ class SectionProfiler { $this->stack[] = array( $message, 0, 0.0, 0.0, 0, 0.0, 0.0, 0 ); } } + $realTime = $this->getTime( 'wall' ); $cpuTime = $this->getTime( 'cpu' ); + $memUsage = memory_get_usage(); + if ( $this->collateOnly ) { $elapsedcpu = $cpuTime - $octime; $elapsedreal = $realTime - $ortime; - $memchange = memory_get_usage() - $omem; + $memchange = $memUsage - $omem; $this->updateEntry( $functionname, $elapsedcpu, $elapsedreal, $memchange ); } else { - $this->stack[] = array_merge( $item, - array( $realTime, $cpuTime, memory_get_usage() ) ); + $this->stack[] = array_merge( $item, array( $realTime, $cpuTime, $memUsage ) ); } + + $this->end = array( + 'cpu' => $cpuTime, + 'real' => $realTime, + 'memory' => $memUsage + ); } /** @@ -320,6 +365,7 @@ class SectionProfiler { $this->collated = array(); # Estimate profiling overhead + $oldEnd = $this->end; $profileCount = count( $this->stack ); $this->calculateOverhead( $profileCount ); @@ -355,7 +401,7 @@ class SectionProfiler { $subcalls = $this->calltreeCount( $this->stack, $index ); if ( substr( $fname, 0, 9 ) !== '-overhead' ) { - # Adjust for profiling overhead (except special values with elapsed=0 + # Adjust for profiling overhead (except special values with elapsed=0) if ( $elapsed ) { $elapsed -= $overheadInternal; $elapsed -= ( $subcalls * $overheadTotal ); @@ -368,6 +414,9 @@ class SectionProfiler { $this->collated['-overhead-total']['count'] = $profileCount; arsort( $this->collated, SORT_NUMERIC ); + + // Unclobber the end info map (the overhead checking alters it) + $this->end = $oldEnd; } /**