jenkins-bot has submitted this change and it was merged.
Change subject: Backport ProfilerOutputStats
......................................................................
Backport ProfilerOutputStats
Cherry-picks the following changes from master:
* I7e07e22ea: Make WebRequest objects time-aware
* Icf644ad34: Introduce ProfilerOutputStats
* Ib3585303b: Follow-up to Icf644ad34: Introduce ProfilerOutputStats
Change-Id: I6cc22664b60b34d699d7e8ea71d55eaa22ae61fb
---
M autoload.php
M includes/DefaultSettings.php
M includes/GlobalFunctions.php
M includes/WebRequest.php
M includes/WebStart.php
M includes/profiler/Profiler.php
M includes/profiler/ProfilerStub.php
A includes/profiler/output/ProfilerOutputStats.php
8 files changed, 198 insertions(+), 53 deletions(-)
Approvals:
Catrope: Looks good to me, approved
jenkins-bot: Verified
diff --git a/autoload.php b/autoload.php
index 892a1f7..aae272b 100644
--- a/autoload.php
+++ b/autoload.php
@@ -911,6 +911,7 @@
'ProfilerOutput' => __DIR__ .
'/includes/profiler/output/ProfilerOutput.php',
'ProfilerOutputDb' => __DIR__ .
'/includes/profiler/output/ProfilerOutputDb.php',
'ProfilerOutputDump' => __DIR__ .
'/includes/profiler/output/ProfilerOutputDump.php',
+ 'ProfilerOutputStats' => __DIR__ .
'/includes/profiler/output/ProfilerOutputStats.php',
'ProfilerOutputText' => __DIR__ .
'/includes/profiler/output/ProfilerOutputText.php',
'ProfilerOutputUdp' => __DIR__ .
'/includes/profiler/output/ProfilerOutputUdp.php',
'ProfilerSectionOnly' => __DIR__ .
'/includes/profiler/ProfilerSectionOnly.php',
diff --git a/includes/DefaultSettings.php b/includes/DefaultSettings.php
index ae8de0e..79c83f9 100644
--- a/includes/DefaultSettings.php
+++ b/includes/DefaultSettings.php
@@ -5413,6 +5413,7 @@
/**
* Only record profiling info for pages that took longer than this
+ * @deprecated since 1.25: set $wgProfiler['threshold'] instead.
*/
$wgProfileLimit = 0.0;
diff --git a/includes/GlobalFunctions.php b/includes/GlobalFunctions.php
index 47e7a15..0995f8c 100644
--- a/includes/GlobalFunctions.php
+++ b/includes/GlobalFunctions.php
@@ -1245,10 +1245,15 @@
* @todo document
*/
function wfLogProfilingData() {
- global $wgRequestTime, $wgDebugLogGroups, $wgDebugRawPage;
- global $wgProfileLimit, $wgUser, $wgRequest;
+ global $wgDebugLogGroups, $wgDebugRawPage;
$context = RequestContext::getMain();
+ $request = $context->getRequest();
+
+ $profiler = Profiler::instance();
+ $profiler->setContext( $context );
+ $profiler->logData();
+
$config = $context->getConfig();
if ( $config->has( 'StatsdServer' ) ) {
$statsdServer = explode( ':', $config->get( 'StatsdServer' ) );
@@ -1259,21 +1264,10 @@
$statsdClient->send( $context->getStats()->getBuffer() );
}
- $profiler = Profiler::instance();
-
# Profiling must actually be enabled...
if ( $profiler instanceof ProfilerStub ) {
return;
}
-
- // Get total page request time and only show pages that longer than
- // $wgProfileLimit time (default is 0)
- $elapsed = microtime( true ) - $wgRequestTime;
- if ( $elapsed <= $wgProfileLimit ) {
- return;
- }
-
- $profiler->logData();
if ( isset( $wgDebugLogGroups['profileoutput'] )
&& $wgDebugLogGroups['profileoutput'] === false
@@ -1285,7 +1279,7 @@
return;
}
- $ctx = array( 'elapsed' => $elapsed );
+ $ctx = array( 'elapsed' => $request->getElapsedTime() );
if ( !empty( $_SERVER['HTTP_X_FORWARDED_FOR'] ) ) {
$ctx['forwarded_for'] = $_SERVER['HTTP_X_FORWARDED_FOR'];
}
@@ -1304,16 +1298,13 @@
// Don't load $wgUser at this late stage just for statistics purposes
// @todo FIXME: We can detect some anons even if it is not loaded.
// See User::getId()
- if ( $wgUser->isItemLoaded( 'id' ) && $wgUser->isAnon() ) {
- $ctx['anon'] = true;
- } else {
- $ctx['anon'] = false;
- }
+ $user = $context->getUser();
+ $ctx['anon'] = $user->isItemLoaded( 'id' ) && $user->isAnon();
// Command line script uses a FauxRequest object which does not have
// any knowledge about an URL and throw an exception instead.
try {
- $ctx['url'] = urldecode( $wgRequest->getRequestURL() );
+ $ctx['url'] = urldecode( $request->getRequestURL() );
} catch ( Exception $ignored ) {
// no-op
}
diff --git a/includes/WebRequest.php b/includes/WebRequest.php
index f86a454..93cc04e 100644
--- a/includes/WebRequest.php
+++ b/includes/WebRequest.php
@@ -51,15 +51,20 @@
private $ip;
/**
+ * The timestamp of the start of the request, with microsecond
precision.
+ * @var float
+ */
+ protected $requestTime;
+
+ /**
* Cached URL protocol
* @var string
*/
protected $protocol;
public function __construct() {
- if ( function_exists( 'get_magic_quotes_gpc' ) &&
get_magic_quotes_gpc() ) {
- throw new MWException( "MediaWiki does not function
when magic quotes are enabled." );
- }
+ $this->requestTime = isset( $_SERVER['REQUEST_TIME_FLOAT'] )
+ ? $_SERVER['REQUEST_TIME_FLOAT'] : microtime( true );
// POST overrides GET data
// We don't use $_REQUEST here to avoid interference from
cookies...
@@ -214,6 +219,17 @@
} else {
return 'http';
}
+ }
+
+ /**
+ * Get the number of seconds to have elapsed since request start,
+ * in fractional seconds, with microsecond resolution.
+ *
+ * @return float
+ * @since 1.25
+ */
+ public function getElapsedTime() {
+ return microtime( true ) - $this->requestTime;
}
/**
@@ -1274,6 +1290,8 @@
public function __construct( $data = array(), $wasPosted = false,
$session = null, $protocol = 'http'
) {
+ $this->requestTime = microtime( true );
+
if ( is_array( $data ) ) {
$this->data = $data;
} else {
@@ -1497,4 +1515,8 @@
public function getProtocol() {
return $this->base->getProtocol();
}
+
+ public function getElapsedTime() {
+ return $this->base->getElapsedTime();
+ }
}
diff --git a/includes/WebStart.php b/includes/WebStart.php
index da4bc87..9c71f3e 100644
--- a/includes/WebStart.php
+++ b/includes/WebStart.php
@@ -34,12 +34,30 @@
. 'for help on how to disable it.' );
}
+if ( function_exists( 'get_magic_quotes_gpc' ) && get_magic_quotes_gpc() ) {
+ die( 'MediaWiki does not function when magic quotes are enabled. '
+ . 'Please see the <a
href="https://php.net/manual/security.magicquotes.disabling.php";>PHP Manual</a>
'
+ . 'for help on how to disable magic quotes.' );
+}
+
+
# bug 15461: Make IE8 turn off content sniffing. Everybody else should ignore
this
# We're adding it here so that it's *always* set, even for alternate entry
# points and when $wgOut gets disabled or overridden.
header( 'X-Content-Type-Options: nosniff' );
-$wgRequestTime = microtime( true );
+# Approximate $_SERVER['REQUEST_TIME_FLOAT'] for PHP<5.4
+if ( !isset( $_SERVER['REQUEST_TIME_FLOAT'] ) ) {
+ $_SERVER['REQUEST_TIME_FLOAT'] = microtime( true );
+}
+
+/**
+ * @var float Request start time as fractional seconds since epoch
+ * @deprecated since 1.25; use $_SERVER['REQUEST_TIME_FLOAT'] or
+ * WebRequest::getElapsedTime() instead.
+ */
+$wgRequestTime = $_SERVER['REQUEST_TIME_FLOAT'];
+
unset( $IP );
# Valid web server entry point, enable includes.
diff --git a/includes/profiler/Profiler.php b/includes/profiler/Profiler.php
index 69470fd..210041a 100644
--- a/includes/profiler/Profiler.php
+++ b/includes/profiler/Profiler.php
@@ -35,6 +35,8 @@
protected $templated = false;
/** @var array All of the params passed from $wgProfiler */
protected $params = array();
+ /** @var IContextSource Current request context */
+ protected $context = null;
/** @var TransactionProfiler */
protected $trxProfiler;
@@ -47,6 +49,7 @@
'text' => 'ProfilerOutputText',
'udp' => 'ProfilerOutputUdp',
'dump' => 'ProfilerOutputDump',
+ 'stats' => 'ProfilerOutputStats',
);
/** @var Profiler */
@@ -69,17 +72,28 @@
*/
final public static function instance() {
if ( self::$instance === null ) {
- global $wgProfiler;
+ global $wgProfiler, $wgProfileLimit;
+
+ $params = array(
+ 'class' => 'ProfilerStub',
+ 'sampling' => 1,
+ 'threshold' => $wgProfileLimit,
+ 'output' => array(),
+ );
if ( is_array( $wgProfiler ) ) {
- $class = isset( $wgProfiler['class'] ) ?
$wgProfiler['class'] : 'ProfilerStub';
- $factor = isset( $wgProfiler['sampling'] ) ?
$wgProfiler['sampling'] : 1;
- if ( PHP_SAPI === 'cli' || mt_rand( 0, $factor
- 1 ) != 0 ) {
- $class = 'ProfilerStub';
- }
- self::$instance = new $class( $wgProfiler );
- } else {
- self::$instance = new ProfilerStub( array() );
+ $params = array_merge( $params, $wgProfiler );
}
+
+ $inSample = mt_rand( 0, $params['sampling'] - 1 ) === 0;
+ if ( PHP_SAPI === 'cli' || !$inSample ) {
+ $params['class'] = 'ProfilerStub';
+ }
+
+ if ( !is_array( $params['output'] ) ) {
+ $params['output'] = array( $params['output'] );
+ }
+
+ self::$instance = new $params['class']( $params );
}
return self::$instance;
}
@@ -114,6 +128,32 @@
return wfWikiID();
} else {
return $this->profileID;
+ }
+ }
+
+ /**
+ * Sets the context for this Profiler
+ *
+ * @param IContextSource $context
+ * @since 1.25
+ */
+ public function setContext( $context ) {
+ $this->context = $context;
+ }
+
+ /**
+ * Gets the context for this Profiler
+ *
+ * @return IContextSource
+ * @since 1.25
+ */
+ public function getContext() {
+ if ( $this->context ) {
+ return $this->context;
+ } else {
+ wfDebug( __METHOD__ . " called and \$context is null. "
.
+ "Return RequestContext::getMain(); for
sanity\n" );
+ return RequestContext::getMain();
}
}
@@ -152,37 +192,49 @@
abstract public function close();
/**
- * Log the data to some store or even the page output
+ * Get all usable outputs.
*
* @throws MWException
+ * @return array Array of ProfilerOutput instances.
+ * @since 1.25
+ */
+ private function getOutputs() {
+ $outputs = array();
+ foreach ( $this->params['output'] as $outputType ) {
+ if ( !isset( self::$outputTypes[$outputType] ) ) {
+ throw new MWException( "'$outputType' is an
invalid output type" );
+ }
+ $outputClass = self::$outputTypes[$outputType];
+ $outputInstance = new $outputClass( $this,
$this->params );
+ if ( $outputInstance->canUse() ) {
+ $outputs[] = $outputInstance;
+ }
+ }
+ return $outputs;
+ }
+
+ /**
+ * Log the data to some store or even the page output
+ *
* @since 1.25
*/
public function logData() {
- $output = isset( $this->params['output'] ) ?
$this->params['output'] : null;
+ $request = $this->getContext()->getRequest();
- if ( !$output || $this instanceof ProfilerStub ) {
- // return early when no output classes defined or we're
a stub
+ $timeElapsed = $request->getElapsedTime();
+ $timeElapsedThreshold = $this->params['threshold'];
+ if ( $timeElapsed <= $timeElapsedThreshold ) {
return;
}
- if ( !is_array( $output ) ) {
- $output = array( $output );
+ $outputs = $this->getOutputs();
+ if ( !$outputs ) {
+ return;
}
- $stats = null;
- foreach ( $output as $outType ) {
- if ( !isset( self::$outputTypes[$outType] ) ) {
- throw new MWException( "'$outType' is an
invalid output type" );
- }
- $class = self::$outputTypes[$outType];
- /** @var ProfilerOutput $profileOut */
- $profileOut = new $class( $this, $this->params );
- if ( $profileOut->canUse() ) {
- if ( is_null( $stats ) ) {
- $stats = $this->getFunctionStats();
- }
- $profileOut->log( $stats );
- }
+ $stats = $this->getFunctionStats();
+ foreach ( $outputs as $output ) {
+ $output->log( $stats );
}
}
diff --git a/includes/profiler/ProfilerStub.php
b/includes/profiler/ProfilerStub.php
index 5580f94..527ef1f 100644
--- a/includes/profiler/ProfilerStub.php
+++ b/includes/profiler/ProfilerStub.php
@@ -43,4 +43,7 @@
public function getCurrentSection() {
return '';
}
+
+ public function logData() {
+ }
}
diff --git a/includes/profiler/output/ProfilerOutputStats.php
b/includes/profiler/output/ProfilerOutputStats.php
new file mode 100644
index 0000000..ef6ef7c
--- /dev/null
+++ b/includes/profiler/output/ProfilerOutputStats.php
@@ -0,0 +1,57 @@
+<?php
+/**
+ * ProfilerOutput class that flushes profiling data to the profiling
+ * context's stats buffer.
+ *
+ * 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
+ */
+
+/**
+ * ProfilerOutput class that flushes profiling data to the profiling
+ * context's stats buffer.
+ *
+ * @ingroup Profiler
+ * @since 1.25
+ */
+class ProfilerOutputStats extends ProfilerOutput {
+
+ /**
+ * Flush profiling data to the current profiling context's stats buffer.
+ *
+ * @param array $stats
+ */
+ public function log( array $stats ) {
+ $contextStats = $this->collector->getContext()->getStats();
+
+ foreach ( $stats as $stat ) {
+ // Sanitize the key
+ $key = str_replace( '::', '.', $stat['name'] );
+ $key = preg_replace( '/[^a-z.]+/i', '_', $key );
+ $key = trim( $key, '_.' );
+
+ // Convert fractional seconds to whole milliseconds
+ $cpu = round( $stat['cpu'] * 1000 );
+ $real = round( $stat['real'] * 1000 );
+
+ $contextStats->increment( "{$key}.calls" );
+ $contextStats->timing( "{$key}.cpu", $cpu );
+ $contextStats->timing( "{$key}.real", $real );
+ }
+ }
+}
--
To view, visit https://gerrit.wikimedia.org/r/201443
To unsubscribe, visit https://gerrit.wikimedia.org/r/settings
Gerrit-MessageType: merged
Gerrit-Change-Id: I6cc22664b60b34d699d7e8ea71d55eaa22ae61fb
Gerrit-PatchSet: 1
Gerrit-Project: mediawiki/core
Gerrit-Branch: wmf/1.25wmf23
Gerrit-Owner: Ori.livneh <o...@wikimedia.org>
Gerrit-Reviewer: Catrope <roan.katt...@gmail.com>
Gerrit-Reviewer: Daniel Friesen <dan...@nadir-seen-fire.com>
Gerrit-Reviewer: TTO <at.li...@live.com.au>
Gerrit-Reviewer: jenkins-bot <>
_______________________________________________
MediaWiki-commits mailing list
MediaWiki-commits@lists.wikimedia.org
https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits
