Gergő Tisza has uploaded a new change for review. (
https://gerrit.wikimedia.org/r/393503 )
Change subject: Add optional EXPLAIN logging
......................................................................
Add optional EXPLAIN logging
Adds an option to Database to EXPLAIN all queries and
log the output to the DBExplain channel, as a convenience
for performance debugging. Adds a MediaWiki config flag
($wgDebugExplainSql) to enable it.
Change-Id: Ide5a83fc832b1f72d8e62c7b0932ebc90973afb7
---
M includes/DefaultSettings.php
M includes/db/MWLBFactory.php
M includes/libs/rdbms/database/Database.php
M includes/libs/rdbms/lbfactory/ILBFactory.php
M includes/libs/rdbms/lbfactory/LBFactory.php
M includes/libs/rdbms/loadbalancer/ILoadBalancer.php
M includes/libs/rdbms/loadbalancer/LoadBalancer.php
7 files changed, 96 insertions(+), 1 deletion(-)
git pull ssh://gerrit.wikimedia.org:29418/mediawiki/core
refs/changes/03/393503/1
diff --git a/includes/DefaultSettings.php b/includes/DefaultSettings.php
index d9f032c..f781c88 100644
--- a/includes/DefaultSettings.php
+++ b/includes/DefaultSettings.php
@@ -6123,6 +6123,11 @@
$wgDebugDumpSql = false;
/**
+ * Run EXPLAIN on all queries and log the output to the DBExplain channel.
+ */
+$wgDebugExplainSql = false;
+
+/**
* Performance expectations for DB usage
*
* @since 1.26
diff --git a/includes/db/MWLBFactory.php b/includes/db/MWLBFactory.php
index aa1918d..e3a1d08 100644
--- a/includes/db/MWLBFactory.php
+++ b/includes/db/MWLBFactory.php
@@ -60,6 +60,9 @@
'hostname' => wfHostname(),
'readOnlyReason' => $readOnlyMode->getReason(),
];
+ if ( $mainConfig->get( 'DebugExplainSql' ) ) {
+ $lbConf['explainLogger'] = LoggerFactory::getInstance(
'DBExplain' );
+ }
// When making changes here, remember to also specify
MediaWiki-specific options
// for Database classes in the relevant Installer subclass.
diff --git a/includes/libs/rdbms/database/Database.php
b/includes/libs/rdbms/database/Database.php
index e04566e..cce31c6 100644
--- a/includes/libs/rdbms/database/Database.php
+++ b/includes/libs/rdbms/database/Database.php
@@ -85,6 +85,8 @@
protected $connLogger;
/** @var LoggerInterface */
protected $queryLogger;
+ /** @var LoggerInterface|null */
+ protected $explainLogger;
/** @var callback Error logging callback */
protected $errorLogger;
@@ -276,6 +278,7 @@
$this->trxProfiler = $params['trxProfiler'];
$this->connLogger = $params['connLogger'];
$this->queryLogger = $params['queryLogger'];
+ $this->explainLogger = isset( $params['explainLogger'] ) ?
$params['explainLogger'] : null;
$this->errorLogger = $params['errorLogger'];
// Set initial dummy domain until open() sets the final
DB/prefix
@@ -323,6 +326,8 @@
* used to adjust lock timeouts or encoding modes and the like.
* - connLogger: Optional PSR-3 logger interface instance.
* - queryLogger: Optional PSR-3 logger interface instance.
+ * - explainLogger: Optional PSR-3 logger interface instance. When
present, all appropriate
+ * queries will be EXPLAINed first and the output sent to this
channel.
* - profiler: Optional class name or object with
profileIn()/profileOut() methods.
* These will be called in query(), using a simplified version of
the SQL that also
* includes the agent as a SQL comment.
@@ -847,6 +852,20 @@
}
/**
+ * Determine whether EXPLAIN works with this query.
+ *
+ * @param string $sql
+ * @return bool
+ */
+ protected function isExplainableQuery( $sql ) {
+ return in_array(
+ $this->getQueryVerb( $sql ),
+ [ 'SELECT', 'INSERT', 'UPDATE', 'REPLACE', 'DELETE' ],
+ true
+ );
+ }
+
+ /**
* @param string $sql A SQL query
* @return bool Whether $sql is SQL for TEMPORARY table operation
*/
@@ -997,6 +1016,16 @@
* object for a successful read query, or false on failure
*/
private function doProfiledQuery( $sql, $commentedSql, $isWrite, $fname
) {
+ if ( $this->explainLogger && $this->isExplainableQuery( $sql )
) {
+ $res = $this->doQuery( "EXPLAIN $commentedSql" );
+ if ( $res ) {
+ $explain = $this->formatResult( $res );
+ $this->explainLogger->info(
"$commentedSql\n$explain", [
+ 'caller' => $fname,
+ ] );
+ }
+ }
+
$isMaster = !is_null( $this->getLBInfo( 'master' ) );
# generalizeSQL() will probably cut down the query to reasonable
# logging size most of the time. The substr is really just a
sanity check.
@@ -3697,6 +3726,53 @@
}
/**
+ * Formats a database result set in a similar way to DB clients. This
is meant as a
+ * convenience for debugging/logging.
+ * @param IResultWrapper|false $res
+ * @return string
+ */
+ protected function formatResult( $res ) {
+ if ( $res === false || $res->numRows() === 0 ) {
+ return '';
+ }
+
+ $data = iterator_to_array( $res );
+ $lengths = $header = [];
+ foreach ( $data[0] as $columnName => $_ ) {
+ $lengths[$columnName] = max( strlen( $columnName ),
+ max( array_map( 'strlen', array_column( $data,
$columnName ) ) ) );
+ $header[$columnName] = $columnName;
+ }
+
+ $explain = $this->formatResultRow( null, $lengths ) . PHP_EOL
+ . $this->formatResultRow( $header, $lengths ) . PHP_EOL
+ . $this->formatResultRow( null, $lengths ) . PHP_EOL;
+ foreach ( $data as $row ) {
+ $explain .= $this->formatResultRow( $row, $lengths ) .
PHP_EOL;
+ }
+ $explain .= $this->formatResultRow( null, $lengths ) . PHP_EOL;
+ return $explain;
+ }
+
+ /**
+ * Helper method for formatResult().
+ * @param array|null $row Row data, or null for a separator row.
+ * @param array $lengths Column lengths.
+ * @return string
+ */
+ protected function formatResultRow( $row, array $lengths ) {
+ $rowText = $row ? '+' : '|';
+ foreach ( $lengths as $columnName => $length ) {
+ if ( $row ) {
+ $rowText .= ' ' . str_pad( $row[$columnName],
$length + 1 ) . '|';
+ } else {
+ $rowText .= str_pad( '', $length + 2, '-' ) .
'+';
+ }
+ }
+ return $rowText;
+ }
+
+ /**
* @since 1.19
* @return string
*/
diff --git a/includes/libs/rdbms/lbfactory/ILBFactory.php
b/includes/libs/rdbms/lbfactory/ILBFactory.php
index f6d080e..190ab2b 100644
--- a/includes/libs/rdbms/lbfactory/ILBFactory.php
+++ b/includes/libs/rdbms/lbfactory/ILBFactory.php
@@ -53,6 +53,8 @@
* - replLogger: PSR-3 logger instance. [optional]
* - connLogger: PSR-3 logger instance. [optional]
* - queryLogger: PSR-3 logger instance. [optional]
+ * - explainLogger: PSR-3 logger interface instance. When present, all
appropriate
+ * queries will be EXPLAINed first and the output sent to this
channel. [optional]
* - perfLogger: PSR-3 logger instance. [optional]
* - errorLogger : Callback that takes an Exception and logs it.
[optional]
* @throws InvalidArgumentException
diff --git a/includes/libs/rdbms/lbfactory/LBFactory.php
b/includes/libs/rdbms/lbfactory/LBFactory.php
index c891fb6..20c3e36 100644
--- a/includes/libs/rdbms/lbfactory/LBFactory.php
+++ b/includes/libs/rdbms/lbfactory/LBFactory.php
@@ -48,6 +48,8 @@
protected $connLogger;
/** @var LoggerInterface */
protected $queryLogger;
+ /** @var LoggerInterface|null */
+ protected $explainLogger;
/** @var LoggerInterface */
protected $perfLogger;
/** @var callable Error logger */
@@ -106,6 +108,7 @@
: function ( Exception $e ) {
trigger_error( E_USER_WARNING, get_class( $e )
. ': ' . $e->getMessage() );
};
+ $this->explainLogger = isset( $conf['explainLogger'] ) ?
$conf['explainLogger'] : null;
$this->profiler = isset( $conf['profiler'] ) ?
$conf['profiler'] : null;
$this->trxProfiler = isset( $conf['trxProfiler'] )
@@ -504,6 +507,7 @@
'profiler' => $this->profiler,
'trxProfiler' => $this->trxProfiler,
'queryLogger' => $this->queryLogger,
+ 'explainLogger' => $this->explainLogger,
'connLogger' => $this->connLogger,
'replLogger' => $this->replLogger,
'errorLogger' => $this->errorLogger,
diff --git a/includes/libs/rdbms/loadbalancer/ILoadBalancer.php
b/includes/libs/rdbms/loadbalancer/ILoadBalancer.php
index 22a5805..1e1918e 100644
--- a/includes/libs/rdbms/loadbalancer/ILoadBalancer.php
+++ b/includes/libs/rdbms/loadbalancer/ILoadBalancer.php
@@ -106,6 +106,8 @@
* - replLogger: PSR-3 logger instance. [optional]
* - connLogger: PSR-3 logger instance. [optional]
* - queryLogger: PSR-3 logger instance. [optional]
+ * - explainLogger: PSR-3 logger interface instance. When present, all
appropriate
+ * queries will be EXPLAINed first and the output sent to this
channel. [optional]
* - perfLogger: PSR-3 logger instance. [optional]
* - errorLogger : Callback that takes an Exception and logs it.
[optional]
* @throws InvalidArgumentException
diff --git a/includes/libs/rdbms/loadbalancer/LoadBalancer.php
b/includes/libs/rdbms/loadbalancer/LoadBalancer.php
index 6bb8945..bc5c435 100644
--- a/includes/libs/rdbms/loadbalancer/LoadBalancer.php
+++ b/includes/libs/rdbms/loadbalancer/LoadBalancer.php
@@ -74,6 +74,8 @@
protected $connLogger;
/** @var LoggerInterface */
protected $queryLogger;
+ /** @var LoggerInterface|null */
+ protected $explainLogger;
/** @var LoggerInterface */
protected $perfLogger;
@@ -218,7 +220,7 @@
: function ( Exception $e ) {
trigger_error( get_class( $e ) . ': ' .
$e->getMessage(), E_USER_WARNING );
};
-
+ $this->explainLogger = isset( $params['explainLogger'] ) ?
$params['explainLogger'] : null;
foreach ( [ 'replLogger', 'connLogger', 'queryLogger',
'perfLogger' ] as $key ) {
$this->$key = isset( $params[$key] ) ? $params[$key] :
new NullLogger();
}
@@ -974,6 +976,7 @@
// Set loggers and profilers
$server['connLogger'] = $this->connLogger;
$server['queryLogger'] = $this->queryLogger;
+ $server['explainLogger'] = $this->explainLogger;
$server['errorLogger'] = $this->errorLogger;
$server['profiler'] = $this->profiler;
$server['trxProfiler'] = $this->trxProfiler;
--
To view, visit https://gerrit.wikimedia.org/r/393503
To unsubscribe, visit https://gerrit.wikimedia.org/r/settings
Gerrit-MessageType: newchange
Gerrit-Change-Id: Ide5a83fc832b1f72d8e62c7b0932ebc90973afb7
Gerrit-PatchSet: 1
Gerrit-Project: mediawiki/core
Gerrit-Branch: master
Gerrit-Owner: Gergő Tisza <[email protected]>
_______________________________________________
MediaWiki-commits mailing list
[email protected]
https://lists.wikimedia.org/mailman/listinfo/mediawiki-commits
