From: Timo Tijhof Date: Sat, 5 Oct 2019 01:56:12 +0000 (+0100) Subject: rdbms: Restore debug toolbar "Queries" feature X-Git-Tag: 1.34.0-rc.1~38 X-Git-Url: https://git.heureux-cyclage.org/?p=lhc%2Fweb%2Fwiklou.git;a=commitdiff_plain;h=88e3a888cc6823f11df79ac53eb963a7e4d2871a rdbms: Restore debug toolbar "Queries" feature This broke after e0cc49ce3971e19, due to the field 'master' being removed from the log context. The LegacyLogger logic forwarding these messages to MWDebug (for the debug toolbar) however, was dependant on. Users of debug toolbar experienced a silent failure because the logic in question is very tolerant of missing fields. This is because it uses those fields to distinguish the 'sql' messages from channel=DBQuery from other messages in the same channel. Making that less fragile is outside the scope of this commit. This commit: * Restore the basic functionality by making sure MWDebug::query() gets called again for DBQuery messages. * Remove the code relating to the 'master' field as this no longer exists in RDBMS. It also wasn't used anywhere (to be used, it would need to be read by mediawiki.debug/debug.js). * Remove unexpanded "{method}" and "{runtime}" noise in the debug toolbar text. This was introduced by he conversion to PSR-3 logging.. These fields are already rendered separately by the toolbar and should not be part of the "SQL" column. To do this, we need to log the $sql bit as its own key, so I've made this a context field as well. * Reduce the condition logic in LegacyLogger to only looking for 'DBQuery' and 'sql'. This way, if it breaks again it will still call the logic within and emit E_NOTICE instead, which would help detect the issue (and still fallback to at least showing the queries). Unlike before this commit where it took quite some time to figure out why it wasn't working. * The above fixes still weren't enough to get queries to show up in the Debug toolbar for me. Turns out, this was because my local setup (mediawiki-docker-dev) uses a master-replica set up. The setup doesn't use any custom LBFactory config, just plain $wgDBservers. The logic for turning these plain settings into LBFactory (in MWLBFactory.php) does kick in, and does run (unlike if I had custom wgLBFactoryConf). But, the DBO_DEBUG flag didn't make it through because of the += operator preferring any pre-existing value my setup has, which is just `DBO_DEFAULT`. Merging 'flags' keys seems unsafe in general, but adding DBO_DEBUG based on $wgDebugDumpSql seems innocent and doesn't affect other behaviour (it's a case of DWIM). Bug: T231742 Change-Id: I122bb1a65620a7ae4e1943136c975b63524a5111 (cherry picked from commit 2e404a25828c713c0926b8f9e2003ad1e7dbe667) --- diff --git a/includes/DefaultSettings.php b/includes/DefaultSettings.php index d8aff2da1c..ea8b5321d4 100644 --- a/includes/DefaultSettings.php +++ b/includes/DefaultSettings.php @@ -6154,9 +6154,8 @@ $wgDebugComments = false; * Write SQL queries to the debug log. * * This setting is only used $wgLBFactoryConf['class'] is set to - * '\Wikimedia\Rdbms\LBFactorySimple' and $wgDBservers is an empty array; otherwise - * the DBO_DEBUG flag must be set in the 'flags' option of the database - * connection to achieve the same functionality. + * '\Wikimedia\Rdbms\LBFactorySimple'; otherwise the DBO_DEBUG flag must be set in + * the 'flags' option of the database connection to achieve the same functionality. */ $wgDebugDumpSql = false; diff --git a/includes/db/MWLBFactory.php b/includes/db/MWLBFactory.php index 5daf9ef8fc..b4e782b62f 100644 --- a/includes/db/MWLBFactory.php +++ b/includes/db/MWLBFactory.php @@ -196,13 +196,14 @@ abstract class MWLBFactory { $server += [ 'schema' => $options->get( 'DBmwschema' ) ]; } - $flags = DBO_DEFAULT; - $flags |= $options->get( 'DebugDumpSql' ) ? DBO_DEBUG : 0; - $flags |= $options->get( 'DebugLogFile' ) ? DBO_DEBUG : 0; + $flags = $server['flags'] ?? DBO_DEFAULT; + if ( $options->get( 'DebugDumpSql' ) || $options->get( 'DebugLogFile' ) ) { + $flags |= DBO_DEBUG; + } + $server['flags'] = $flags; $server += [ 'tablePrefix' => $options->get( 'DBprefix' ), - 'flags' => $flags, 'sqlMode' => $options->get( 'SQLMode' ), ]; diff --git a/includes/debug/MWDebug.php b/includes/debug/MWDebug.php index 6bcb0e6ff8..057d8fa1a0 100644 --- a/includes/debug/MWDebug.php +++ b/includes/debug/MWDebug.php @@ -371,11 +371,11 @@ class MWDebug { * @since 1.19 * @param string $sql * @param string $function - * @param bool $isMaster * @param float $runTime Query run time + * @param string $dbhost * @return bool True if debugger is enabled, false otherwise */ - public static function query( $sql, $function, $isMaster, $runTime ) { + public static function query( $sql, $function, $runTime, $dbhost ) { if ( !self::$enabled ) { return false; } @@ -406,9 +406,8 @@ class MWDebug { $sql = UtfNormal\Validator::cleanUp( $sql ); self::$query[] = [ - 'sql' => $sql, + 'sql' => "$dbhost: $sql", 'function' => $function, - 'master' => (bool)$isMaster, 'time' => $runTime, ]; diff --git a/includes/debug/logger/LegacyLogger.php b/includes/debug/logger/LegacyLogger.php index 72c7643418..974b044beb 100644 --- a/includes/debug/logger/LegacyLogger.php +++ b/includes/debug/logger/LegacyLogger.php @@ -102,16 +102,15 @@ class LegacyLogger extends AbstractLogger { $level = self::$levelMapping[$level]; } if ( $this->channel === 'DBQuery' - && isset( $context['method'] ) - && isset( $context['master'] ) - && isset( $context['runtime'] ) + && $level === self::$levelMapping[LogLevel::DEBUG] + && isset( $context['sql'] ) ) { // Also give the query information to the MWDebug tools $enabled = MWDebug::query( - $message, + $context['sql'], $context['method'], - $context['master'], - $context['runtime'] + $context['runtime'], + $context['db_host'] ); if ( $enabled ) { // If we the toolbar was enabled, return early so that we don't diff --git a/includes/libs/rdbms/database/Database.php b/includes/libs/rdbms/database/Database.php index 51596da7c3..5f59f34822 100644 --- a/includes/libs/rdbms/database/Database.php +++ b/includes/libs/rdbms/database/Database.php @@ -1334,10 +1334,11 @@ abstract class Database implements IDatabase, IMaintainableDatabase, LoggerAware // Avoid the overhead of logging calls unless debug mode is enabled if ( $this->getFlag( self::DBO_DEBUG ) ) { $this->queryLogger->debug( - "{method} [{runtime}s] {db_host}: $sql", + "{method} [{runtime}s] {db_host}: {sql}", [ 'method' => $fname, 'db_host' => $this->getServer(), + 'sql' => $sql, 'domain' => $this->getDomainID(), 'runtime' => round( $queryRuntime, 3 ) ]