22use Psr\Log\LoggerInterface;
23use Wikimedia\ScopedCallback;
59 $this->logger = LoggerFactory::getInstance(
'profiler' );
100if ( is_array( $this->start ) && is_array( $this->end ) ) {
101 $totalCpu = max( $this->end[
'cpu'] - $this->start[
'cpu'], 0 );
102 $totalReal = max( $this->end[
'real'] - $this->start[
'real'], 0 );
103 $totalMem = max( $this->end[
'memory'] - $this->start[
'memory'], 0 );
111foreach ( $this->collated as $fname => $data ) {
114'calls' => $data[
'count'],
115'real' => $data[
'real'] * 1000,
116'%real' => $totalReal ? 100 * $data[
'real'] / $totalReal : 0,
117'cpu' => $data[
'cpu'] * 1000,
118'%cpu' => $totalCpu ? 100 * $data[
'cpu'] / $totalCpu : 0,
119'memory' => $data[
'memory'],
120'%memory' => $totalMem ? 100 * $data[
'memory'] / $totalMem : 0,
121'min_real' => 1000 * $data[
'min_real'],
122'max_real' => 1000 * $data[
'max_real']
129'real' => 1000 * $totalReal,
131'cpu' => 1000 * $totalCpu,
133'memory' => $totalMem,
135'min_real' => 1000 * $totalReal,
136'max_real' => 1000 * $totalReal
149 $this->workStack = [];
150 $this->collated = [];
151 $this->collateDone =
false;
185protectedfunctionupdateEntry( $name, $elapsedCpu, $elapsedReal, $memChange ) {
186 $entry =& $this->collated[$name];
187if ( !is_array( $entry ) ) {
189 $this->collated[$name] =& $entry;
191 $entry[
'cpu'] += $elapsedCpu;
192 $entry[
'real'] += $elapsedReal;
193 $entry[
'memory'] += $memChange > 0 ? $memChange : 0;
195 $entry[
'min_real'] = min( $entry[
'min_real'], $elapsedReal );
196 $entry[
'max_real'] = max( $entry[
'max_real'], $elapsedReal );
205// Once the data is collated for reports, any future calls 206// should clear the collation cache so the next report will 207// reflect them. This matters when trace mode is used. 208 $this->collateDone =
false;
211 $real = $this->
getTime(
'wall' );
212 $memory = memory_get_usage();
214if ( $this->start ===
null ) {
215 $this->start = [
'cpu' => $cpu,
'real' => $real,
'memory' => $memory ];
218 $this->workStack[] = [
220 count( $this->workStack ),
233 $item = array_pop( $this->workStack );
234if ( $item ===
null ) {
235 $this->logger->error(
"Profiling error: $functionname" );
238 [ $ofname,
/* $ocount */, $ortime, $octime, $omem ] = $item;
240if ( $functionname ===
'close' ) {
241 $message =
"Profile section ended by close(): {$ofname}";
242 $this->logger->error( $message );
243 $this->collated[$message] = $this->errorEntry;
244 $functionname = $ofname;
245 } elseif ( $ofname !== $functionname ) {
246 $message =
"Profiling error: in({$ofname}), out($functionname)";
247 $this->logger->error( $message );
248 $this->collated[$message] = $this->errorEntry;
251 $realTime = $this->
getTime(
'wall' );
252 $cpuTime = $this->
getTime(
'cpu' );
253 $memUsage = memory_get_usage();
255 $elapsedcpu = $cpuTime - $octime;
256 $elapsedreal = $realTime - $ortime;
257 $memchange = $memUsage - $omem;
258 $this->
updateEntry( $functionname, $elapsedcpu, $elapsedreal, $memchange );
271if ( $this->collateDone ) {
274 $this->collateDone =
true;
275// Close opened profiling sections 276while ( count( $this->workStack ) ) {
292if ( $metric ===
'cpu' || $metric ===
'user' ) {
293 $ru = getrusage( 0
/* RUSAGE_SELF */ );
294 $time = $ru[
'ru_utime.tv_sec'] + $ru[
'ru_utime.tv_usec'] / 1e6;
295if ( $metric ===
'cpu' ) {
296 # This is the time of system calls, added to the user time 297 # it gives the total CPU time 298 $time += $ru[
'ru_stime.tv_sec'] + $ru[
'ru_stime.tv_usec'] / 1e6;
302return microtime(
true );
Create PSR-3 logger objects.
Subclass ScopedCallback to avoid call_user_func_array(), which is slow.
Arbitrary section name based PHP profiling.
array[] $collated
Map of (function name => aggregate data array)
profileInInternal( $functionname)
This method should not be called outside SectionProfiler.
array $errorEntry
Cache of a standard broken collation entry.
scopedProfileOut(ScopedCallback &$section)
getTime( $metric='wall')
Get the initial time of the request, based on getrusage()
array null $start
Map of (mem,real,cpu)
__construct(array $params=[])
array $workStack
Queue of open profile calls with start data.
getFunctionStats()
Get the aggregated inclusive profiling data for each method.
array null $end
Map of (mem,real,cpu)
scopedProfileIn( $section)
profileOutInternal( $functionname)
This method should not be called outside SectionProfiler.
array[] $stack
List of resolved profile calls with start/end data.
reset()
Clear all of the profiling data for another run.
updateEntry( $name, $elapsedCpu, $elapsedReal, $memChange)
Update the collation entry for a given method name.
collateData()
Populate collated data.