*/
class ProfilerStandard extends Profiler {
/** @var array List of resolved profile calls with start/end data */
- protected $mStack = array();
+ protected $stack = array();
/** @var array Queue of open profile calls with start data */
- protected $mWorkStack = array();
+ protected $workStack = array();
/** @var array Map of (function name => aggregate data array) */
- protected $mCollated = array();
+ protected $collated = array();
/** @var bool */
- protected $mCollateDone = false;
+ protected $collateDone = false;
/** @var bool Whether to collect the full stack trace or just aggregates */
- protected $mCollateOnly = true;
+ protected $collateOnly = true;
/** @var array Cache of a standard broken collation entry */
- protected $mErrorEntry;
+ protected $errorEntry;
/**
* @param array $params
+ * - initTotal : set to false to omit -total/-setup entries (which use request start time)
*/
public function __construct( array $params ) {
parent::__construct( $params );
- $this->addInitialStack();
- }
-
- /**
- * Return whether this a stub profiler
- *
- * @return bool
- */
- public function isStub() {
- return false;
- }
-
- /**
- * Return whether this profiler stores data
- *
- * @see Profiler::logData()
- * @return bool
- */
- public function isPersistent() {
- return false;
+ if ( !isset( $params['initTotal'] ) || $params['initTotal'] ) {
+ $this->addInitialStack();
+ }
}
/**
* Add the inital item in the stack.
*/
protected function addInitialStack() {
- $this->mErrorEntry = $this->getErrorEntry();
+ $this->errorEntry = $this->getErrorEntry();
$initialTime = $this->getInitialTime( 'wall' );
$initialCpu = $this->getInitialTime( 'cpu' );
if ( $initialTime !== null && $initialCpu !== null ) {
- $this->mWorkStack[] = array( '-total', 0, $initialTime, $initialCpu, 0 );
- if ( $this->mCollateOnly ) {
- $this->mWorkStack[] = array( '-setup', 1, $initialTime, $initialCpu, 0 );
+ $this->workStack[] = array( '-total', 0, $initialTime, $initialCpu, 0 );
+ if ( $this->collateOnly ) {
+ $this->workStack[] = array( '-setup', 1, $initialTime, $initialCpu, 0 );
$this->profileOut( '-setup' );
} else {
- $this->mStack[] = array( '-setup', 1, $initialTime, $initialCpu, 0,
+ $this->stack[] = array( '-setup', 1, $initialTime, $initialCpu, 0,
$this->getTime( 'wall' ), $this->getTime( 'cpu' ), 0 );
}
} else {
'max_cpu' => 0.0,
'min_real' => 0.0,
'max_real' => 0.0,
- 'periods' => array(), // not filled if mCollateOnly
- 'overhead' => 0 // not filled if mCollateOnly
+ 'periods' => array(), // not filled if collateOnly
+ 'overhead' => 0 // not filled if collateOnly
);
}
protected function updateEntry(
$name, $elapsedCpu, $elapsedReal, $memChange, $subcalls = 0, $period = null
) {
- $entry =& $this->mCollated[$name];
+ $entry =& $this->collated[$name];
if ( !is_array( $entry ) ) {
$entry = $this->getZeroEntry();
- $this->mCollated[$name] =& $entry;
+ $this->collated[$name] =& $entry;
}
$entry['cpu'] += $elapsedCpu;
$entry['cpu_sq'] += $elapsedCpu * $elapsedCpu;
global $wgDebugFunctionEntry;
if ( $wgDebugFunctionEntry ) {
- $this->debug( str_repeat( ' ', count( $this->mWorkStack ) ) .
+ $this->debug( str_repeat( ' ', count( $this->workStack ) ) .
'Entering ' . $functionname . "\n" );
}
- $this->mWorkStack[] = array(
+ $this->workStack[] = array(
$functionname,
- count( $this->mWorkStack ),
+ count( $this->workStack ),
$this->getTime( 'time' ),
$this->getTime( 'cpu' ),
memory_get_usage()
global $wgDebugFunctionEntry;
if ( $wgDebugFunctionEntry ) {
- $this->debug( str_repeat( ' ', count( $this->mWorkStack ) - 1 ) .
+ $this->debug( str_repeat( ' ', count( $this->workStack ) - 1 ) .
'Exiting ' . $functionname . "\n" );
}
- $item = array_pop( $this->mWorkStack );
+ $item = array_pop( $this->workStack );
list( $ofname, /* $ocount */, $ortime, $octime, $omem ) = $item;
if ( $item === null ) {
if ( $ofname !== '-total' ) {
$message = "Profile section ended by close(): {$ofname}";
$this->debugGroup( 'profileerror', $message );
- if ( $this->mCollateOnly ) {
- $this->mCollated[$message] = $this->mErrorEntry;
+ if ( $this->collateOnly ) {
+ $this->collated[$message] = $this->errorEntry;
} else {
- $this->mStack[] = array( $message, 0, 0.0, 0.0, 0, 0.0, 0.0, 0 );
+ $this->stack[] = array( $message, 0, 0.0, 0.0, 0, 0.0, 0.0, 0 );
}
}
$functionname = $ofname;
} elseif ( $ofname !== $functionname ) {
$message = "Profiling error: in({$ofname}), out($functionname)";
$this->debugGroup( 'profileerror', $message );
- if ( $this->mCollateOnly ) {
- $this->mCollated[$message] = $this->mErrorEntry;
+ if ( $this->collateOnly ) {
+ $this->collated[$message] = $this->errorEntry;
} else {
- $this->mStack[] = array( $message, 0, 0.0, 0.0, 0, 0.0, 0.0, 0 );
+ $this->stack[] = array( $message, 0, 0.0, 0.0, 0, 0.0, 0.0, 0 );
}
}
$realTime = $this->getTime( 'wall' );
$cpuTime = $this->getTime( 'cpu' );
- if ( $this->mCollateOnly ) {
+ if ( $this->collateOnly ) {
$elapsedcpu = $cpuTime - $octime;
$elapsedreal = $realTime - $ortime;
$memchange = memory_get_usage() - $omem;
$this->updateEntry( $functionname, $elapsedcpu, $elapsedreal, $memchange );
} else {
- $this->mStack[] = array_merge( $item,
+ $this->stack[] = array_merge( $item,
array( $realTime, $cpuTime, memory_get_usage() ) );
}
- $this->trxProfiler->recordFunctionCompletion( $functionname, $realTime - $ortime );
}
}
+ public function scopedProfileIn( $section ) {
+ $this->profileIn( $section );
+
+ $that = $this;
+ return new ScopedCallback( function () use ( $that, $section ) {
+ $that->profileOut( $section );
+ } );
+ }
+
/**
* Close opened profiling sections
*/
public function close() {
- while ( count( $this->mWorkStack ) ) {
+ while ( count( $this->workStack ) ) {
$this->profileOut( 'close' );
}
}
- /**
- * Log the data to some store or even the page output
- */
- public function logData() {
- /* Implement in subclasses */
- }
-
/**
* Returns a profiling output to be stored in debug file
*
$wgDebugFunctionEntry = false; // hack
- if ( !count( $this->mStack ) && !count( $this->mCollated ) ) {
+ if ( !count( $this->stack ) && !count( $this->collated ) ) {
return "No profiling output\n";
}
*/
protected function getCallTree() {
return implode( '', array_map(
- array( &$this, 'getCallTreeLine' ), $this->remapCallTree( $this->mStack )
+ array( &$this, 'getCallTreeLine' ), $this->remapCallTree( $this->stack )
) );
}
}
/**
- * Populate mCollated
+ * Return the collated data, collating first if need be
+ * @return array
+ */
+ public function getCollatedData() {
+ if ( !$this->collateDone ) {
+ $this->collateData();
+ }
+ return $this->collated;
+ }
+
+ /**
+ * Populate collated
*/
protected function collateData() {
- if ( $this->mCollateDone ) {
+ if ( $this->collateDone ) {
return;
}
- $this->mCollateDone = true;
+ $this->collateDone = true;
$this->close(); // set "-total" entry
- if ( $this->mCollateOnly ) {
+ if ( $this->collateOnly ) {
return; // already collated as methods exited
}
- $this->mCollated = array();
+ $this->collated = array();
# Estimate profiling overhead
- $profileCount = count( $this->mStack );
+ $profileCount = count( $this->stack );
self::calculateOverhead( $profileCount );
# First, subtract the overhead!
$overheadTotal = $overheadMemory = $overheadInternal = array();
- foreach ( $this->mStack as $entry ) {
+ foreach ( $this->stack as $entry ) {
// $entry is (name,pos,rtime0,cputime0,mem0,rtime1,cputime1,mem1)
$fname = $entry[0];
$elapsed = $entry[5] - $entry[2];
array_sum( $overheadInternal ) / count( $overheadInternal ) : 0;
# Collate
- foreach ( $this->mStack as $index => $entry ) {
+ foreach ( $this->stack as $index => $entry ) {
// $entry is (name,pos,rtime0,cputime0,mem0,rtime1,cputime1,mem1)
$fname = $entry[0];
$elapsedCpu = $entry[6] - $entry[3];
$elapsedReal = $entry[5] - $entry[2];
$memchange = $entry[7] - $entry[4];
- $subcalls = $this->calltreeCount( $this->mStack, $index );
+ $subcalls = $this->calltreeCount( $this->stack, $index );
if ( substr( $fname, 0, 9 ) !== '-overhead' ) {
# Adjust for profiling overhead (except special values with elapsed=0
$this->updateEntry( $fname, $elapsedCpu, $elapsedReal, $memchange, $subcalls, $period );
}
- $this->mCollated['-overhead-total']['count'] = $profileCount;
- arsort( $this->mCollated, SORT_NUMERIC );
+ $this->collated['-overhead-total']['count'] = $profileCount;
+ arsort( $this->collated, SORT_NUMERIC );
}
/**
$prof = "\nProfiling data\n";
$prof .= sprintf( $titleFormat, 'Name', 'Calls', 'Total', 'Each', '%', 'Mem' );
- $total = isset( $this->mCollated['-total'] )
- ? $this->mCollated['-total']['real']
+ $total = isset( $this->collated['-total'] )
+ ? $this->collated['-total']['real']
: 0;
- foreach ( $this->mCollated as $fname => $data ) {
+ foreach ( $this->collated as $fname => $data ) {
$calls = $data['count'];
$percent = $total ? 100 * $data['real'] / $total : 0;
$memory = $data['memory'];
return $prof;
}
- /**
- * @return array
- */
- public function getRawData() {
+ public function getFunctionStats() {
// This method is called before shutdown in the footer method on Skins.
// If some outer methods have not yet called wfProfileOut(), work around
// that by clearing anything in the work stack to just the "-total" entry.
// Collate after doing this so the results do not include profile errors.
- if ( count( $this->mWorkStack ) > 1 ) {
- $oldWorkStack = $this->mWorkStack;
- $this->mWorkStack = array( $this->mWorkStack[0] ); // just the "-total" one
+ if ( count( $this->workStack ) > 1 ) {
+ $oldWorkStack = $this->workStack;
+ $this->workStack = array( $this->workStack[0] ); // just the "-total" one
} else {
$oldWorkStack = null;
}
$this->collateData();
// If this trick is used, then the old work stack is swapped back afterwards
- // and mCollateDone is reset to false. This means that logData() will still
+ // and collateDone is reset to false. This means that logData() will still
// make use of all the method data since the missing wfProfileOut() calls
// should be made by the time it is called.
if ( $oldWorkStack ) {
- $this->mWorkStack = $oldWorkStack;
- $this->mCollateDone = false;
+ $this->workStack = $oldWorkStack;
+ $this->collateDone = false;
}
- $total = isset( $this->mCollated['-total'] )
- ? $this->mCollated['-total']['real']
+ $totalCpu = isset( $this->collated['-total'] )
+ ? $this->collated['-total']['cpu']
+ : 0;
+ $totalReal = isset( $this->collated['-total'] )
+ ? $this->collated['-total']['real']
+ : 0;
+ $totalMem = isset( $this->collated['-total'] )
+ ? $this->collated['-total']['memory']
: 0;
$profile = array();
- foreach ( $this->mCollated as $fname => $data ) {
- $periods = array();
- foreach ( $data['periods'] as $period ) {
- $period['start'] *= 1000;
- $period['end'] *= 1000;
- $periods[] = $period;
- }
+ foreach ( $this->collated as $fname => $data ) {
$profile[] = array(
'name' => $fname,
'calls' => $data['count'],
- 'elapsed' => $data['real'] * 1000,
- 'percent' => $total ? 100 * $data['real'] / $total : 0,
+ 'real' => $data['real'] * 1000,
+ '%real' => $totalReal ? 100 * $data['real'] / $totalReal : 0,
+ 'cpu' => $data['cpu'] * 1000,
+ '%cpu' => $totalCpu ? 100 * $data['cpu'] / $totalCpu : 0,
'memory' => $data['memory'],
+ '%memory' => $totalMem ? 100 * $data['memory'] / $totalMem : 0,
'min' => $data['min_real'] * 1000,
- 'max' => $data['max_real'] * 1000,
- 'overhead' => $data['overhead'],
- 'periods' => $periods
+ 'max' => $data['max_real'] * 1000
);
}
}
/**
- * Get the content type sent out to the client.
- * Used for profilers that output instead of store data.
- * @return string
+ * Get the initial time of the request, based either on $wgRequestTime or
+ * $wgRUstart. Will return null if not able to find data.
+ *
+ * @param string|bool $metric Metric to use, with the following possibilities:
+ * - user: User CPU time (without system calls)
+ * - cpu: Total CPU time (user and system calls)
+ * - wall (or any other string): elapsed time
+ * - false (default): will fall back to default metric
+ * @return float|null
*/
- protected function getContentType() {
- foreach ( headers_list() as $header ) {
- if ( preg_match( '#^content-type: (\w+/\w+);?#i', $header, $m ) ) {
- return $m[1];
+ protected function getTime( $metric = 'wall' ) {
+ if ( $metric === 'cpu' || $metric === 'user' ) {
+ $ru = wfGetRusage();
+ if ( !$ru ) {
+ return 0;
}
+ $time = $ru['ru_utime.tv_sec'] + $ru['ru_utime.tv_usec'] / 1e6;
+ if ( $metric === 'cpu' ) {
+ # This is the time of system calls, added to the user time
+ # it gives the total CPU time
+ $time += $ru['ru_stime.tv_sec'] + $ru['ru_stime.tv_usec'] / 1e6;
+ }
+ return $time;
+ } else {
+ return microtime( true );
+ }
+ }
+
+ /**
+ * Get the initial time of the request, based either on $wgRequestTime or
+ * $wgRUstart. Will return null if not able to find data.
+ *
+ * @param string|bool $metric Metric to use, with the following possibilities:
+ * - user: User CPU time (without system calls)
+ * - cpu: Total CPU time (user and system calls)
+ * - wall (or any other string): elapsed time
+ * - false (default): will fall back to default metric
+ * @return float|null
+ */
+ protected function getInitialTime( $metric = 'wall' ) {
+ global $wgRequestTime, $wgRUstart;
+
+ if ( $metric === 'cpu' || $metric === 'user' ) {
+ if ( !count( $wgRUstart ) ) {
+ return null;
+ }
+
+ $time = $wgRUstart['ru_utime.tv_sec'] + $wgRUstart['ru_utime.tv_usec'] / 1e6;
+ if ( $metric === 'cpu' ) {
+ # This is the time of system calls, added to the user time
+ # it gives the total CPU time
+ $time += $wgRUstart['ru_stime.tv_sec'] + $wgRUstart['ru_stime.tv_usec'] / 1e6;
+ }
+ return $time;
+ } else {
+ if ( empty( $wgRequestTime ) ) {
+ return null;
+ } else {
+ return $wgRequestTime;
+ }
+ }
+ }
+
+ /**
+ * Add an entry in the debug log file
+ *
+ * @param string $s String to output
+ */
+ protected function debug( $s ) {
+ if ( function_exists( 'wfDebug' ) ) {
+ wfDebug( $s );
+ }
+ }
+
+ /**
+ * Add an entry in the debug log group
+ *
+ * @param string $group Group to send the message to
+ * @param string $s String to output
+ */
+ protected function debugGroup( $group, $s ) {
+ if ( function_exists( 'wfDebugLog' ) ) {
+ wfDebugLog( $group, $s );
}
- return null;
}
}
dépôts / lhc / web / wiklou.git / blobdiff