[Summary view] [Print] [Text view]

   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          // Replace invalid UTF-8 chars with a square UTF-8 character
 339          // This prevents json_encode from erroring out due to binary SQL data
 340          $sql = preg_replace(
 341              '/(
 342                  [\xC0-\xC1] # Invalid UTF-8 Bytes
 343                  | [\xF5-\xFF] # Invalid UTF-8 Bytes
 344                  | \xE0[\x80-\x9F] # Overlong encoding of prior code point
 345                  | \xF0[\x80-\x8F] # Overlong encoding of prior code point
 346                  | [\xC2-\xDF](?![\x80-\xBF]) # Invalid UTF-8 Sequence Start
 347                  | [\xE0-\xEF](?![\x80-\xBF]{2}) # Invalid UTF-8 Sequence Start
 348                  | [\xF0-\xF4](?![\x80-\xBF]{3}) # Invalid UTF-8 Sequence Start
 349                  | (?<=[\x0-\x7F\xF5-\xFF])[\x80-\xBF] # Invalid UTF-8 Sequence Middle
 350                  | (?<![\xC2-\xDF]|[\xE0-\xEF]|[\xE0-\xEF][\x80-\xBF]|[\xF0-\xF4]
 351                     |[\xF0-\xF4][\x80-\xBF]|[\xF0-\xF4][\x80-\xBF]{2})[\x80-\xBF] # Overlong Sequence
 352                  | (?<=[\xE0-\xEF])[\x80-\xBF](?![\x80-\xBF]) # Short 3 byte sequence
 353                  | (?<=[\xF0-\xF4])[\x80-\xBF](?![\x80-\xBF]{2}) # Short 4 byte sequence
 354                  | (?<=[\xF0-\xF4][\x80-\xBF])[\x80-\xBF](?![\x80-\xBF]) # Short 4 byte sequence (2)
 355              )/x',
 356              '■',
 357              $sql
 358          );
 359  
 360          self::$query[] = array(
 361              'sql' => $sql,
 362              'function' => $function,
 363              'master' => (bool)$isMaster,
 364              'time' => 0.0,
 365              '_start' => microtime( true ),
 366          );
 367  
 368          return count( self::$query ) - 1;
 369      }
 370  
 371      /**
 372       * Calculates how long a query took.
 373       *
 374       * @since 1.19
 375       * @param int $id
 376       */
 377  	public static function queryTime( $id ) {
 378          if ( $id === -1 || !self::$enabled ) {
 379              return;
 380          }
 381  
 382          self::$query[$id]['time'] = microtime( true ) - self::$query[$id]['_start'];
 383          unset( self::$query[$id]['_start'] );
 384      }
 385  
 386      /**
 387       * Returns a list of files included, along with their size
 388       *
 389       * @param IContextSource $context
 390       * @return array
 391       */
 392  	protected static function getFilesIncluded( IContextSource $context ) {
 393          $files = get_included_files();
 394          $fileList = array();
 395          foreach ( $files as $file ) {
 396              $size = filesize( $file );
 397              $fileList[] = array(
 398                  'name' => $file,
 399                  'size' => $context->getLanguage()->formatSize( $size ),
 400              );
 401          }
 402  
 403          return $fileList;
 404      }
 405  
 406      /**
 407       * Returns the HTML to add to the page for the toolbar
 408       *
 409       * @since 1.19
 410       * @param IContextSource $context
 411       * @return string
 412       */
 413  	public static function getDebugHTML( IContextSource $context ) {
 414          global $wgDebugComments;
 415  
 416          $html = '';
 417  
 418          if ( self::$enabled ) {
 419              MWDebug::log( 'MWDebug output complete' );
 420              $debugInfo = self::getDebugInfo( $context );
 421  
 422              // Cannot use OutputPage::addJsConfigVars because those are already outputted
 423              // by the time this method is called.
 424              $html = Html::inlineScript(
 425                  ResourceLoader::makeLoaderConditionalScript(
 426                      ResourceLoader::makeConfigSetScript( array( 'debugInfo' => $debugInfo ) )
 427                  )
 428              );
 429          }
 430  
 431          if ( $wgDebugComments ) {
 432              $html .= "<!-- Debug output:\n" .
 433                  htmlspecialchars( implode( "\n", self::$debug ) ) .
 434                  "\n\n-->";
 435          }
 436  
 437          return $html;
 438      }
 439  
 440      /**
 441       * Generate debug log in HTML for displaying at the bottom of the main
 442       * content area.
 443       * If $wgShowDebug is false, an empty string is always returned.
 444       *
 445       * @since 1.20
 446       * @return string HTML fragment
 447       */
 448  	public static function getHTMLDebugLog() {
 449          global $wgDebugTimestamps, $wgShowDebug;
 450  
 451          if ( !$wgShowDebug ) {
 452              return '';
 453          }
 454  
 455          $curIdent = 0;
 456          $ret = "\n<hr />\n<strong>Debug data:</strong><ul id=\"mw-debug-html\">\n<li>";
 457  
 458          foreach ( self::$debug as $line ) {
 459              $pre = '';
 460              if ( $wgDebugTimestamps ) {
 461                  $matches = array();
 462                  if ( preg_match( '/^(\d+\.\d+ {1,3}\d+.\dM\s{2})/', $line, $matches ) ) {
 463                      $pre = $matches[1];
 464                      $line = substr( $line, strlen( $pre ) );
 465                  }
 466              }
 467              $display = ltrim( $line );
 468              $ident = strlen( $line ) - strlen( $display );
 469              $diff = $ident - $curIdent;
 470  
 471              $display = $pre . $display;
 472              if ( $display == '' ) {
 473                  $display = "\xc2\xa0";
 474              }
 475  
 476              if ( !$ident
 477                  && $diff < 0
 478                  && substr( $display, 0, 9 ) != 'Entering '
 479                  && substr( $display, 0, 8 ) != 'Exiting '
 480              ) {
 481                  $ident = $curIdent;
 482                  $diff = 0;
 483                  $display = '<span style="background:yellow;">' .
 484                      nl2br( htmlspecialchars( $display ) ) . '</span>';
 485              } else {
 486                  $display = nl2br( htmlspecialchars( $display ) );
 487              }
 488  
 489              if ( $diff < 0 ) {
 490                  $ret .= str_repeat( "</li></ul>\n", -$diff ) . "</li><li>\n";
 491              } elseif ( $diff == 0 ) {
 492                  $ret .= "</li><li>\n";
 493              } else {
 494                  $ret .= str_repeat( "<ul><li>\n", $diff );
 495              }
 496              $ret .= "<code>$display</code>\n";
 497  
 498              $curIdent = $ident;
 499          }
 500  
 501          $ret .= str_repeat( '</li></ul>', $curIdent ) . "</li>\n</ul>\n";
 502  
 503          return $ret;
 504      }
 505  
 506      /**
 507       * Append the debug info to given ApiResult
 508       *
 509       * @param IContextSource $context
 510       * @param ApiResult $result
 511       */
 512  	public static function appendDebugInfoToApiResult( IContextSource $context, ApiResult $result ) {
 513          if ( !self::$enabled ) {
 514              return;
 515          }
 516  
 517          // output errors as debug info, when display_errors is on
 518          // this is necessary for all non html output of the api, because that clears all errors first
 519          $obContents = ob_get_contents();
 520          if ( $obContents ) {
 521              $obContentArray = explode( '<br />', $obContents );
 522              foreach ( $obContentArray as $obContent ) {
 523                  if ( trim( $obContent ) ) {
 524                      self::debugMsg( Sanitizer::stripAllTags( $obContent ) );
 525                  }
 526              }
 527          }
 528  
 529          MWDebug::log( 'MWDebug output complete' );
 530          $debugInfo = self::getDebugInfo( $context );
 531  
 532          $result->setIndexedTagName( $debugInfo, 'debuginfo' );
 533          $result->setIndexedTagName( $debugInfo['log'], 'line' );
 534          $result->setIndexedTagName( $debugInfo['debugLog'], 'msg' );
 535          $result->setIndexedTagName( $debugInfo['queries'], 'query' );
 536          $result->setIndexedTagName( $debugInfo['includes'], 'queries' );
 537          $result->setIndexedTagName( $debugInfo['profile'], 'function' );
 538          $result->addValue( null, 'debuginfo', $debugInfo );
 539      }
 540  
 541      /**
 542       * Returns the HTML to add to the page for the toolbar
 543       *
 544       * @param IContextSource $context
 545       * @return array
 546       */
 547  	public static function getDebugInfo( IContextSource $context ) {
 548          if ( !self::$enabled ) {
 549              return array();
 550          }
 551  
 552          global $wgVersion, $wgRequestTime;
 553          $request = $context->getRequest();
 554  
 555          // HHVM's reported memory usage from memory_get_peak_usage()
 556          // is not useful when passing false, but we continue passing
 557          // false for consistency of historical data in zend.
 558          // see: https://github.com/facebook/hhvm/issues/2257#issuecomment-39362246
 559          $realMemoryUsage = wfIsHHVM();
 560  
 561          return array(
 562              'mwVersion' => $wgVersion,
 563              'phpEngine' => wfIsHHVM() ? 'HHVM' : 'PHP',
 564              'phpVersion' => wfIsHHVM() ? HHVM_VERSION : PHP_VERSION,
 565              'gitRevision' => GitInfo::headSHA1(),
 566              'gitBranch' => GitInfo::currentBranch(),
 567              'gitViewUrl' => GitInfo::headViewUrl(),
 568              'time' => microtime( true ) - $wgRequestTime,
 569              'log' => self::$log,
 570              'debugLog' => self::$debug,
 571              'queries' => self::$query,
 572              'request' => array(
 573                  'method' => $request->getMethod(),
 574                  'url' => $request->getRequestURL(),
 575                  'headers' => $request->getAllHeaders(),
 576                  'params' => $request->getValues(),
 577              ),
 578              'memory' => $context->getLanguage()->formatSize( memory_get_usage( $realMemoryUsage ) ),
 579              'memoryPeak' => $context->getLanguage()->formatSize( memory_get_peak_usage( $realMemoryUsage ) ),
 580              'includes' => self::getFilesIncluded( $context ),
 581              'profile' => Profiler::instance()->getRawData(),
 582          );
 583      }
 584  }