-<?
+<?php
# This file is only included if profiling is enabled
-$wgDebugProfiling = true;
-
function wfProfileIn( $functionname )
{
global $wgProfiler;
function profileIn( $functionname )
{
+ global $wgDebugFunctionEntry;
+ if ( $wgDebugFunctionEntry && function_exists( "wfDebug" ) ) {
+ wfDebug( "Entering $functionname\n" );
+ }
array_push( $this->mWorkStack, array($functionname, count( $this->mWorkStack ), microtime() ) );
}
function profileOut( $functionname)
{
- global $wgDebugProfiling;
+ global $wgDebugProfiling, $wgDebugFunctionEntry;
+
+ if ( $wgDebugFunctionEntry && function_exists( "wfDebug" ) ) {
+ wfDebug( "Exiting $functionname\n" );
+ }
+
$bit = array_pop( $this->mWorkStack );
- if ( $wgDebugProfiling ) {
- if ( $functionname == "close" ) {
- wfDebug( "Profile section ended by close(): {$bit[0]}\n" );
- } elseif ( $bit[0] != $functionname ) {
- wfDebug( "Profiling error: in({$bit[0]}), out($functionname)\n" );
+ if ( !$bit ) {
+ wfDebug( "Profiling error, !\$bit: $functionname\n" );
+ } else {
+ if ( $wgDebugProfiling ) {
+ if ( $functionname == "close" ) {
+ wfDebug( "Profile section ended by close(): {$bit[0]}\n" );
+ } elseif ( $bit[0] != $functionname ) {
+ wfDebug( "Profiling error: in({$bit[0]}), out($functionname)\n" );
+ }
}
+ array_push( $bit, microtime() );
+ array_push( $this->mStack, $bit );
}
- array_push( $bit, microtime() );
- array_push( $this->mStack, $bit );
}
function close()
}
}
-
function getOutput( $scriptStart, $scriptElapsed )
{
- set_time_limit( 0 );
- $width = 80;
- $format = "%-39s %6.2f / %6.2f = %6.2f %6.2f%%\n";
- $prof = "";
if( !count( $this->mStack ) ) {
return "No profiling output\n";
}
+ $this->close();
+ $width = 125;
+ $format = "%-" . ($width - 28) . "s %6d %6.3f %6.3f %6.3f%%\n";
+ $titleFormat = "%-" . ($width - 28) . "s %9s %9s %9s %9s\n";
+ $prof = "\nProfiling data\n";
+ $prof .= sprintf( $titleFormat, "Name", "Calls", "Total", "Each", "%" );
$this->mCollated = array();
-
- $top = $this->doLevel( 0, true );
- $this->merge( "WIKI.PHTML", $top, $scriptElapsed );
- $this->mCollated = array_reverse( $this->mCollated, true );
-/*
- # Calculate totals
- foreach ( $this->mCollated as $f1 => $f1data ) {
- $total = 0;
- foreach ( $f1data as $f2 => $t ) {
- $total += $t;
- }
- $this->mCollated[$f1][0] = $total;
- }
-*/
- # Output
- foreach ( $this->mCollated as $f1 => $f1data ) {
- $prof .= "\n" . str_repeat( "-", $width ) . "\n";
- $t = $this->mTotals[$f1] * 1000;
- $calls = $this->mCalls[$f1];
- if ( $calls == 0 ) {
- $calls = 1;
- }
- $each = $t / $calls;
- $percent = $this->mTotals[$f1] / $scriptElapsed * 100;
- $prof .= sprintf( $format, "| $f1", $t, $calls, $each, $percent );
- $prof .= str_repeat( "-", $width ) . "\n";
- foreach ( $f1data as $f2 => $t ) {
- $percent = $t / $this->mTotals[$f1] * 100;
- $t *= 1000;
- $calls = $this->mCalls[$f1];
- if ( $calls == 0 ) {
- $calls = 1;
- }
- $each = $t / $calls;
- $percent = $this->mTotals[$f1] / $scriptElapsed * 100;
- $prof .= sprintf( $format, $f2, $t, $calls, $each, $percent );
- }
+ $this->mCalls = array();
+
+ # Estimate profiling overhead
+ $profileCount = count( $this->mStack );
+ wfProfileIn( "-overhead-total" );
+ for ($i=0; $i<$profileCount ; $i++) {
+ wfProfileIn( "-overhead-internal" );
+ wfProfileOut( "-overhead-internal" );
}
- $prof .= str_repeat( "-", $width ) . "\n";
- return $prof;
- }
+ wfProfileOut( "-overhead-total" );
-
- function doLevel( $p, $fTop )
- {
- $level = false;
- $getOut = false;
- $hotArray = false;
- $tempArray = array();
- do {
- $fname = $this->mStack[$p][0];
- $thislevel = $this->mStack[$p][1];
- $start = (float)$this->mStack[$p][2] + (float)$this->mStack[$p][3];
- $end = (float)$this->mStack[$p][4] + (float)$this->mStack[$p][5];
+ # Collate
+ foreach ( $this->mStack as $entry ) {
+ $fname = $entry[0];
+ $thislevel = $entry[1];
+ $start = explode( " ", $entry[2]);
+ $start = (float)$start[0] + (float)$start[1];
+ $end = explode( " ", $entry[3]);
+ $end = (float)$end[0] + (float)$end[1];
$elapsed = $end - $start;
- if ( $hotArray !== false ) {
- # Just dropped down a level
- # Therefore this entry is the parent of $hotArray
- $this->merge( $fname, $hotArray, $elapsed );
- $hotArray = false;
+
+ if ( !array_key_exists( $fname, $this->mCollated ) ) {
+ $this->mCollated[$fname] = 0;
+ $this->mCalls[$fname] = 0;
}
- if ( $level === false ) {
- $level = $thislevel;
- }
+ $this->mCollated[$fname] += $elapsed;
+ $this->mCalls[$fname] ++;
+ }
- if ( $thislevel == $level ) {
- $tempArray[$fname] += $elapsed;
- #$this->mTotals[$fname] += elapsed;
- $this->mCalls[$fname] ++;
- } elseif ($thislevel > $level ) {
- $hotArray = $this->doLevel( $p, false );
- } else {
- $getOut = true;
+ $total = @$this->mCollated["-total"];
+ $overhead = $this->mCollated["-overhead-internal"] / $profileCount;
+ $this->mCalls["-overhead-total"] = $profileCount;
+
+ # Output
+ foreach ( $this->mCollated as $fname => $elapsed ) {
+ $calls = $this->mCalls[$fname];
+ # Adjust for overhead
+ if ( $fname[0] != "-" ) {
+ $elapsed -= $overhead * $calls;
}
- # Special case: top of hierarchy
- # File starts with lvl 1 entry, then drops back to lvl 0
- if ( $fTop && $getOut ) {
- $hotArray = $tempArray;
- $getOut = false;
+ $percent = $total ? 100. * $elapsed / $total : 0;
+ $prof .= sprintf( $format, $fname, $calls, (float)($elapsed * 1000),
+ (float)($elapsed * 1000) / $calls, $percent );
+
+ global $wgProfileToDatabase;
+ if( $wgProfileToDatabase ) {
+ Profiler::logToDB( $fname, (float)($elapsed * 1000), $calls );
}
+ }
+ $prof .= "\nTotal: $total\n\n";
- $p++;
- } while ( !$getOut && $p < count( $this->mStack ) );
- return $tempArray;
+ return $prof;
}
- function merge( $f1, $a, $parentTime )
+
+ /* static */ function logToDB($name, $timeSum, $eventCount)
{
- foreach ( $a as $f2 => $elapsed ) {
- $this->mCollated[$f1][$f2] += $elapsed;
+ $name = wfStrencode( $name );
+ $sql = "UPDATE profiling ".
+ "SET pf_count=pf_count+{$eventCount}, ".
+ "pf_time=pf_time + {$timeSum} ".
+ "WHERE pf_name='{$name}'";
+ wfQuery($sql , DB_WRITE);
+
+ $rc = wfAffectedRows();
+ if( $rc == 0) {
+ $sql = "INSERT IGNORE INTO profiling (pf_name,pf_count,pf_time) ".
+ "VALUES ('{$name}', {$eventCount}, {$timeSum}) ";
+ wfQuery($sql , DB_WRITE);
+ $rc = wfAffectedRows();
}
- $this->mTotals[$f1] += $parentTime;
+ // When we upgrade to mysql 4.1, the insert+update
+ // can be merged into just a insert with this construct added:
+ // "ON DUPLICATE KEY UPDATE ".
+ // "pf_count=pf_count + VALUES(pf_count), ".
+ // "pf_time=pf_time + VALUES(pf_time)";
}
+
}
-$wgProfiler = new Profiler();
+$wgProfiler = new Profiler();
+$wgProfiler->profileIn( "-total" );
?>
dépôts / lhc / web / wiklou.git / blobdiff