-<?
+<?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( str_repeat( " ", count( $this->mWorkStack ) ) . "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( str_repeat( " ", count( $this->mWorkStack ) - 1 ) . "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 )
+ function getOutput()
{
+ global $wgDebugFunctionEntry;
+ $wgDebugFunctionEntry = false;
+
if( !count( $this->mStack ) ) {
return "No profiling output\n";
}
-
- $format = "%-49s %6d %6.3f %6.3f %6.3f%%\n";
- $titleFormat = "%-49s %9s %9s %9s %9s\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();
$end = explode( " ", $entry[3]);
$end = (float)$end[0] + (float)$end[1];
$elapsed = $end - $start;
+
+ if ( !array_key_exists( $fname, $this->mCollated ) ) {
+ $this->mCollated[$fname] = 0;
+ $this->mCalls[$fname] = 0;
+ }
+
$this->mCollated[$fname] += $elapsed;
$this->mCalls[$fname] ++;
}
- $total = $this->mCollated["-total"];
+ $total = @$this->mCollated["-total"];
$overhead = $this->mCollated["-overhead-internal"] / $profileCount;
$this->mCalls["-overhead-total"] = $profileCount;
if ( $fname[0] != "-" ) {
$elapsed -= $overhead * $calls;
}
-
+
$percent = $total ? 100. * $elapsed / $total : 0;
$prof .= sprintf( $format, $fname, $calls, (float)($elapsed * 1000),
- (float)($elapsed * 1000) / $calls, $percent );
+ (float)($elapsed * 1000) / $calls, $percent );
+
+ global $wgProfileToDatabase;
+ if( $wgProfileToDatabase ) {
+ Profiler::logToDB( $fname, (float)($elapsed * 1000), $calls );
+ }
}
$prof .= "\nTotal: $total\n\n";
return $prof;
}
+
+
+ /* static */ function logToDB($name, $timeSum, $eventCount)
+ {
+ $dbw =& wfGetDB( DB_MASTER );
+ $profiling = $dbw->tableName( 'profiling' );
+
+ $name = $dbw->strencode( $name );
+ $sql = "UPDATE $profiling ".
+ "SET pf_count=pf_count+{$eventCount}, ".
+ "pf_time=pf_time + {$timeSum} ".
+ "WHERE pf_name='{$name}'";
+ $dbw->query($sql);
+
+ $rc = $dbw->affectedRows();
+ if( $rc == 0) {
+ $sql = "INSERT IGNORE INTO $profiling (pf_name,pf_count,pf_time) ".
+ "VALUES ('{$name}', {$eventCount}, {$timeSum}) ";
+ $dbw->query($sql , DB_MASTER);
+ }
+ // 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->profileIn( "-total" );
-
?>