includes/debug/MWDebug.php

   1 <?php
   2 /**
   3  * Debug toolbar related code.
   4  *
   5  * This program is free software; you can redistribute it and/or modify
   6  * it under the terms of the GNU General Public License as published by
   7  * the Free Software Foundation; either version 2 of the License, or
   8  * (at your option) any later version.
   9  *
  10  * This program is distributed in the hope that it will be useful,
  11  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  12  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
  13  * GNU General Public License for more details.
  14  *
  15  * You should have received a copy of the GNU General Public License along
  16  * with this program; if not, write to the Free Software Foundation, Inc.,
  17  * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
  18  * http://www.gnu.org/copyleft/gpl.html
  19  *
  20  * @file
  21  */
  22
  23 /**
  24  * New debugger system that outputs a toolbar on page view.
  25  *
  26  * By default, most methods do nothing ( self::$enabled = false ). You have
  27  * to explicitly call MWDebug::init() to enabled them.
  28  *
  29  * @since 1.19
  30  */
  31 class MWDebug {
  32         /**
  33          * Log lines
  34          *
  35          * @var array $log
  36          */
  37         protected static $log = [];
  38
  39         /**
  40          * Debug messages from wfDebug().
  41          *
  42          * @var array $debug
  43          */
  44         protected static $debug = [];
  45
  46         /**
  47          * SQL statements of the database queries.
  48          *
  49          * @var array $query
  50          */
  51         protected static $query = [];
  52
  53         /**
  54          * Is the debugger enabled?
  55          *
  56          * @var bool $enabled
  57          */
  58         protected static $enabled = false;
  59
  60         /**
  61          * Array of functions that have already been warned, formatted
  62          * function-caller to prevent a buttload of warnings
  63          *
  64          * @var array $deprecationWarnings
  65          */
  66         protected static $deprecationWarnings = [];
  67
  68         /**
  69          * Enabled the debugger and load resource module.
  70          * This is called by Setup.php when $wgDebugToolbar is true.
  71          *
  72          * @since 1.19
  73          */
  74         public static function init() {
  75                 self::$enabled = true;
  76         }
  77
  78         /**
  79          * Disable the debugger.
  80          *
  81          * @since 1.28
  82          */
  83         public static function deinit() {
  84                 self::$enabled = false;
  85         }
  86
  87         /**
  88          * Add ResourceLoader modules to the OutputPage object if debugging is
  89          * enabled.
  90          *
  91          * @since 1.19
  92          * @param OutputPage $out
  93          */
  94         public static function addModules( OutputPage $out ) {
  95                 if ( self::$enabled ) {
  96                         $out->addModules( 'mediawiki.debug.init' );
  97                 }
  98         }
  99
 100         /**
 101          * Adds a line to the log
 102          *
 103          * @since 1.19
 104          * @param mixed $str
 105          */
 106         public static function log( $str ) {
 107                 if ( !self::$enabled ) {
 108                         return;
 109                 }
 110                 if ( !is_string( $str ) ) {
 111                         $str = print_r( $str, true );
 112                 }
 113                 self::$log[] = [
 114                         'msg' => htmlspecialchars( $str ),
 115                         'type' => 'log',
 116                         'caller' => wfGetCaller(),
 117                 ];
 118         }
 119
 120         /**
 121          * Returns internal log array
 122          * @since 1.19
 123          * @return array
 124          */
 125         public static function getLog() {
 126                 return self::$log;
 127         }
 128
 129         /**
 130          * Clears internal log array and deprecation tracking
 131          * @since 1.19
 132          */
 133         public static function clearLog() {
 134                 self::$log = [];
 135                 self::$deprecationWarnings = [];
 136         }
 137
 138         /**
 139          * Adds a warning entry to the log
 140          *
 141          * @since 1.19
 142          * @param string $msg
 143          * @param int $callerOffset
 144          * @param int $level A PHP error level. See sendMessage()
 145          * @param string $log 'production' will always trigger a php error, 'auto'
 146          *    will trigger an error if $wgDevelopmentWarnings is true, and 'debug'
 147          *    will only write to the debug log(s).
 148          *
 149          * @return mixed
 150          */
 151         public static function warning( $msg, $callerOffset = 1, $level = E_USER_NOTICE, $log = 'auto' ) {
 152                 global $wgDevelopmentWarnings;
 153
 154                 if ( $log === 'auto' && !$wgDevelopmentWarnings ) {
 155                         $log = 'debug';
 156                 }
 157
 158                 if ( $log === 'debug' ) {
 159                         $level = false;
 160                 }
 161
 162                 $callerDescription = self::getCallerDescription( $callerOffset );
 163
 164                 self::sendMessage( $msg, $callerDescription, 'warning', $level );
 165
 166                 if ( self::$enabled ) {
 167                         self::$log[] = [
 168                                 'msg' => htmlspecialchars( $msg ),
 169                                 'type' => 'warn',
 170                                 'caller' => $callerDescription['func'],
 171                         ];
 172                 }
 173         }
 174
 175         /**
 176          * Show a warning that $function is deprecated.
 177          * This will send it to the following locations:
 178          * - Debug toolbar, with one item per function and caller, if $wgDebugToolbar
 179          *   is set to true.
 180          * - PHP's error log, with level E_USER_DEPRECATED, if $wgDevelopmentWarnings
 181          *   is set to true.
 182          * - MediaWiki's debug log, if $wgDevelopmentWarnings is set to false.
 183          *
 184          * @since 1.19
 185          * @param string $function Function that is deprecated.
 186          * @param string|bool $version Version in which the function was deprecated.
 187          * @param string|bool $component Component to which the function belongs.
 188          *    If false, it is assumbed the function is in MediaWiki core.
 189          * @param int $callerOffset How far up the callstack is the original
 190          *    caller. 2 = function that called the function that called
 191          *    MWDebug::deprecated() (Added in 1.20).
 192          */
 193         public static function deprecated( $function, $version = false,
 194                 $component = false, $callerOffset = 2
 195         ) {
 196                 $callerDescription = self::getCallerDescription( $callerOffset );
 197                 $callerFunc = $callerDescription['func'];
 198
 199                 $sendToLog = true;
 200
 201                 // Check to see if there already was a warning about this function
 202                 if ( isset( self::$deprecationWarnings[$function][$callerFunc] ) ) {
 203                         return;
 204                 } elseif ( isset( self::$deprecationWarnings[$function] ) ) {
 205                         if ( self::$enabled ) {
 206                                 $sendToLog = false;
 207                         } else {
 208                                 return;
 209                         }
 210                 }
 211
 212                 self::$deprecationWarnings[$function][$callerFunc] = true;
 213
 214                 if ( $version ) {
 215                         global $wgDeprecationReleaseLimit;
 216                         if ( $wgDeprecationReleaseLimit && $component === false ) {
 217                                 # Strip -* off the end of $version so that branches can use the
 218                                 # format #.##-branchname to avoid issues if the branch is merged into
 219                                 # a version of MediaWiki later than what it was branched from
 220                                 $comparableVersion = preg_replace( '/-.*$/', '', $version );
 221
 222                                 # If the comparableVersion is larger than our release limit then
 223                                 # skip the warning message for the deprecation
 224                                 if ( version_compare( $wgDeprecationReleaseLimit, $comparableVersion, '<' ) ) {
 225                                         $sendToLog = false;
 226                                 }
 227                         }
 228
 229                         $component = $component === false ? 'MediaWiki' : $component;
 230                         $msg = "Use of $function was deprecated in $component $version.";
 231                 } else {
 232                         $msg = "Use of $function is deprecated.";
 233                 }
 234
 235                 if ( $sendToLog ) {
 236                         global $wgDevelopmentWarnings; // we could have a more specific $wgDeprecationWarnings setting.
 237                         self::sendMessage(
 238                                 $msg,
 239                                 $callerDescription,
 240                                 'deprecated',
 241                                 $wgDevelopmentWarnings ? E_USER_DEPRECATED : false
 242                         );
 243                 }
 244
 245                 if ( self::$enabled ) {
 246                         $logMsg = htmlspecialchars( $msg ) .
 247                                 Html::rawElement( 'div', [ 'class' => 'mw-debug-backtrace' ],
 248                                         Html::element( 'span', [], 'Backtrace:' ) . wfBacktrace()
 249                                 );
 250
 251                         self::$log[] = [
 252                                 'msg' => $logMsg,
 253                                 'type' => 'deprecated',
 254                                 'caller' => $callerFunc,
 255                         ];
 256                 }
 257         }
 258
 259         /**
 260          * Get an array describing the calling function at a specified offset.
 261          *
 262          * @param int $callerOffset How far up the callstack is the original
 263          *    caller. 0 = function that called getCallerDescription()
 264          * @return array Array with two keys: 'file' and 'func'
 265          */
 266         private static function getCallerDescription( $callerOffset ) {
 267                 $callers = wfDebugBacktrace();
 268
 269                 if ( isset( $callers[$callerOffset] ) ) {
 270                         $callerfile = $callers[$callerOffset];
 271                         if ( isset( $callerfile['file'] ) && isset( $callerfile['line'] ) ) {
 272                                 $file = $callerfile['file'] . ' at line ' . $callerfile['line'];
 273                         } else {
 274                                 $file = '(internal function)';
 275                         }
 276                 } else {
 277                         $file = '(unknown location)';
 278                 }
 279
 280                 if ( isset( $callers[$callerOffset + 1] ) ) {
 281                         $callerfunc = $callers[$callerOffset + 1];
 282                         $func = '';
 283                         if ( isset( $callerfunc['class'] ) ) {
 284                                 $func .= $callerfunc['class'] . '::';
 285                         }
 286                         if ( isset( $callerfunc['function'] ) ) {
 287                                 $func .= $callerfunc['function'];
 288                         }
 289                 } else {
 290                         $func = 'unknown';
 291                 }
 292
 293                 return [ 'file' => $file, 'func' => $func ];
 294         }
 295
 296         /**
 297          * Send a message to the debug log and optionally also trigger a PHP
 298          * error, depending on the $level argument.
 299          *
 300          * @param string $msg Message to send
 301          * @param array $caller Caller description get from getCallerDescription()
 302          * @param string $group Log group on which to send the message
 303          * @param int|bool $level Error level to use; set to false to not trigger an error
 304          */
 305         private static function sendMessage( $msg, $caller, $group, $level ) {
 306                 $msg .= ' [Called from ' . $caller['func'] . ' in ' . $caller['file'] . ']';
 307
 308                 if ( $level !== false ) {
 309                         trigger_error( $msg, $level );
 310                 }
 311
 312                 wfDebugLog( $group, $msg, 'private' );
 313         }
 314
 315         /**
 316          * This is a method to pass messages from wfDebug to the pretty debugger.
 317          * Do NOT use this method, use MWDebug::log or wfDebug()
 318          *
 319          * @since 1.19
 320          * @param string $str
 321          * @param array $context
 322          */
 323         public static function debugMsg( $str, $context = [] ) {
 324                 global $wgDebugComments, $wgShowDebug;
 325
 326                 if ( self::$enabled || $wgDebugComments || $wgShowDebug ) {
 327                         if ( $context ) {
 328                                 $prefix = '';
 329                                 if ( isset( $context['prefix'] ) ) {
 330                                         $prefix = $context['prefix'];
 331                                 } elseif ( isset( $context['channel'] ) && $context['channel'] !== 'wfDebug' ) {
 332                                         $prefix = "[{$context['channel']}] ";
 333                                 }
 334                                 if ( isset( $context['seconds_elapsed'] ) && isset( $context['memory_used'] ) ) {
 335                                         $prefix .= "{$context['seconds_elapsed']} {$context['memory_used']}  ";
 336                                 }
 337                                 $str = $prefix . $str;
 338                         }
 339                         self::$debug[] = rtrim( UtfNormal\Validator::cleanUp( $str ) );
 340                 }
 341         }
 342
 343         /**
 344          * Begins profiling on a database query
 345          *
 346          * @since 1.19
 347          * @param string $sql
 348          * @param string $function
 349          * @param bool $isMaster
 350          * @return int ID number of the query to pass to queryTime or -1 if the
 351          *  debugger is disabled
 352          */
 353         public static function query( $sql, $function, $isMaster ) {
 354                 if ( !self::$enabled ) {
 355                         return -1;
 356                 }
 357
 358                 // Replace invalid UTF-8 chars with a square UTF-8 character
 359                 // This prevents json_encode from erroring out due to binary SQL data
 360                 $sql = preg_replace(
 361                         '/(
 362                                 [\xC0-\xC1] # Invalid UTF-8 Bytes
 363                                 | [\xF5-\xFF] # Invalid UTF-8 Bytes
 364                                 | \xE0[\x80-\x9F] # Overlong encoding of prior code point
 365                                 | \xF0[\x80-\x8F] # Overlong encoding of prior code point
 366                                 | [\xC2-\xDF](?![\x80-\xBF]) # Invalid UTF-8 Sequence Start
 367                                 | [\xE0-\xEF](?![\x80-\xBF]{2}) # Invalid UTF-8 Sequence Start
 368                                 | [\xF0-\xF4](?![\x80-\xBF]{3}) # Invalid UTF-8 Sequence Start
 369                                 | (?<=[\x0-\x7F\xF5-\xFF])[\x80-\xBF] # Invalid UTF-8 Sequence Middle
 370                                 | (?<![\xC2-\xDF]|[\xE0-\xEF]|[\xE0-\xEF][\x80-\xBF]|[\xF0-\xF4]
 371                                    |[\xF0-\xF4][\x80-\xBF]|[\xF0-\xF4][\x80-\xBF]{2})[\x80-\xBF] # Overlong Sequence
 372                                 | (?<=[\xE0-\xEF])[\x80-\xBF](?![\x80-\xBF]) # Short 3 byte sequence
 373                                 | (?<=[\xF0-\xF4])[\x80-\xBF](?![\x80-\xBF]{2}) # Short 4 byte sequence
 374                                 | (?<=[\xF0-\xF4][\x80-\xBF])[\x80-\xBF](?![\x80-\xBF]) # Short 4 byte sequence (2)
 375                         )/x',
 376                         '■',
 377                         $sql
 378                 );
 379
 380                 // last check for invalid utf8
 381                 $sql = UtfNormal\Validator::cleanUp( $sql );
 382
 383                 self::$query[] = [
 384                         'sql' => $sql,
 385                         'function' => $function,
 386                         'master' => (bool)$isMaster,
 387                         'time' => 0.0,
 388                         '_start' => microtime( true ),
 389                 ];
 390
 391                 return count( self::$query ) - 1;
 392         }
 393
 394         /**
 395          * Calculates how long a query took.
 396          *
 397          * @since 1.19
 398          * @param int $id
 399          */
 400         public static function queryTime( $id ) {
 401                 if ( $id === -1 || !self::$enabled ) {
 402                         return;
 403                 }
 404
 405                 self::$query[$id]['time'] = microtime( true ) - self::$query[$id]['_start'];
 406                 unset( self::$query[$id]['_start'] );
 407         }
 408
 409         /**
 410          * Returns a list of files included, along with their size
 411          *
 412          * @param IContextSource $context
 413          * @return array
 414          */
 415         protected static function getFilesIncluded( IContextSource $context ) {
 416                 $files = get_included_files();
 417                 $fileList = [];
 418                 foreach ( $files as $file ) {
 419                         $size = filesize( $file );
 420                         $fileList[] = [
 421                                 'name' => $file,
 422                                 'size' => $context->getLanguage()->formatSize( $size ),
 423                         ];
 424                 }
 425
 426                 return $fileList;
 427         }
 428
 429         /**
 430          * Returns the HTML to add to the page for the toolbar
 431          *
 432          * @since 1.19
 433          * @param IContextSource $context
 434          * @return string
 435          */
 436         public static function getDebugHTML( IContextSource $context ) {
 437                 global $wgDebugComments;
 438
 439                 $html = '';
 440
 441                 if ( self::$enabled ) {
 442                         MWDebug::log( 'MWDebug output complete' );
 443                         $debugInfo = self::getDebugInfo( $context );
 444
 445                         // Cannot use OutputPage::addJsConfigVars because those are already outputted
 446                         // by the time this method is called.
 447                         $html = ResourceLoader::makeInlineScript(
 448                                 ResourceLoader::makeConfigSetScript( [ 'debugInfo' => $debugInfo ] )
 449                         );
 450                 }
 451
 452                 if ( $wgDebugComments ) {
 453                         $html .= "<!-- Debug output:\n" .
 454                                 htmlspecialchars( implode( "\n", self::$debug ) ) .
 455                                 "\n\n-->";
 456                 }
 457
 458                 return $html;
 459         }
 460
 461         /**
 462          * Generate debug log in HTML for displaying at the bottom of the main
 463          * content area.
 464          * If $wgShowDebug is false, an empty string is always returned.
 465          *
 466          * @since 1.20
 467          * @return string HTML fragment
 468          */
 469         public static function getHTMLDebugLog() {
 470                 global $wgShowDebug;
 471
 472                 if ( !$wgShowDebug ) {
 473                         return '';
 474                 }
 475
 476                 $ret = "\n<hr />\n<strong>Debug data:</strong><ul id=\"mw-debug-html\">\n";
 477
 478                 foreach ( self::$debug as $line ) {
 479                         $display = nl2br( htmlspecialchars( trim( $line ) ) );
 480
 481                         $ret .= "<li><code>$display</code></li>\n";
 482                 }
 483
 484                 $ret .= '</ul>' . "\n";
 485
 486                 return $ret;
 487         }
 488
 489         /**
 490          * Append the debug info to given ApiResult
 491          *
 492          * @param IContextSource $context
 493          * @param ApiResult $result
 494          */
 495         public static function appendDebugInfoToApiResult( IContextSource $context, ApiResult $result ) {
 496                 if ( !self::$enabled ) {
 497                         return;
 498                 }
 499
 500                 // output errors as debug info, when display_errors is on
 501                 // this is necessary for all non html output of the api, because that clears all errors first
 502                 $obContents = ob_get_contents();
 503                 if ( $obContents ) {
 504                         $obContentArray = explode( '<br />', $obContents );
 505                         foreach ( $obContentArray as $obContent ) {
 506                                 if ( trim( $obContent ) ) {
 507                                         self::debugMsg( Sanitizer::stripAllTags( $obContent ) );
 508                                 }
 509                         }
 510                 }
 511
 512                 MWDebug::log( 'MWDebug output complete' );
 513                 $debugInfo = self::getDebugInfo( $context );
 514
 515                 ApiResult::setIndexedTagName( $debugInfo, 'debuginfo' );
 516                 ApiResult::setIndexedTagName( $debugInfo['log'], 'line' );
 517                 ApiResult::setIndexedTagName( $debugInfo['debugLog'], 'msg' );
 518                 ApiResult::setIndexedTagName( $debugInfo['queries'], 'query' );
 519                 ApiResult::setIndexedTagName( $debugInfo['includes'], 'queries' );
 520                 $result->addValue( null, 'debuginfo', $debugInfo );
 521         }
 522
 523         /**
 524          * Returns the HTML to add to the page for the toolbar
 525          *
 526          * @param IContextSource $context
 527          * @return array
 528          */
 529         public static function getDebugInfo( IContextSource $context ) {
 530                 if ( !self::$enabled ) {
 531                         return [];
 532                 }
 533
 534                 global $wgVersion, $wgRequestTime;
 535                 $request = $context->getRequest();
 536
 537                 // HHVM's reported memory usage from memory_get_peak_usage()
 538                 // is not useful when passing false, but we continue passing
 539                 // false for consistency of historical data in zend.
 540                 // see: https://github.com/facebook/hhvm/issues/2257#issuecomment-39362246
 541                 $realMemoryUsage = wfIsHHVM();
 542
 543                 return [
 544                         'mwVersion' => $wgVersion,
 545                         'phpEngine' => wfIsHHVM() ? 'HHVM' : 'PHP',
 546                         'phpVersion' => wfIsHHVM() ? HHVM_VERSION : PHP_VERSION,
 547                         'gitRevision' => GitInfo::headSHA1(),
 548                         'gitBranch' => GitInfo::currentBranch(),
 549                         'gitViewUrl' => GitInfo::headViewUrl(),
 550                         'time' => microtime( true ) - $wgRequestTime,
 551                         'log' => self::$log,
 552                         'debugLog' => self::$debug,
 553                         'queries' => self::$query,
 554                         'request' => [
 555                                 'method' => $request->getMethod(),
 556                                 'url' => $request->getRequestURL(),
 557                                 'headers' => $request->getAllHeaders(),
 558                                 'params' => $request->getValues(),
 559                         ],
 560                         'memory' => $context->getLanguage()->formatSize( memory_get_usage( $realMemoryUsage ) ),
 561                         'memoryPeak' => $context->getLanguage()->formatSize( memory_get_peak_usage( $realMemoryUsage ) ),
 562                         'includes' => self::getFilesIncluded( $context ),
 563                 ];
 564         }
 565 }