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