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 d8aff2d..ea8b532 100644 (file)
--- 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
  * 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;
 
  */
 $wgDebugDumpSql = false;
 

diff --git a/includes/db/MWLBFactory.php b/includes/db/MWLBFactory.php
index 5daf9ef..b4e782b 100644 (file)
--- a/includes/db/MWLBFactory.php
+++ b/includes/db/MWLBFactory.php
@@ -196,13 +196,14 @@ abstract class MWLBFactory {
                        $server += [ 'schema' => $options->get( 'DBmwschema' ) ];
                }
 
                        $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' ),
 
                $server += [
                        'tablePrefix' => $options->get( 'DBprefix' ),

-                       'flags' => $flags,

                        'sqlMode' => $options->get( 'SQLMode' ),
                ];
 
                        'sqlMode' => $options->get( 'SQLMode' ),
                ];
 

diff --git a/includes/debug/MWDebug.php b/includes/debug/MWDebug.php
index 6bcb0e6..057d8fa 100644 (file)
--- 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
         * @since 1.19
         * @param string $sql
         * @param string $function

-        * @param bool $isMaster

         * @param float $runTime Query run time
         * @param float $runTime Query run time

+        * @param string $dbhost

         * @return bool True if debugger is enabled, false otherwise
         */
         * @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;
                }
                if ( !self::$enabled ) {
                        return false;
                }


@@ -406,9 +406,8 @@ class MWDebug {
                $sql = UtfNormal\Validator::cleanUp( $sql );
 
                self::$query[] = [
                $sql = UtfNormal\Validator::cleanUp( $sql );
 
                self::$query[] = [

-                       'sql' => $sql,
+                       'sql' => "$dbhost: $sql",

                        'function' => $function,
                        'function' => $function,

-                       'master' => (bool)$isMaster,

                        'time' => $runTime,
                ];
 
                        'time' => $runTime,
                ];
 

diff --git a/includes/debug/logger/LegacyLogger.php b/includes/debug/logger/LegacyLogger.php
index 72c7643..974b044 100644 (file)
--- 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'
                        $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(
                ) {
                        // Also give the query information to the MWDebug tools
                        $enabled = MWDebug::query(

-                               $message,
+                               $context['sql'],

                                $context['method'],
                                $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
                        );
                        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 51596da..5f59f34 100644 (file)
--- 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(
                // 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(),
                                [
                                        'method' => $fname,
                                        'db_host' => $this->getServer(),

+                                       'sql' => $sql,

                                        'domain' => $this->getDomainID(),
                                        'runtime' => round( $queryRuntime, 3 )
                                ]
                                        'domain' => $this->getDomainID(),
                                        'runtime' => round( $queryRuntime, 3 )
                                ]