* (bug 72951) The UserGetLanguageObject hook may be passed any IContextSource
for its $context parameter. Formerly it was documented as receiving a
RequestContext specifically.
+* Profiling was restructured and $wgProfiler now requires an 'output' parameter.
+ See StartProfiler.sample for details.
=== New features in 1.25 ===
* (bug 62861) Updated plural rules to CLDR 26. Includes incompatible changes
/**
* To use a profiler, copy this file to StartProfiler.php,
* and add either:
+ * $wgProfiler['class'] = 'ProfilerStandard';
+ * or
+ * $wgProfiler['class'] = 'ProfilerXhprof';
*
- * // Does not support the debugging toolbar
- * // Stores profiling information in the database
- * // Requires running maintenance/archives/patch-profiling.sql
- * $wgProfiler['class'] = 'ProfilerSimpleDB'
+ * For output, add:
+ * $wgProfiler['output'] = array( 'text' );
+ * 'text' can be one (or more) of 'text' 'udp' or 'db'
+ * 'db' requires creating the profiling table, see patch-profiling.sql
*
- * or:
+ * The 'text' output will be added to the output page in a comment approriate
+ * to the output's mime type. For a text/html page, this display can be
+ * changed to a preformatted text block by setting the 'visible' configuration
+ * flag:
+ * $wgProfiler['visible'] = true;
*
- * // Supports the debugging toolbar
- * // Does not store profiling information in the database
- * $wgProfiler['class'] = 'ProfilerStandard';
+ * The 'db' output expects a database table that can be created by applying
+ * maintenance/archives/patch-profiling.sql to your database.
*
- * Or for a sampling profiler:
+ * For a rudimentary sampling profiler:
* if ( !mt_rand( 0, 100 ) ) {
- * $wgProfiler['class'] = 'ProfilerSimpleDB';
- * } else {
- * $wgProfiler['class'] = 'ProfilerStub';
+ * $wgProfiler['class'] = 'ProfilerStandard';
+ * $wgProfiler['output'] = array( 'db' );
* }
- *
- * Configuration of the profiler output can be done in LocalSettings.php
*/
'ProcessCacheLRU' => __DIR__ . '/includes/libs/ProcessCacheLRU.php',
'ProfileSection' => __DIR__ . '/includes/profiler/ProfileSection.php',
'Profiler' => __DIR__ . '/includes/profiler/Profiler.php',
- 'ProfilerSimpleDB' => __DIR__ . '/includes/profiler/ProfilerSimpleDB.php',
- 'ProfilerSimpleText' => __DIR__ . '/includes/profiler/ProfilerSimpleText.php',
+ 'ProfilerOutput' => __DIR__ . '/includes/profiler/output/ProfilerOutput.php',
+ 'ProfilerOutputDb' => __DIR__ . '/includes/profiler/output/ProfilerOutputDb.php',
+ 'ProfilerOutputText' => __DIR__ . '/includes/profiler/output/ProfilerOutputText.php',
+ 'ProfilerOutputUdp' => __DIR__ . '/includes/profiler/output/ProfilerOutputUdp.php',
'ProfilerSimpleTrace' => __DIR__ . '/includes/profiler/ProfilerSimpleTrace.php',
- 'ProfilerSimpleUDP' => __DIR__ . '/includes/profiler/ProfilerSimpleUDP.php',
'ProfilerStandard' => __DIR__ . '/includes/profiler/ProfilerStandard.php',
'ProfilerStub' => __DIR__ . '/includes/profiler/ProfilerStub.php',
'ProfilerXhprof' => __DIR__ . '/includes/profiler/ProfilerXhprof.php',
'lessc_formatter_lessjs' => __DIR__ . '/includes/libs/lessc.inc.php',
'lessc_parser' => __DIR__ . '/includes/libs/lessc.inc.php',
'profile_point' => __DIR__ . '/profileinfo.php',
-);
+);
\ No newline at end of file
// Add on template profiling data
$dataByFunc = $this->mProfiler->getFunctionStats();
uasort( $dataByFunc, function( $a, $b ) {
- return $a['elapsed'] < $b['elapsed']; // descending order
+ return $a['real'] < $b['real']; // descending order
} );
$profileReport = "Top template expansion time report (%,ms,calls,template)\n";
foreach ( array_slice( $dataByFunc, 0, 10 ) as $item ) {
$profileReport .= sprintf( "%6.2f%% %3.6f %6d - %s\n",
- $item['percent'], $item['elapsed'], $item['calls'],
+ $item['%real'], $item['real'], $item['calls'],
htmlspecialchars($item['name'] ) );
}
$text .= "\n<!-- \n$profileReport-->\n";
protected $profileID = false;
/** @var bool Whether MediaWiki is in a SkinTemplate output context */
protected $templated = false;
+ /** @var array All of the params passed from $wgProfiler */
+ protected $params = array();
/** @var TransactionProfiler */
protected $trxProfiler;
if ( isset( $params['profileID'] ) ) {
$this->profileID = $params['profileID'];
}
+ $this->params = $params;
$this->trxProfiler = new TransactionProfiler();
}
/**
* Log the data to some store or even the page output
+ *
+ * @since 1.25
*/
- abstract public function logData();
+ public function logData() {
+ $output = isset( $this->params['output'] ) ?
+ $this->params['output'] : null;
+
+ if ( !$output || $this->isStub() ) {
+ // return early when no output classes defined or we're a stub
+ return;
+ }
+
+ if ( !is_array( $output ) ) {
+ $output = array( $output );
+ }
+
+ foreach ( $output as $outType ) {
+ $class = 'ProfilerOutput' . ucfirst( strtolower( $outType ) );
+ $profileOut = new $class( $this, $this->params );
+ if ( $profileOut->canUse() ) {
+ $profileOut->log();
+ }
+ }
+ }
+
+ /**
+ * Get the content type sent out to the client.
+ * Used for profilers that output instead of store data.
+ * @return string
+ * @since 1.25
+ */
+ public function getContentType() {
+ foreach ( headers_list() as $header ) {
+ if ( preg_match( '#^content-type: (\w+/\w+);?#i', $header, $m ) ) {
+ return $m[1];
+ }
+ }
+ return null;
+ }
/**
* Mark this call as templated or not
}
/**
- * Returns a profiling output to be stored in debug file
+ * Was this call as templated or not
*
- * @return string
+ * @return bool
*/
- abstract public function getOutput();
+ public function getTemplated() {
+ return $this->templated;
+ }
/**
- * Get data for the debugging toolbar.
+ * Get the aggregated inclusive profiling data for each method
*
- * @return array
- */
- abstract public function getRawData();
-
- /**
- * Get the initial time of the request, based either on $wgRequestTime or
- * $wgRUstart. Will return null if not able to find data.
+ * The percent time for each time is based on the current "total" time
+ * used is based on all methods so far. This method can therefore be
+ * called several times in between several profiling calls without the
+ * delays in usage of the profiler skewing the results. A "-total" entry
+ * is always included in the results.
*
- * @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
+ * When a call chain involves a method invoked within itself, any
+ * entries for the cyclic invocation should be be demarked with "@".
+ * This makes filtering them out easier and follows the xhprof style.
+ *
+ * @return array List of method entries arrays, each having:
+ * - name : method name
+ * - calls : the number of invoking calls
+ * - real : real time ellapsed (ms)
+ * - %real : percent real time
+ * - cpu : CPU time ellapsed (ms)
+ * - %cpu : percent CPU time
+ * - memory : memory used (bytes)
+ * - %memory : percent memory used
+ * @since 1.25
*/
- 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 );
- }
- }
+ abstract public function getFunctionStats();
/**
- * Get the initial time of the request, based either on $wgRequestTime or
- * $wgRUstart. Will return null if not able to find data.
+ * Returns a profiling output to be stored in debug file
*
- * @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
+ * @return string
*/
- 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;
- }
- }
- }
+ abstract public function getOutput();
}
+++ /dev/null
-<?php
-/**
- * Profiler storing information in the DB.
- *
- * This program is free software; you can redistribute it and/or modify
- * it under the terms of the GNU General Public License as published by
- * the Free Software Foundation; either version 2 of the License, or
- * (at your option) any later version.
- *
- * This program is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- * GNU General Public License for more details.
- *
- * You should have received a copy of the GNU General Public License along
- * with this program; if not, write to the Free Software Foundation, Inc.,
- * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
- * http://www.gnu.org/copyleft/gpl.html
- *
- * @file
- * @ingroup Profiler
- */
-
-/**
- * $wgProfiler['class'] = 'ProfilerSimpleDB';
- *
- * @ingroup Profiler
- */
-class ProfilerSimpleDB extends ProfilerStandard {
- /**
- * Log the whole profiling data into the database.
- */
- public function logData() {
- global $wgProfilePerHost;
-
- # Do not log anything if database is readonly (bug 5375)
- if ( wfReadOnly() ) {
- return;
- }
-
- if ( $wgProfilePerHost ) {
- $pfhost = wfHostname();
- } else {
- $pfhost = '';
- }
-
- try {
- $this->collateData();
-
- $dbw = wfGetDB( DB_MASTER );
- $useTrx = ( $dbw->getType() === 'sqlite' ); // much faster
- if ( $useTrx ) {
- $dbw->startAtomic( __METHOD__ );
- }
- foreach ( $this->collated as $name => $data ) {
- $eventCount = $data['count'];
- $timeSum = (float)( $data['real'] * 1000 );
- $memorySum = (float)$data['memory'];
- $name = substr( $name, 0, 255 );
-
- // Kludge
- $timeSum = $timeSum >= 0 ? $timeSum : 0;
- $memorySum = $memorySum >= 0 ? $memorySum : 0;
-
- $dbw->update( 'profiling',
- array(
- "pf_count=pf_count+{$eventCount}",
- "pf_time=pf_time+{$timeSum}",
- "pf_memory=pf_memory+{$memorySum}",
- ),
- array(
- 'pf_name' => $name,
- 'pf_server' => $pfhost,
- ),
- __METHOD__ );
-
- $rc = $dbw->affectedRows();
- if ( $rc == 0 ) {
- $dbw->insert( 'profiling',
- array(
- 'pf_name' => $name,
- 'pf_count' => $eventCount,
- 'pf_time' => $timeSum,
- 'pf_memory' => $memorySum,
- 'pf_server' => $pfhost
- ),
- __METHOD__,
- array( 'IGNORE' )
- );
- }
- // 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)";
- }
- if ( $useTrx ) {
- $dbw->endAtomic( __METHOD__ );
- }
- } catch ( DBError $e ) {
- }
- }
-}
+++ /dev/null
-<?php
-/**
- * Profiler showing output in page source.
- *
- * This program is free software; you can redistribute it and/or modify
- * it under the terms of the GNU General Public License as published by
- * the Free Software Foundation; either version 2 of the License, or
- * (at your option) any later version.
- *
- * This program is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- * GNU General Public License for more details.
- *
- * You should have received a copy of the GNU General Public License along
- * with this program; if not, write to the Free Software Foundation, Inc.,
- * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
- * http://www.gnu.org/copyleft/gpl.html
- *
- * @file
- * @ingroup Profiler
- */
-
-/**
- * The least sophisticated profiler output class possible, view your source! :)
- *
- * Put the following 2 lines in StartProfiler.php:
- *
- * $wgProfiler['class'] = 'ProfilerSimpleText';
- * $wgProfiler['visible'] = true;
- *
- * @ingroup Profiler
- */
-class ProfilerSimpleText extends ProfilerStandard {
- public $visible = false; /* Show as <PRE> or <!-- ? */
-
- public function __construct( $profileConfig ) {
- if ( isset( $profileConfig['visible'] ) && $profileConfig['visible'] ) {
- $this->visible = true;
- }
- parent::__construct( $profileConfig );
- }
-
- public function logData() {
- $out = '';
- if ( $this->templated ) {
- $this->close();
- $totalReal = isset( $this->collated['-total'] )
- ? $this->collated['-total']['real']
- : 0; // profiling mismatch error?
-
- uasort( $this->collated, function( $a, $b ) {
- // sort descending by time elapsed
- return $a['real'] < $b['real'];
- } );
-
- array_walk( $this->collated,
- function( $item, $key ) use ( &$out, $totalReal ) {
- $perc = $totalReal ? $item['real'] / $totalReal * 100 : 0;
- $out .= sprintf( "%6.2f%% %3.6f %6d - %s\n",
- $perc, $item['real'], $item['count'], $key );
- }
- );
-
- $contentType = $this->getContentType();
- if ( PHP_SAPI === 'cli' ) {
- print "<!--\n{$out}\n-->\n";
- } elseif ( $contentType === 'text/html' ) {
- if ( $this->visible ) {
- print "<pre>{$out}</pre>";
- } else {
- print "<!--\n{$out}\n-->\n";
- }
- } elseif ( $contentType === 'text/javascript' ) {
- print "\n/*\n${$out}*/\n";
- } elseif ( $contentType === 'text/css' ) {
- print "\n/*\n{$out}*/\n";
- }
- }
- }
-}
+++ /dev/null
-<?php
-/**
- * Profiler sending messages over UDP.
- *
- * This program is free software; you can redistribute it and/or modify
- * it under the terms of the GNU General Public License as published by
- * the Free Software Foundation; either version 2 of the License, or
- * (at your option) any later version.
- *
- * This program is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- * GNU General Public License for more details.
- *
- * You should have received a copy of the GNU General Public License along
- * with this program; if not, write to the Free Software Foundation, Inc.,
- * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
- * http://www.gnu.org/copyleft/gpl.html
- *
- * @file
- * @ingroup Profiler
- */
-
-/**
- * ProfilerSimpleUDP class, that sends out messages for 'udpprofile' daemon
- * (the one from
- * http://git.wikimedia.org/tree/operations%2Fsoftware.git/master/udpprofile)
- * @ingroup Profiler
- */
-class ProfilerSimpleUDP extends ProfilerStandard {
- public function logData() {
- global $wgUDPProfilerHost, $wgUDPProfilerPort, $wgUDPProfilerFormatString;
-
- $this->close();
-
- if ( !function_exists( 'socket_create' ) ) {
- # Sockets are not enabled
- return;
- }
-
- $sock = socket_create( AF_INET, SOCK_DGRAM, SOL_UDP );
- $plength = 0;
- $packet = "";
- foreach ( $this->collated as $entry => $pfdata ) {
- if ( !isset( $pfdata['count'] )
- || !isset( $pfdata['cpu'] )
- || !isset( $pfdata['cpu_sq'] )
- || !isset( $pfdata['real'] )
- || !isset( $pfdata['real_sq'] ) ) {
- continue;
- }
- $pfline = sprintf( $wgUDPProfilerFormatString, $this->getProfileID(), $pfdata['count'],
- $pfdata['cpu'], $pfdata['cpu_sq'], $pfdata['real'], $pfdata['real_sq'], $entry,
- $pfdata['memory'] );
- $length = strlen( $pfline );
- /* printf("<!-- $pfline -->"); */
- if ( $length + $plength > 1400 ) {
- socket_sendto( $sock, $packet, $plength, 0, $wgUDPProfilerHost, $wgUDPProfilerPort );
- $packet = "";
- $plength = 0;
- }
- $packet .= $pfline;
- $plength += $length;
- }
- socket_sendto( $sock, $packet, $plength, 0x100, $wgUDPProfilerHost, $wgUDPProfilerPort );
- }
-}
}
}
- /**
- * 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
*
trim( sprintf( "%7.3f", $delta * 1000.0 ) ), $space, $fname );
}
+ /**
+ * Return the collated data, collating first if need be
+ * @return array
+ */
+ public function getCollatedData() {
+ if ( !$this->collateDone ) {
+ $this->collateData();
+ }
+ return $this->collated;
+ }
+
/**
* Populate collated
*/
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.
$this->collateDone = false;
}
- $total = isset( $this->collated['-total'] )
+ $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->collated as $fname => $data ) {
- $periods = array();
- foreach ( $data['periods'] as $period ) {
- $period['start'] *= 1000;
- $period['end'] *= 1000;
- $periods[] = $period;
- }
$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;
}
}
- return null;
}
/**
public function profileOut( $fn ) {
}
- public function getOutput() {
+ public function getFunctionStats() {
}
- public function close() {
+ public function getOutput() {
}
- public function logData() {
+ public function close() {
}
public function getCurrentSection() {
return '';
}
-
- public function getRawData() {
- return array();
- }
}
/**
* Profiler wrapper for XHProf extension.
*
- * Mimics the output of ProfilerSimpleText, ProfilerSimpleUDP or
- * ProfilerSimpleTrace but using data collected via the XHProf PHP extension.
- * This Profiler also produces data compatable with the debugging toolbar.
+ * Mimics the output of ProfilerStandard using data collected via the XHProf
+ * PHP extension.
*
- * To mimic ProfilerSimpleText results:
* @code
* $wgProfiler['class'] = 'ProfilerXhprof';
* $wgProfiler['flags'] = XHPROF_FLAGS_NO_BUILTINS;
- * $wgProfiler['log'] = 'text';
+ * $wgProfiler['output'] = 'text';
* $wgProfiler['visible'] = true;
* @endcode
*
- * To mimic ProfilerSimpleUDP results:
* @code
* $wgProfiler['class'] = 'ProfilerXhprof';
* $wgProfiler['flags'] = XHPROF_FLAGS_CPU | XHPROF_FLAGS_MEMORY | XHPROF_FLAGS_NO_BUILTINS;
- * $wgProfiler['log'] = 'udpprofile';
- * @endcode
- *
- * Similar to ProfilerSimpleTrace results, report the most expensive path
- * through the application:
- * @code
- * $wgProfiler['class'] = 'ProfilerXhprof';
- * $wgProfiler['flags'] = XHPROF_FLAGS_NO_BUILTINS;
- * $wgProfiler['log'] = 'critpath';
- * $wgProfiler['visible'] = true;
+ * $wgProfiler['output'] = 'udp';
* @endcode
*
* Rather than obeying wfProfileIn() and wfProfileOut() calls placed in the
* To restrict the functions for which profiling data is collected, you can
* use either a whitelist ($wgProfiler['include']) or a blacklist
* ($wgProfiler['exclude']) containing an array of function names. The
- * blacklist funcitonality is built into HHVM and will completely exclude the
+ * blacklist functionality is built into HHVM and will completely exclude the
* named functions from profiling collection. The whitelist is implemented by
- * Xhprof class and will filter the data collected by XHProf before reporting.
+ * Xhprof class which will filter the data collected by XHProf before reporting.
* See documentation for the Xhprof class and the XHProf extension for
* additional information.
*
- * Data reported to debug toolbar via getRawData() can be restricted by
- * setting $wgProfiler['toolbarCutoff'] to a minumum cumulative wall clock
- * percentage. Functions in the call graph which contribute less than this
- * percentage to the total wall clock time measured will be excluded from the
- * data sent to debug toolbar. The default cutoff is 0.1 (1/1000th of the
- * total time measured).
- *
* @author Bryan Davis <bd808@wikimedia.org>
* @copyright © 2014 Bryan Davis and Wikimedia Foundation.
* @ingroup Profiler
*/
protected $visible;
- /**
- * Minimum wall time precentage for a fucntion to be reported to the debug
- * toolbar via getRawData().
- * @var float $toolbarCutoff
- */
- protected $toolbarCutoff;
-
/**
* @param array $params
* @see Xhprof::__construct()
$params = array_merge(
array(
'log' => 'text',
- 'visible' => false,
- 'toolbarCutoff' => 0.1,
+ 'visible' => false
),
$params
);
public function close() {
}
- /**
- * Get data for the debugging toolbar.
- *
- * @return array
- * @see https://www.mediawiki.org/wiki/Debugging_toolbar
- */
- public function getRawData() {
+ public function getFunctionStats() {
$metrics = $this->xhprof->getCompleteMetrics();
- $endEpoch = $this->getTime();
$profile = array();
foreach ( $metrics as $fname => $stats ) {
- if ( $stats['wt']['percent'] < $this->toolbarCutoff ) {
- // Ignore functions which are not significant contributors
- // to the total elapsed time.
- continue;
- }
-
- $record = array(
+ // Convert elapsed times from μs to ms to match ProfilerStandard
+ $profile[] = array(
'name' => $fname,
'calls' => $stats['ct'],
- 'elapsed' => $stats['wt']['total'] / 1000,
- 'percent' => $stats['wt']['percent'],
+ 'real' => $stats['wt']['total'] / 1000,
+ '%real' => $stats['wt']['percent'],
+ 'cpu' => isset( $stats['cpu'] ) ? $stats['cpu']['total'] / 1000 : 0,
+ '%cpu' => isset( $stats['cpu'] ) ? $stats['cpu']['percent'] : 0,
'memory' => isset( $stats['mu'] ) ? $stats['mu']['total'] : 0,
+ '%memory' => isset( $stats['mu'] ) ? $stats['mu']['percent'] : 0,
'min' => $stats['wt']['min'] / 1000,
- 'max' => $stats['wt']['max'] / 1000,
- 'overhead' => array_reduce(
- $stats['subcalls'],
- function( $carry, $item ) {
- return $carry + $item['ct'];
- },
- 0
- ),
- 'periods' => array(),
- );
-
- // We are making up periods based on the call segments we have.
- // What we don't have is the start time for each call (which
- // actually may be a collection of multiple calls from the
- // caller). We will pretend that all the calls happen sequentially
- // and finish at the end of the end of the request.
- foreach ( $stats['calls'] as $call ) {
- $avgElapsed = $call['wt'] / 1000 / $call['ct'];
- $avgMem = isset( $call['mu'] ) ? $call['mu'] / $call['ct'] : 0;
- $start = $endEpoch - $avgElapsed;
- for ( $i = 0; $i < $call['ct']; $i++ ) {
- $callStart = $start + ( $avgElapsed * $i );
- $record['periods'][] = array(
- 'start' => $callStart,
- 'end' => $callStart + $avgElapsed,
- 'memory' => $avgMem,
- 'subcalls' => 0,
- );
- }
- }
-
- $profile[] = $record;
- }
- return $profile;
- }
-
- /**
- * Log the data to some store or even the page output.
- */
- public function logData() {
- if ( $this->logType === 'text' ) {
- $this->logText();
- } elseif ( $this->logType === 'udpprofile' ) {
- $this->logToUdpprofile();
- } elseif ( $this->logType === 'critpath' ){
- $this->logCriticalPath();
- } else {
- wfLogWarning(
- "Unknown ProfilerXhprof log type '{$this->logType}'"
- );
- }
- }
-
- /**
- * Write a brief profile report to stdout.
- */
- protected function logText() {
- if ( $this->templated ) {
- $ct = $this->getContentType();
- if ( $ct === 'text/html' && $this->visible ) {
- $prefix = '<pre>';
- $suffix = '</pre>';
- } elseif ( $ct === 'text/javascript' || $ct === 'text/css' ) {
- $prefix = "\n/*";
- $suffix = "*/\n";
- } else {
- $prefix = "<!--";
- $suffix = "-->\n";
- }
-
- print $this->getSummaryReport( $prefix, $suffix );
- }
- }
-
- /**
- * Send collected information to a udpprofile daemon.
- *
- * @see http://git.wikimedia.org/tree/operations%2Fsoftware.git/master/udpprofile
- * @see $wgUDPProfilerHost
- * @see $wgUDPProfilerPort
- * @see $wgUDPProfilerFormatString
- */
- protected function logToUdpprofile() {
- global $wgUDPProfilerHost, $wgUDPProfilerPort;
- global $wgUDPProfilerFormatString;
-
- if ( !function_exists( 'socket_create' ) ) {
- return;
- }
-
- $metrics = $this->xhprof->getInclusiveMetrics();
-
- $sock = socket_create( AF_INET, SOCK_DGRAM, SOL_UDP );
- $buffer = '';
- $bufferSize = 0;
- foreach ( $metrics as $func => $data ) {
- if ( strpos( $func, '@' ) !== false ) {
- continue; // ignore cyclic re-entries to functions
- }
- $line = sprintf( $wgUDPProfilerFormatString,
- $this->getProfileID(),
- $data['ct'],
- isset( $data['cpu'] ) ? $data['cpu']['total'] : 0,
- isset( $data['cpu'] ) ? $data['cpu']['variance'] : 0,
- $data['wt']['total'] / 1000,
- $data['wt']['variance'],
- $func,
- isset( $data['mu'] ) ? $data['mu']['total'] : 0
+ 'max' => $stats['wt']['max'] / 1000
);
- $lineLength = strlen( $line );
- if ( $lineLength + $bufferSize > 1400 ) {
- // Line would exceed max packet size, send packet before
- // appending to buffer.
- socket_sendto( $sock, $buffer, $bufferSize, 0,
- $wgUDPProfilerHost, $wgUDPProfilerPort
- );
- $buffer = '';
- $bufferSize = 0;
- }
- $buffer .= $line;
- $bufferSize += $lineLength;
}
- // Send final buffer
- socket_sendto( $sock, $buffer, $bufferSize, 0x100 /* EOF */,
- $wgUDPProfilerHost, $wgUDPProfilerPort
- );
- }
- /**
- * Write a critical path report to stdout.
- */
- protected function logCriticalPath() {
- if ( $this->templated ) {
- $ct = $this->getContentType();
- if ( $ct === 'text/html' && $this->visible ) {
- $prefix = '<pre>Critical path:';
- $suffix = '</pre>';
- } elseif ( $ct === 'text/javascript' || $ct === 'text/css' ) {
- $prefix = "\n/* Critical path:";
- $suffix = "*/\n";
- } else {
- $prefix = "<!-- Critical path:";
- $suffix = "-->\n";
- }
-
- print $this->getCriticalPathReport( $prefix, $suffix );
- }
- }
-
- /**
- * Get the content type of the current request.
- * @return string
- */
- protected function getContentType() {
- foreach ( headers_list() as $header ) {
- if ( preg_match( '#^content-type: (\w+/\w+);?#i', $header, $m ) ) {
- return $m[1];
- }
- }
- return 'application/octet-stream';
+ return $profile;
}
/**
$out[] = $footer;
return implode( "\n", $out );
}
-
- /**
- * Get a brief report of the most costly code path by wall clock time.
- *
- * Each line of the report includes this data:
- * - Total wall clock time spent in function in seconds
- * - Function name
- *
- * @param string $header Header text to prepend to report
- * @param string $footer Footer text to append to report
- * @return string
- */
- protected function getCriticalPathReport( $header = '', $footer = '' ) {
- $data = $this->xhprof->getCriticalPath();
-
- $out = array( $header );
- $out[] = sprintf( "%7s %9s %9s %6s %4s",
- 'Time%', 'Time', 'Mem', 'Calls', 'Name'
- );
-
- $format = '%6.2f%% %9.6f %9d %6d %s%s';
- $total = null;
- $nest = 0;
- foreach ( $data as $key => $stats ) {
- list( $parent, $child ) = Xhprof::splitKey( $key );
- if ( $total === null ) {
- $total = $stats;
- }
- $out[] = sprintf( $format,
- 100 * $stats['wt'] / $total['wt'],
- $stats['wt'] / 1e6,
- isset( $stats['mu'] ) ? $stats['mu'] : 0,
- $stats['ct'],
- //$nest ? str_repeat( ' ', $nest - 1 ) . 'â”— ' : '',
- $nest ? str_repeat( ' ', $nest - 1 ) . '└─' : '',
- $child
- );
- $nest++;
- }
- $out[] = $footer;
- return implode( "\n", $out );
- }
}
}
/**
- * Get the raw and collated breakdown data for each method
+ * Get the aggregated inclusive profiling data for each method
*
* The percent time for each time is based on the current "total" time
* used is based on all methods so far. This method can therefore be
* is always included in the results.
*
* @return array List of method entries arrays, each having:
- * - name : method name
- * - calls : the number of method calls
- * - elapsed : real time ellapsed (ms)
- * - percent : percent real time
- * - memory : memory used (bytes)
- * - min : min real time of all calls (ms)
- * - max : max real time of all calls (ms)
+ * - name : method name
+ * - calls : the number of invoking calls
+ * - real : real time ellapsed (ms)
+ * - %real : percent real time
+ * - cpu : real time ellapsed (ms)
+ * - %cpu : percent real time
+ * - memory : memory used (bytes)
+ * - %memory : percent memory used
*/
public function getFunctionStats() {
- $data = $this->profiler->getRawData();
+ $data = $this->profiler->getFunctionStats();
+ $cpuTotal = 0;
$memoryTotal = 0;
$elapsedTotal = 0;
foreach ( $data as $item ) {
$memoryTotal += $item['memory'];
- $elapsedTotal += $item['elapsed'];
+ $elapsedTotal += $item['real'];
+ $cpuTotal += $item['cpu'];
}
foreach ( $data as &$item ) {
- $item['percent'] = $item['elapsed'] / $elapsedTotal * 100;
+ $item['%cpu'] = $item['cpu'] ? $item['cpu'] / $cpuTotal * 100 : 0;
+ $item['%real'] = $elapsedTotal ? $item['real'] / $elapsedTotal * 100 : 0;
+ $item['%memory'] = $item['memory'] ? $item['memory'] / $memoryTotal * 100 : 0;
}
unset( $item );
$data[] = array(
'name' => '-total',
'calls' => 1,
- 'elapsed' => $elapsedTotal,
- 'percent' => 100,
+ 'real' => $elapsedTotal,
+ '%real' => 100,
'memory' => $memoryTotal,
- 'min' => $elapsedTotal,
- 'max' => $elapsedTotal
+ '%memory' => 100,
);
return $data;
--- /dev/null
+<?php
+/**
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ * @ingroup Profiler
+ */
+
+/**
+ * Base class for profiling output
+ *
+ * Since 1.25
+ */
+abstract class ProfilerOutput {
+ /** @var Profiler */
+ protected $collector;
+ /** @var array Configuration of $wgProfiler */
+ protected $params = array();
+
+ /**
+ * Constructor
+ * @param Profiler $collector The actual profiler
+ * @param array $params Configuration array, passed down from $wgProfiler
+ */
+ public function __construct( Profiler $collector, array $params ) {
+ $this->collector = $collector;
+ $this->params = $params;
+ }
+
+ /**
+ * Can this output type be used?
+ * @return bool
+ */
+ public function canUse() {
+ return true;
+ }
+
+ /**
+ * Delegate to the proper method
+ */
+ public function log() {
+ $this->logStandardData( $this->collector->getFunctionStats() );
+ }
+
+ /**
+ * Log MediaWiki-style profiling data
+ *
+ * @param array $stats Result of Profiler::getFunctionStats()
+ */
+ abstract protected function logStandardData( array $stats );
+}
--- /dev/null
+<?php
+/**
+ * Profiler storing information in the DB.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ * @ingroup Profiler
+ */
+
+/**
+ * Logs profiling data into the local DB
+ *
+ * $wgProfiler['class'] = 'ProfilerSimpleDB';
+ *
+ * @ingroup Profiler
+ * @since 1.25
+ */
+class ProfilerOutputDb extends ProfilerOutput {
+ public function canUse() {
+ # Do not log anything if database is readonly (bug 5375)
+ return !wfReadOnly();
+ }
+
+ protected function logStandardData( array $stats ) {
+ global $wgProfilePerHost;
+
+ if ( $wgProfilePerHost ) {
+ $pfhost = wfHostname();
+ } else {
+ $pfhost = '';
+ }
+
+ try {
+ $dbw = wfGetDB( DB_MASTER );
+ $useTrx = ( $dbw->getType() === 'sqlite' ); // much faster
+ if ( $useTrx ) {
+ $dbw->startAtomic( __METHOD__ );
+ }
+ foreach ( $stats as $data ) {
+ $name = $data['name'];
+ $eventCount = $data['calls'];
+ $timeSum = (float)$data['real'];
+ $memorySum = (float)$data['memory'];
+ $name = substr( $name, 0, 255 );
+
+ // Kludge
+ $timeSum = $timeSum >= 0 ? $timeSum : 0;
+ $memorySum = $memorySum >= 0 ? $memorySum : 0;
+
+ $dbw->update( 'profiling',
+ array(
+ "pf_count=pf_count+{$eventCount}",
+ "pf_time=pf_time+{$timeSum}",
+ "pf_memory=pf_memory+{$memorySum}",
+ ),
+ array(
+ 'pf_name' => $name,
+ 'pf_server' => $pfhost,
+ ),
+ __METHOD__ );
+
+ $rc = $dbw->affectedRows();
+ if ( $rc == 0 ) {
+ $dbw->insert( 'profiling',
+ array(
+ 'pf_name' => $name,
+ 'pf_count' => $eventCount,
+ 'pf_time' => $timeSum,
+ 'pf_memory' => $memorySum,
+ 'pf_server' => $pfhost
+ ),
+ __METHOD__,
+ array( 'IGNORE' )
+ );
+ }
+ // 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)";
+ }
+ if ( $useTrx ) {
+ $dbw->endAtomic( __METHOD__ );
+ }
+ } catch ( DBError $e ) {
+ }
+ }
+}
--- /dev/null
+<?php
+/**
+ * Profiler showing output in page source.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ * @ingroup Profiler
+ */
+
+/**
+ * The least sophisticated profiler output class possible, view your source! :)
+ *
+ * Put the following 2 lines in StartProfiler.php:
+ *
+ * $wgProfiler['class'] = 'ProfilerSimpleText';
+ * $wgProfiler['visible'] = true;
+ *
+ * @ingroup Profiler
+ * @since 1.25
+ */
+class ProfilerOutputText extends ProfilerOutput {
+ /** @var float Min real time display threshold */
+ protected $thresholdMs;
+
+ function __construct( Profiler $collector, array $params ) {
+ parent::__construct( $collector, $params );
+ $this->thresholdMs = isset( $params['thresholdMs'] )
+ ? $params['thresholdMs']
+ : .25;
+ }
+ protected function logStandardData( array $stats ) {
+ if ( $this->collector->getTemplated() ) {
+ $out = '';
+
+ // Filter out really tiny entries
+ $min = $this->thresholdMs;
+ $stats = array_filter( $stats, function( $a ) use ( $min ) {
+ return $a['real'] > $min;
+ } );
+ // Sort descending by time elapsed
+ usort( $stats, function( $a, $b ) {
+ return $a['real'] < $b['real'];
+ } );
+
+ array_walk( $stats,
+ function ( $item ) use ( &$out ) {
+ $out .= sprintf( "%6.2f%% %3.3f %6d - %s\n",
+ $item['%real'], $item['real'], $item['calls'], $item['name'] );
+ }
+ );
+
+ $contentType = $this->collector->getContentType();
+ if ( PHP_SAPI === 'cli' ) {
+ print "<!--\n{$out}\n-->\n";
+ } elseif ( $contentType === 'text/html' ) {
+ $visible = isset( $this->params['visible'] ) ?
+ $this->params['visible'] : false;
+ if ( $visible ) {
+ print "<pre>{$out}</pre>";
+ } else {
+ print "<!--\n{$out}\n-->\n";
+ }
+ } elseif ( $contentType === 'text/javascript' ) {
+ print "\n/*\n${$out}*/\n";
+ } elseif ( $contentType === 'text/css' ) {
+ print "\n/*\n{$out}*/\n";
+ }
+ }
+ }
+}
--- /dev/null
+<?php
+/**
+ * Profiler sending messages over UDP.
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation; either version 2 of the License, or
+ * (at your option) any later version.
+ *
+ * This program is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License along
+ * with this program; if not, write to the Free Software Foundation, Inc.,
+ * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
+ * http://www.gnu.org/copyleft/gpl.html
+ *
+ * @file
+ * @ingroup Profiler
+ */
+
+/**
+ * ProfilerSimpleUDP class, that sends out messages for 'udpprofile' daemon
+ * (see http://git.wikimedia.org/tree/operations%2Fsoftware.git/master/udpprofile)
+ *
+ * @ingroup Profiler
+ * @since 1.25
+ */
+class ProfilerOutputUdp extends ProfilerOutput {
+ public function canUse() {
+ # Sockets are not enabled
+ return function_exists( 'socket_create' );
+ }
+
+ protected function logStandardData( array $stats ) {
+ global $wgUDPProfilerHost, $wgUDPProfilerPort, $wgUDPProfilerFormatString;
+
+ $sock = socket_create( AF_INET, SOCK_DGRAM, SOL_UDP );
+ $plength = 0;
+ $packet = "";
+ foreach ( $stats as $pfdata ) {
+ $pfline = sprintf( $wgUDPProfilerFormatString,
+ $this->collector->getProfileID(),
+ $pfdata['calls'],
+ $pfdata['cpu'] / 1000, // ms => sec
+ 0.0, // sum of CPU^2 for each invocation (unused)
+ $pfdata['real'] / 1000, // ms => sec
+ 0.0, // sum of real^2 for each invocation (unused)
+ $pfdata['name'],
+ $pfdata['memory']
+ );
+ $length = strlen( $pfline );
+ if ( $length + $plength > 1400 ) {
+ socket_sendto( $sock, $packet, $plength, 0, $wgUDPProfilerHost, $wgUDPProfilerPort );
+ $packet = "";
+ $plength = 0;
+ }
+ $packet .= $pfline;
+ $plength += $length;
+ }
+ socket_sendto( $sock, $packet, $plength, 0x100, $wgUDPProfilerHost, $wgUDPProfilerPort );
+ }
+}
$this->addOption( 'server', "The protocol and server name to use in URLs, e.g. " .
"http://en.wikipedia.org. This is sometimes necessary because " .
"server name detection may fail in command line scripts.", false, true );
- $this->addOption( 'profiler', 'Set to "text" or "trace" to show profiling output', false, true );
# Save generic options to display them separately in help
$this->mGenericParameters = $this->mParams;
// @codingStandardsIgnoreStart
$this->adjustMemoryLimit();
-
- // Per-script profiling; useful for debugging
- $forcedProfiler = $this->getOption( 'profiler' );
- if ( $forcedProfiler === 'text' ) {
- Profiler::setInstance( new ProfilerSimpleText( array() ) );
- Profiler::instance()->setTemplated( true );
- } elseif ( $forcedProfiler === 'trace' ) {
- Profiler::setInstance( new ProfilerSimpleTrace( array() ) );
- Profiler::instance()->setTemplated( true );
- }
}
/**
$last = false;
foreach ( $res as $o ) {
$next = new profile_point( $o->pf_name, $o->pf_count, $o->pf_time, $o->pf_memory );
- if ( $next->name() == '-total' ) {
+ if ( $next->name() == '-total' || $next->name() == 'main()' ) {
profile_point::$totaltime = $next->time();
profile_point::$totalcount = $next->count();
profile_point::$totalmemory = $next->memory();
dépôts / lhc / web / wiklou.git / commitdiff