MediaWiki  master
MWExceptionHandler.php
Go to the documentation of this file.
1 <?php
23 use Psr\Log\LogLevel;
24 use Wikimedia\NormalizedException\INormalizedException;
27 
34  public const CAUGHT_BY_HANDLER = 'mwe_handler';
36  public const CAUGHT_BY_ENTRYPOINT = 'entrypoint';
38  public const CAUGHT_BY_OTHER = 'other';
39 
41  protected static $reservedMemory;
42 
53  protected static $fatalErrorTypes = [
54  E_ERROR,
55  E_PARSE,
56  E_CORE_ERROR,
57  E_COMPILE_ERROR,
58  E_USER_ERROR,
59 
60  // E.g. "Catchable fatal error: Argument X must be Y, null given"
61  E_RECOVERABLE_ERROR,
62  ];
63 
69  private static $logExceptionBacktrace = true;
70 
76  private static $propagateErrors;
77 
85  public static function installHandler(
86  bool $logExceptionBacktrace = true,
87  bool $propagateErrors = true
88  ) {
89  self::$logExceptionBacktrace = $logExceptionBacktrace;
90  self::$propagateErrors = $propagateErrors;
91 
92  // This catches:
93  // * Exception objects that were explicitly thrown but not
94  // caught anywhere in the application. This is rare given those
95  // would normally be caught at a high-level like MediaWiki::run (index.php),
96  // api.php, or ResourceLoader::respond (load.php). These high-level
97  // catch clauses would then call MWExceptionHandler::logException
98  // or MWExceptionHandler::handleException.
99  // If they are not caught, then they are handled here.
100  // * Error objects for issues that would historically
101  // cause fatal errors but may now be caught as Throwable (not Exception).
102  // Same as previous case, but more common to bubble to here instead of
103  // caught locally because they tend to not be safe to recover from.
104  // (e.g. argument TypeError, division by zero, etc.)
105  set_exception_handler( 'MWExceptionHandler::handleUncaughtException' );
106 
107  // This catches recoverable errors (e.g. PHP Notice, PHP Warning, PHP Error) that do not
108  // interrupt execution in any way. We log these in the background and then continue execution.
109  set_error_handler( 'MWExceptionHandler::handleError' );
110 
111  // This catches fatal errors for which no Throwable is thrown,
112  // including Out-Of-Memory and Timeout fatals.
113  // Reserve 16k of memory so we can report OOM fatals.
114  self::$reservedMemory = str_repeat( ' ', 16384 );
115  register_shutdown_function( 'MWExceptionHandler::handleFatalError' );
116  }
117 
122  protected static function report( Throwable $e ) {
123  try {
124  // Try and show the exception prettily, with the normal skin infrastructure
125  if ( $e instanceof MWException ) {
126  // Delegate to MWException until all subclasses are handled by
127  // MWExceptionRenderer and MWException::report() has been
128  // removed.
129  $e->report();
130  } else {
132  }
133  } catch ( Throwable $e2 ) {
134  // Exception occurred from within exception handler
135  // Show a simpler message for the original exception,
136  // don't try to invoke report()
138  }
139  }
140 
150  public static function rollbackPrimaryChangesAndLog(
151  Throwable $e,
152  $catcher = self::CAUGHT_BY_OTHER
153  ) {
154  $services = MediaWikiServices::getInstance();
155  if ( !$services->isServiceDisabled( 'DBLoadBalancerFactory' ) ) {
156  // Rollback DBs to avoid transaction notices. This might fail
157  // to rollback some databases due to connection issues or exceptions.
158  // However, any sensible DB driver will rollback implicitly anyway.
159  try {
160  $lbFactory = $services->getDBLoadBalancerFactory();
161  $lbFactory->rollbackPrimaryChanges( __METHOD__ );
162  $lbFactory->flushPrimarySessions( __METHOD__ );
163  } catch ( DBError $e2 ) {
164  // If the DB is unreachable, rollback() will throw an error
165  // and the error report() method might need messages from the DB,
166  // which would result in an exception loop. PHP may escalate such
167  // errors to "Exception thrown without a stack frame" fatals, but
168  // it's better to be explicit here.
169  self::logException( $e2, $catcher );
170  }
171  }
172 
173  self::logException( $e, $catcher );
174  }
175 
181  public static function rollbackMasterChangesAndLog(
182  Throwable $e,
183  $catcher = self::CAUGHT_BY_OTHER
184  ) {
185  wfDeprecated( __METHOD__, '1.37' );
186  self::rollbackPrimaryChangesAndLog( $e, $catcher );
187  }
188 
195  public static function handleUncaughtException( Throwable $e ) {
196  self::handleException( $e, self::CAUGHT_BY_HANDLER );
197 
198  // Make sure we don't claim success on exit for CLI scripts (T177414)
199  if ( wfIsCLI() ) {
200  register_shutdown_function(
204  static function () {
205  exit( 255 );
206  }
207  );
208  }
209  }
210 
226  public static function handleException( Throwable $e, $catcher = self::CAUGHT_BY_OTHER ) {
227  self::rollbackPrimaryChangesAndLog( $e, $catcher );
228  self::report( $e );
229  }
230 
245  public static function handleError(
246  $level,
247  $message,
248  $file = null,
249  $line = null
250  ) {
251  // Map PHP error constant to a PSR-3 severity level.
252  // Avoid use of "DEBUG" or "INFO" levels, unless the
253  // error should evade error monitoring and alerts.
254  //
255  // To decide the log level, ask yourself: "Has the
256  // program's behaviour diverged from what the written
257  // code expected?"
258  //
259  // For example, use of a deprecated method or violating a strict standard
260  // has no impact on functional behaviour (Warning). On the other hand,
261  // accessing an undefined variable makes behaviour diverge from what the
262  // author intended/expected. PHP recovers from an undefined variables by
263  // yielding null and continuing execution, but it remains a change in
264  // behaviour given the null was not part of the code and is likely not
265  // accounted for.
266  switch ( $level ) {
267  case E_WARNING:
268  case E_CORE_WARNING:
269  case E_COMPILE_WARNING:
270  $prefix = 'PHP Warning: ';
271  $severity = LogLevel::ERROR;
272  break;
273  case E_NOTICE:
274  $prefix = 'PHP Notice: ';
275  $severity = LogLevel::ERROR;
276  break;
277  case E_USER_NOTICE:
278  // Used by wfWarn(), MWDebug::warning()
279  $prefix = 'PHP Notice: ';
280  $severity = LogLevel::WARNING;
281  break;
282  case E_USER_WARNING:
283  // Used by wfWarn(), MWDebug::warning()
284  $prefix = 'PHP Warning: ';
285  $severity = LogLevel::WARNING;
286  break;
287  case E_STRICT:
288  $prefix = 'PHP Strict Standards: ';
289  $severity = LogLevel::WARNING;
290  break;
291  case E_DEPRECATED:
292  $prefix = 'PHP Deprecated: ';
293  $severity = LogLevel::WARNING;
294  break;
295  case E_USER_DEPRECATED:
296  $prefix = 'PHP Deprecated: ';
297  $severity = LogLevel::WARNING;
298  $real = MWDebug::parseCallerDescription( $message );
299  if ( $real ) {
300  // Used by wfDeprecated(), MWDebug::deprecated()
301  // Apply caller offset from wfDeprecated() to the native error.
302  // This makes errors easier to aggregate and find in e.g. Kibana.
303  $file = $real['file'];
304  $line = $real['line'];
305  $message = $real['message'];
306  }
307  break;
308  default:
309  $prefix = 'PHP Unknown error: ';
310  $severity = LogLevel::ERROR;
311  break;
312  }
313 
314  // @phan-suppress-next-line PhanTypeMismatchArgumentNullableInternal False positive
315  $e = new ErrorException( $prefix . $message, 0, $level, $file, $line );
316  self::logError( $e, 'error', $severity, self::CAUGHT_BY_HANDLER );
317 
318  // If $propagateErrors is true return false so PHP shows/logs the error normally.
319  // Ignore $propagateErrors if track_errors is set
320  // (which means someone is counting on regular PHP error handling behavior).
321  return !( self::$propagateErrors || ini_get( 'track_errors' ) );
322  }
323 
338  public static function handleFatalError() {
339  // Free reserved memory so that we have space to process OOM
340  // errors
341  self::$reservedMemory = null;
342 
343  $lastError = error_get_last();
344  if ( $lastError === null ) {
345  return false;
346  }
347 
348  $level = $lastError['type'];
349  $message = $lastError['message'];
350  $file = $lastError['file'];
351  $line = $lastError['line'];
352 
353  if ( !in_array( $level, self::$fatalErrorTypes ) ) {
354  // Only interested in fatal errors, others should have been
355  // handled by MWExceptionHandler::handleError
356  return false;
357  }
358 
359  $msgParts = [
360  '[{reqId}] {exception_url} PHP Fatal Error',
361  ( $line || $file ) ? ' from' : '',
362  $line ? " line $line" : '',
363  ( $line && $file ) ? ' of' : '',
364  $file ? " $file" : '',
365  ": $message",
366  ];
367  $msg = implode( '', $msgParts );
368 
369  // Look at message to see if this is a class not found failure (Class 'foo' not found)
370  if ( preg_match( "/Class '\w+' not found/", $message ) ) {
371  // phpcs:disable Generic.Files.LineLength
372  $msg = <<<TXT
373 {$msg}
374 
375 MediaWiki or an installed extension requires this class but it is not embedded directly in MediaWiki's git repository and must be installed separately by the end user.
376 
377 Please see <a href="https://www.mediawiki.org/wiki/Download_from_Git#Fetch_external_libraries">mediawiki.org</a> for help on installing the required components.
378 TXT;
379  // phpcs:enable
380  }
381 
382  $e = new ErrorException( "PHP Fatal Error: {$message}", 0, $level, $file, $line );
383  $logger = LoggerFactory::getInstance( 'exception' );
384  $logger->error( $msg, self::getLogContext( $e, self::CAUGHT_BY_HANDLER ) );
385 
386  return false;
387  }
388 
399  public static function getRedactedTraceAsString( Throwable $e ) {
400  $from = 'from ' . $e->getFile() . '(' . $e->getLine() . ')' . "\n";
401  return $from . self::prettyPrintTrace( self::getRedactedTrace( $e ) );
402  }
403 
412  public static function prettyPrintTrace( array $trace, $pad = '' ) {
413  $text = '';
414 
415  $level = 0;
416  foreach ( $trace as $level => $frame ) {
417  if ( isset( $frame['file'] ) && isset( $frame['line'] ) ) {
418  $text .= "{$pad}#{$level} {$frame['file']}({$frame['line']}): ";
419  } else {
420  // 'file' and 'line' are unset for calls from C code
421  // (T57634) This matches behaviour of
422  // Throwable::getTraceAsString to instead display "[internal
423  // function]".
424  $text .= "{$pad}#{$level} [internal function]: ";
425  }
426 
427  if ( isset( $frame['class'] ) && isset( $frame['type'] ) && isset( $frame['function'] ) ) {
428  $text .= $frame['class'] . $frame['type'] . $frame['function'];
429  } else {
430  $text .= $frame['function'] ?? 'NO_FUNCTION_GIVEN';
431  }
432 
433  if ( isset( $frame['args'] ) ) {
434  $text .= '(' . implode( ', ', $frame['args'] ) . ")\n";
435  } else {
436  $text .= "()\n";
437  }
438  }
439 
440  $level++;
441  $text .= "{$pad}#{$level} {main}";
442 
443  return $text;
444  }
445 
457  public static function getRedactedTrace( Throwable $e ) {
458  return static::redactTrace( $e->getTrace() );
459  }
460 
471  public static function redactTrace( array $trace ) {
472  return array_map( static function ( $frame ) {
473  if ( isset( $frame['args'] ) ) {
474  $frame['args'] = array_map( static function ( $arg ) {
475  return is_object( $arg ) ? get_class( $arg ) : gettype( $arg );
476  }, $frame['args'] );
477  }
478  return $frame;
479  }, $trace );
480  }
481 
489  public static function getURL() {
490  global $wgRequest;
491  if ( !isset( $wgRequest ) || $wgRequest instanceof FauxRequest ) {
492  return false;
493  }
494  return $wgRequest->getRequestURL();
495  }
496 
508  public static function getLogMessage( Throwable $e ) {
509  $id = WebRequest::getRequestId();
510  $type = get_class( $e );
511  $message = $e->getMessage();
512  $url = self::getURL() ?: '[no req]';
513 
514  if ( $e instanceof DBQueryError ) {
515  $message = "A database query error has occurred. Did you forget to run"
516  . " your application's database schema updater after upgrading"
517  . " or after adding a new extension?\n\nPlease see"
518  . " https://www.mediawiki.org/wiki/Special:MyLanguage/Manual:Upgrading and"
519  . " https://www.mediawiki.org/wiki/Special:MyLanguage/Manual:How_to_debug"
520  . " for more information.\n\n"
521  . $message;
522  }
523 
524  return "[$id] $url $type: $message";
525  }
526 
536  public static function getLogNormalMessage( Throwable $e ) {
537  if ( $e instanceof INormalizedException ) {
538  $message = $e->getNormalizedMessage();
539  } else {
540  $message = $e->getMessage();
541  }
542  if ( !$e instanceof ErrorException ) {
543  // ErrorException is something we use internally to represent
544  // PHP errors (runtime warnings that aren't thrown or caught),
545  // don't bother putting it in the logs. Let the log message
546  // lead with "PHP Warning: " instead (see ::handleError).
547  $message = get_class( $e ) . ": $message";
548  }
549 
550  return "[{reqId}] {exception_url} $message";
551  }
552 
557  public static function getPublicLogMessage( Throwable $e ) {
558  $reqId = WebRequest::getRequestId();
559  $type = get_class( $e );
560  return '[' . $reqId . '] '
561  . gmdate( 'Y-m-d H:i:s' ) . ': '
562  . 'Fatal exception of type "' . $type . '"';
563  }
564 
577  public static function getLogContext( Throwable $e, $catcher = self::CAUGHT_BY_OTHER ) {
578  $context = [
579  'exception' => $e,
580  'exception_url' => self::getURL() ?: '[no req]',
581  // The reqId context key use the same familiar name and value as the top-level field
582  // provided by LogstashFormatter. However, formatters are configurable at run-time,
583  // and their top-level fields are logically separate from context keys and cannot be,
584  // substituted in a message, hence set explicitly here. For WMF users, these may feel,
585  // like the same thing due to Monolog V0 handling, which transmits "fields" and "context",
586  // in the same JSON object (after message formatting).
587  'reqId' => WebRequest::getRequestId(),
588  'caught_by' => $catcher
589  ];
590  if ( $e instanceof INormalizedException ) {
591  $context += $e->getMessageContext();
592  }
593  return $context;
594  }
595 
608  public static function getStructuredExceptionData(
609  Throwable $e,
610  $catcher = self::CAUGHT_BY_OTHER
611  ) {
612  $data = [
613  'id' => WebRequest::getRequestId(),
614  'type' => get_class( $e ),
615  'file' => $e->getFile(),
616  'line' => $e->getLine(),
617  'message' => $e->getMessage(),
618  'code' => $e->getCode(),
619  'url' => self::getURL() ?: null,
620  'caught_by' => $catcher
621  ];
622 
623  if ( $e instanceof ErrorException &&
624  ( error_reporting() & $e->getSeverity() ) === 0
625  ) {
626  // Flag suppressed errors
627  $data['suppressed'] = true;
628  }
629 
630  if ( self::$logExceptionBacktrace ) {
631  $data['backtrace'] = self::getRedactedTrace( $e );
632  }
633 
634  $previous = $e->getPrevious();
635  if ( $previous !== null ) {
636  $data['previous'] = self::getStructuredExceptionData( $previous, $catcher );
637  }
638 
639  return $data;
640  }
641 
696  public static function jsonSerializeException(
697  Throwable $e,
698  $pretty = false,
699  $escaping = 0,
700  $catcher = self::CAUGHT_BY_OTHER
701  ) {
702  return FormatJson::encode(
703  self::getStructuredExceptionData( $e, $catcher ),
704  $pretty,
705  $escaping
706  );
707  }
708 
720  public static function logException(
721  Throwable $e,
722  $catcher = self::CAUGHT_BY_OTHER,
723  $extraData = []
724  ) {
725  if ( !( $e instanceof MWException ) || $e->isLoggable() ) {
726  $logger = LoggerFactory::getInstance( 'exception' );
727  $context = self::getLogContext( $e, $catcher );
728  if ( $extraData ) {
729  $context['extraData'] = $extraData;
730  }
731  $logger->error(
732  self::getLogNormalMessage( $e ),
733  $context
734  );
735 
736  $json = self::jsonSerializeException( $e, false, FormatJson::ALL_OK, $catcher );
737  if ( $json !== false ) {
738  $logger = LoggerFactory::getInstance( 'exception-json' );
739  $logger->error( $json, [ 'private' => true ] );
740  }
741 
742  Hooks::runner()->onLogException( $e, false );
743  }
744  }
745 
754  private static function logError(
755  ErrorException $e,
756  $channel,
757  $level,
758  $catcher
759  ) {
760  // The set_error_handler callback is independent from error_reporting.
761  // Filter out unwanted errors manually (e.g. when
762  // AtEase::suppressWarnings is active).
763  $suppressed = ( error_reporting() & $e->getSeverity() ) === 0;
764  if ( !$suppressed ) {
765  $logger = LoggerFactory::getInstance( $channel );
766  $logger->log(
767  $level,
768  self::getLogNormalMessage( $e ),
769  self::getLogContext( $e, $catcher )
770  );
771  }
772 
773  // Include all errors in the json log (suppressed errors will be flagged)
774  $json = self::jsonSerializeException( $e, false, FormatJson::ALL_OK, $catcher );
775  if ( $json !== false ) {
776  $logger = LoggerFactory::getInstance( "{$channel}-json" );
777  // Unlike the 'error' channel, the 'error-json' channel is unfiltered,
778  // and emits messages even if wikimedia/at-ease was used to suppress the
779  // error. To avoid clobbering Logstash dashboards with these, make sure
780  // those have their level casted to DEBUG so that they are excluded by
781  // level-based filters automatically instead of requiring a dedicated filter
782  // for this channel. To be improved: T193472.
783  $unfilteredLevel = $suppressed ? LogLevel::DEBUG : $level;
784  $logger->log( $unfilteredLevel, $json, [ 'private' => true ] );
785  }
786 
787  Hooks::runner()->onLogException( $e, $suppressed );
788  }
789 }
wfDeprecated( $function, $version=false, $component=false, $callerOffset=2)
Logs a warning that a deprecated feature was used.
wfIsCLI()
Check if we are running from the commandline.
global $wgRequest
Definition: Setup.php:377
WebRequest clone which takes values from a provided array.
Definition: FauxRequest.php:37
static encode( $value, $pretty=false, $escaping=0)
Returns the JSON representation of a value.
Definition: FormatJson.php:96
const ALL_OK
Skip escaping as many characters as reasonably possible.
Definition: FormatJson.php:55
static runner()
Get a HookRunner instance for calling hooks using the new interfaces.
Definition: Hooks.php:173
static parseCallerDescription( $msg)
Append a caller description to an error message.
Definition: MWDebug.php:482
Handler class for MWExceptions.
static getLogContext(Throwable $e, $catcher=self::CAUGHT_BY_OTHER)
Get a PSR-3 log event context from a Throwable.
static handleError( $level, $message, $file=null, $line=null)
Handler for set_error_handler() callback notifications.
static rollbackPrimaryChangesAndLog(Throwable $e, $catcher=self::CAUGHT_BY_OTHER)
Roll back any open database transactions and log the stack trace of the throwable.
static installHandler(bool $logExceptionBacktrace=true, bool $propagateErrors=true)
Install handlers with PHP.
static getStructuredExceptionData(Throwable $e, $catcher=self::CAUGHT_BY_OTHER)
Get a structured representation of a Throwable.
static rollbackMasterChangesAndLog(Throwable $e, $catcher=self::CAUGHT_BY_OTHER)
static getRedactedTraceAsString(Throwable $e)
Generate a string representation of a throwable's stack trace.
static report(Throwable $e)
Report a throwable to the user.
static logException(Throwable $e, $catcher=self::CAUGHT_BY_OTHER, $extraData=[])
Log a throwable to the exception log (if enabled).
static array $fatalErrorTypes
Error types that, if unhandled, are fatal to the request.
static getPublicLogMessage(Throwable $e)
static getRedactedTrace(Throwable $e)
Return a copy of a throwable's backtrace as an array.
static handleUncaughtException(Throwable $e)
Callback to use with PHP's set_exception_handler.
static prettyPrintTrace(array $trace, $pad='')
Generate a string representation of a stacktrace.
static string null $reservedMemory
static jsonSerializeException(Throwable $e, $pretty=false, $escaping=0, $catcher=self::CAUGHT_BY_OTHER)
Serialize a Throwable object to JSON.
static getLogMessage(Throwable $e)
Get a message formatting the throwable message and its origin.
static redactTrace(array $trace)
Redact a stacktrace generated by Throwable::getTrace(), debug_backtrace() or similar means.
static handleFatalError()
Callback used as a registered shutdown function.
static getLogNormalMessage(Throwable $e)
Get a normalised message for formatting with PSR-3 log event context.
static getURL()
If the exception occurred in the course of responding to a request, returns the requested URL.
static handleException(Throwable $e, $catcher=self::CAUGHT_BY_OTHER)
Exception handler which simulates the appropriate catch() handling:
static output(Throwable $e, $mode, Throwable $eNew=null)
MediaWiki exception.
Definition: MWException.php:29
PSR-3 logger instance factory.
Service locator for MediaWiki core services.
The MediaWiki class is the helper class for the index.php entry point.
Definition: MediaWiki.php:38
static getRequestId()
Get the current request ID.
Definition: WebRequest.php:343
Database error base class.
Definition: DBError.php:31
$line
Definition: mcc.php:119
if(PHP_SAPI !='cli-server') if(!isset( $_SERVER['SCRIPT_FILENAME'])) $file
Item class for a filearchive table row.
Definition: router.php:42