MWDebug.php

Go to the documentation of this file.

<?php
use MediaWiki\Logger\LegacyLogger;
use MediaWiki\ResourceLoader\ResourceLoader;
use Wikimedia\WrappedString;
use Wikimedia\WrappedStringList;
 
class MWDebug {
    protected static $log = [];
 
    protected static $debug = [];
 
    protected static $query = [];
 
    protected static $enabled = false;
 
    protected static $deprecationWarnings = [];
 
    protected static $deprecationFilters = [];
 
    public static function setup() {
        global $wgDebugToolbar,
            $wgUseCdn, $wgUseFileCache, $wgCommandLineMode;
 
        if (
            // Easy to forget to falsify $wgDebugToolbar for static caches.
            // If file cache or CDN cache is on, just disable this (DWIMD).
            $wgUseCdn ||
            $wgUseFileCache ||
            // Keep MWDebug off on CLI. This prevents MWDebug from eating up
            // all the memory for logging SQL queries in maintenance scripts.
            $wgCommandLineMode
        ) {
            return;
        }
 
        if ( $wgDebugToolbar ) {
            self::init();
        }
    }
 
    public static function init() {
        self::$enabled = true;
    }
 
    public static function deinit() {
        self::$enabled = false;
    }
 
    public static function addModules( OutputPage $out ) {
        if ( self::$enabled ) {
            $out->addModules( 'mediawiki.debug' );
        }
    }
 
    public static function log( $str ) {
        if ( !self::$enabled ) {
            return;
        }
        if ( !is_string( $str ) ) {
            $str = print_r( $str, true );
        }
        self::$log[] = [
            'msg' => htmlspecialchars( $str ),
            'type' => 'log',
            'caller' => wfGetCaller(),
        ];
    }
 
    public static function getLog() {
        return self::$log;
    }
 
    public static function clearLog() {
        self::$log = [];
        self::$deprecationWarnings = [];
    }
 
    public static function warning( $msg, $callerOffset = 1, $level = E_USER_NOTICE, $log = 'auto' ) {
        global $wgDevelopmentWarnings;
 
        if ( $log === 'auto' && !$wgDevelopmentWarnings ) {
            $log = 'debug';
        }
 
        if ( $log === 'debug' ) {
            $level = false;
        }
 
        $callerDescription = self::getCallerDescription( $callerOffset );
 
        self::sendMessage(
            self::formatCallerDescription( $msg, $callerDescription ),
            'warning',
            $level );
 
        if ( self::$enabled ) {
            self::$log[] = [
                'msg' => htmlspecialchars( $msg ),
                'type' => 'warn',
                'caller' => $callerDescription['func'],
            ];
        }
    }
 
    public static function deprecated( $function, $version = false,
        $component = false, $callerOffset = 2
    ) {
        if ( $version ) {
            $component = $component ?: 'MediaWiki';
            $msg = "Use of $function was deprecated in $component $version.";
        } else {
            $msg = "Use of $function is deprecated.";
        }
        self::deprecatedMsg( $msg, $version, $component, $callerOffset + 1 );
    }
 
    public static function detectDeprecatedOverride( $instance, $class, $method, $version = false,
        $component = false, $callerOffset = 2
    ) {
        $reflectionMethod = new ReflectionMethod( $instance, $method );
        $declaringClass = $reflectionMethod->getDeclaringClass()->getName();
 
        if ( $declaringClass === $class ) {
            // not overridden, nothing to do
            return false;
        }
 
        if ( $version ) {
            $component = $component ?: 'MediaWiki';
            $msg = "$declaringClass overrides $method which was deprecated in $component $version.";
            self::deprecatedMsg( $msg, $version, $component, $callerOffset + 1 );
        }
 
        return true;
    }
 
    public static function deprecatedMsg( $msg, $version = false,
        $component = false, $callerOffset = 2
    ) {
        if ( $callerOffset === false ) {
            $callerFunc = '';
            $rawMsg = $msg;
        } else {
            $callerDescription = self::getCallerDescription( $callerOffset );
            $callerFunc = $callerDescription['func'];
            $rawMsg = self::formatCallerDescription( $msg, $callerDescription );
        }
 
        $sendToLog = true;
 
        // Check to see if there already was a warning about this function
        if ( isset( self::$deprecationWarnings[$msg][$callerFunc] ) ) {
            return;
        } elseif ( isset( self::$deprecationWarnings[$msg] ) ) {
            if ( self::$enabled ) {
                $sendToLog = false;
            } else {
                return;
            }
        }
 
        self::$deprecationWarnings[$msg][$callerFunc] = true;
 
        if ( $version ) {
            global $wgDeprecationReleaseLimit;
 
            $component = $component ?: 'MediaWiki';
            if ( $wgDeprecationReleaseLimit && $component === 'MediaWiki' ) {
                # Strip -* off the end of $version so that branches can use the
                # format #.##-branchname to avoid issues if the branch is merged into
                # a version of MediaWiki later than what it was branched from
                $comparableVersion = preg_replace( '/-.*$/', '', $version );
 
                # If the comparableVersion is larger than our release limit then
                # skip the warning message for the deprecation
                if ( version_compare( $wgDeprecationReleaseLimit, $comparableVersion, '<' ) ) {
                    $sendToLog = false;
                }
            }
        }
 
        self::sendRawDeprecated(
            $rawMsg,
            $sendToLog,
            $callerFunc
        );
    }
 
    public static function sendRawDeprecated( $msg, $sendToLog = true, $callerFunc = '' ) {
        foreach ( self::$deprecationFilters as $filter => $callback ) {
            if ( preg_match( $filter, $msg ) ) {
                if ( is_callable( $callback ) ) {
                    $callback();
                }
                return;
            }
        }
 
        if ( $sendToLog ) {
            trigger_error( $msg, E_USER_DEPRECATED );
        }
 
        if ( self::$enabled ) {
            $logMsg = htmlspecialchars( $msg ) .
                Html::rawElement( 'div', [ 'class' => 'mw-debug-backtrace' ],
                    Html::element( 'span', [], 'Backtrace:' ) . wfBacktrace()
                );
 
            self::$log[] = [
                'msg' => $logMsg,
                'type' => 'deprecated',
                'caller' => $callerFunc,
            ];
        }
    }
 
    public static function filterDeprecationForTest(
        string $regex, ?callable $callback = null
    ): void {
        if ( !defined( 'MW_PHPUNIT_TEST' ) && !defined( 'MW_PARSER_TEST' ) ) {
            throw new RuntimeException( __METHOD__ . ' can only be used in tests' );
        }
        self::$deprecationFilters[$regex] = $callback;
    }
 
    public static function clearDeprecationFilters() {
        self::$deprecationFilters = [];
    }
 
    private static function getCallerDescription( $callerOffset ) {
        $callers = wfDebugBacktrace();
 
        if ( isset( $callers[$callerOffset] ) ) {
            $callerfile = $callers[$callerOffset];
            if ( isset( $callerfile['file'] ) && isset( $callerfile['line'] ) ) {
                $file = $callerfile['file'] . ' at line ' . $callerfile['line'];
            } else {
                $file = '(internal function)';
            }
        } else {
            $file = '(unknown location)';
        }
 
        if ( isset( $callers[$callerOffset + 1] ) ) {
            $callerfunc = $callers[$callerOffset + 1];
            $func = '';
            if ( isset( $callerfunc['class'] ) ) {
                $func .= $callerfunc['class'] . '::';
            }
            if ( isset( $callerfunc['function'] ) ) {
                $func .= $callerfunc['function'];
            }
        } else {
            $func = 'unknown';
        }
 
        return [ 'file' => $file, 'func' => $func ];
    }
 
    private static function formatCallerDescription( $msg, $caller ) {
        // When changing this, update the below parseCallerDescription() method  as well.
        return $msg . ' [Called from ' . $caller['func'] . ' in ' . $caller['file'] . ']';
    }
 
    public static function parseCallerDescription( $msg ) {
        $match = null;
        preg_match( '/(.*) \[Called from ([^ ]+) in ([^ ]+) at line (\d+)\]$/', $msg, $match );
        if ( $match ) {
            return [
                'message' => "{$match[1]} [Called from {$match[2]}]",
                'func' => $match[2],
                'file' => $match[3],
                'line' => $match[4],
            ];
        } else {
            return null;
        }
    }
 
    private static function sendMessage( $msg, $group, $level ) {
        if ( $level !== false ) {
            trigger_error( $msg, $level );
        }
 
        wfDebugLog( $group, $msg );
    }
 
    public static function debugMsg( $str, $context = [] ) {
        global $wgDebugComments, $wgShowDebug;
 
        if ( self::$enabled || $wgDebugComments || $wgShowDebug ) {
            if ( $context ) {
                $prefix = '';
                if ( isset( $context['prefix'] ) ) {
                    $prefix = $context['prefix'];
                } elseif ( isset( $context['channel'] ) && $context['channel'] !== 'wfDebug' ) {
                    $prefix = "[{$context['channel']}] ";
                }
                if ( isset( $context['seconds_elapsed'] ) && isset( $context['memory_used'] ) ) {
                    $prefix .= "{$context['seconds_elapsed']} {$context['memory_used']}  ";
                }
                $str = LegacyLogger::interpolate( $str, $context );
                $str = $prefix . $str;
            }
            self::$debug[] = rtrim( UtfNormal\Validator::cleanUp( $str ) );
        }
    }
 
    public static function query( $sql, $function, $runTime, $dbhost ) {
        if ( !self::$enabled ) {
            return false;
        }
 
        // Replace invalid UTF-8 chars with a square UTF-8 character
        // This prevents json_encode from erroring out due to binary SQL data
        $sql = preg_replace(
            '/(
                [\xC0-\xC1] # Invalid UTF-8 Bytes
                | [\xF5-\xFF] # Invalid UTF-8 Bytes
                | \xE0[\x80-\x9F] # Overlong encoding of prior code point
                | \xF0[\x80-\x8F] # Overlong encoding of prior code point
                | [\xC2-\xDF](?![\x80-\xBF]) # Invalid UTF-8 Sequence Start
                | [\xE0-\xEF](?![\x80-\xBF]{2}) # Invalid UTF-8 Sequence Start
                | [\xF0-\xF4](?![\x80-\xBF]{3}) # Invalid UTF-8 Sequence Start
                | (?<=[\x0-\x7F\xF5-\xFF])[\x80-\xBF] # Invalid UTF-8 Sequence Middle
                | (?<![\xC2-\xDF]|[\xE0-\xEF]|[\xE0-\xEF][\x80-\xBF]|[\xF0-\xF4]
                    | [\xF0-\xF4][\x80-\xBF]|[\xF0-\xF4][\x80-\xBF]{2})[\x80-\xBF] # Overlong Sequence
                | (?<=[\xE0-\xEF])[\x80-\xBF](?![\x80-\xBF]) # Short 3 byte sequence
                | (?<=[\xF0-\xF4])[\x80-\xBF](?![\x80-\xBF]{2}) # Short 4 byte sequence
                | (?<=[\xF0-\xF4][\x80-\xBF])[\x80-\xBF](?![\x80-\xBF]) # Short 4 byte sequence (2)
            )/x',
            '■',
            $sql
        );
 
        // last check for invalid utf8
        $sql = UtfNormal\Validator::cleanUp( $sql );
 
        self::$query[] = [
            'sql' => "$dbhost: $sql",
            'function' => $function,
            'time' => $runTime,
        ];
 
        return true;
    }
 
    protected static function getFilesIncluded( IContextSource $context ) {
        $files = get_included_files();
        $fileList = [];
        foreach ( $files as $file ) {
            $size = filesize( $file );
            $fileList[] = [
                'name' => $file,
                'size' => $context->getLanguage()->formatSize( $size ),
            ];
        }
 
        return $fileList;
    }
 
    public static function getDebugHTML( IContextSource $context ) {
        global $wgDebugComments;
 
        $html = [];
 
        if ( self::$enabled ) {
            self::log( 'MWDebug output complete' );
            $debugInfo = self::getDebugInfo( $context );
 
            // Cannot use OutputPage::addJsConfigVars because those are already outputted
            // by the time this method is called.
            $html[] = ResourceLoader::makeInlineScript(
                ResourceLoader::makeConfigSetScript( [ 'debugInfo' => $debugInfo ] ),
                $context->getOutput()->getCSP()->getNonce()
            );
        }
 
        if ( $wgDebugComments ) {
            $html[] = '<!-- Debug output:';
            foreach ( self::$debug as $line ) {
                $html[] = htmlspecialchars( $line, ENT_NOQUOTES );
            }
            $html[] = '-->';
        }
 
        return WrappedString::join( "\n", $html );
    }
 
    public static function getHTMLDebugLog() {
        global $wgShowDebug;
 
        $html = [];
        if ( $wgShowDebug ) {
            $html[] = Html::openElement( 'div', [ 'id' => 'mw-html-debug-log' ] );
            $html[] = "<hr />\n<strong>Debug data:</strong><ul id=\"mw-debug-html\">";
 
            foreach ( self::$debug as $line ) {
                $display = nl2br( htmlspecialchars( trim( $line ) ) );
 
                $html[] = "<li><code>$display</code></li>";
            }
 
            $html[] = '</ul>';
            $html[] = '</div>';
        }
        return WrappedString::join( "\n", $html );
    }
 
    public static function appendDebugInfoToApiResult( IContextSource $context, ApiResult $result ) {
        if ( !self::$enabled ) {
            return;
        }
 
        // output errors as debug info, when display_errors is on
        // this is necessary for all non html output of the api, because that clears all errors first
        $obContents = ob_get_contents();
        if ( $obContents ) {
            $obContentArray = explode( '<br />', $obContents );
            foreach ( $obContentArray as $obContent ) {
                if ( trim( $obContent ) ) {
                    self::debugMsg( Sanitizer::stripAllTags( $obContent ) );
                }
            }
        }
 
        self::log( 'MWDebug output complete' );
        $debugInfo = self::getDebugInfo( $context );
 
        ApiResult::setIndexedTagName( $debugInfo, 'debuginfo' );
        ApiResult::setIndexedTagName( $debugInfo['log'], 'line' );
        ApiResult::setIndexedTagName( $debugInfo['debugLog'], 'msg' );
        ApiResult::setIndexedTagName( $debugInfo['queries'], 'query' );
        ApiResult::setIndexedTagName( $debugInfo['includes'], 'queries' );
        $result->addValue( null, 'debuginfo', $debugInfo );
    }
 
    public static function getDebugInfo( IContextSource $context ) {
        if ( !self::$enabled ) {
            return [];
        }
 
        $request = $context->getRequest();
 
        $branch = GitInfo::currentBranch();
        if ( GitInfo::isSHA1( $branch ) ) {
            // If it's a detached HEAD, the SHA1 will already be
            // included in the MW version, so don't show it.
            $branch = false;
        }
 
        return [
            'mwVersion' => MW_VERSION,
            'phpEngine' => 'PHP',
            'phpVersion' => PHP_VERSION,
            'gitRevision' => GitInfo::headSHA1(),
            'gitBranch' => $branch,
            'gitViewUrl' => GitInfo::headViewUrl(),
            'time' => $request->getElapsedTime(),
            'log' => self::$log,
            'debugLog' => self::$debug,
            'queries' => self::$query,
            'request' => [
                'method' => $request->getMethod(),
                'url' => $request->getRequestURL(),
                'headers' => $request->getAllHeaders(),
                'params' => $request->getValues(),
            ],
            'memory' => $context->getLanguage()->formatSize( memory_get_usage() ),
            'memoryPeak' => $context->getLanguage()->formatSize( memory_get_peak_usage() ),
            'includes' => self::getFilesIncluded( $context ),
        ];
    }
}