MediaWiki  master
MWExceptionHandler.php
Go to the documentation of this file.
1 <?php
26 use Psr\Log\LogLevel;
27 use Wikimedia\NormalizedException\INormalizedException;
30 
37  public const CAUGHT_BY_HANDLER = 'mwe_handler';
39  public const CAUGHT_BY_ENTRYPOINT = 'entrypoint';
41  public const CAUGHT_BY_OTHER = 'other';
42 
44  protected static $reservedMemory;
45 
56  protected static $fatalErrorTypes = [
57  E_ERROR,
58  E_PARSE,
59  E_CORE_ERROR,
60  E_COMPILE_ERROR,
61  E_USER_ERROR,
62 
63  // E.g. "Catchable fatal error: Argument X must be Y, null given"
64  E_RECOVERABLE_ERROR,
65  ];
66 
72  private static $logExceptionBacktrace = true;
73 
79  private static $propagateErrors;
80 
88  public static function installHandler(
89  bool $logExceptionBacktrace = true,
90  bool $propagateErrors = true
91  ) {
92  self::$logExceptionBacktrace = $logExceptionBacktrace;
93  self::$propagateErrors = $propagateErrors;
94 
95  // This catches:
96  // * Exception objects that were explicitly thrown but not
97  // caught anywhere in the application. This is rare given those
98  // would normally be caught at a high-level like MediaWiki::run (index.php),
99  // api.php, or ResourceLoader::respond (load.php). These high-level
100  // catch clauses would then call MWExceptionHandler::logException
101  // or MWExceptionHandler::handleException.
102  // If they are not caught, then they are handled here.
103  // * Error objects for issues that would historically
104  // cause fatal errors but may now be caught as Throwable (not Exception).
105  // Same as previous case, but more common to bubble to here instead of
106  // caught locally because they tend to not be safe to recover from.
107  // (e.g. argument TypeError, division by zero, etc.)
108  set_exception_handler( [ self::class, 'handleUncaughtException' ] );
109 
110  // This catches recoverable errors (e.g. PHP Notice, PHP Warning, PHP Error) that do not
111  // interrupt execution in any way. We log these in the background and then continue execution.
112  set_error_handler( [ self::class, 'handleError' ] );
113 
114  // This catches fatal errors for which no Throwable is thrown,
115  // including Out-Of-Memory and Timeout fatals.
116  // Reserve 16k of memory so we can report OOM fatals.
117  self::$reservedMemory = str_repeat( ' ', 16384 );
118  register_shutdown_function( [ self::class, 'handleFatalError' ] );
119  }
120 
125  protected static function report( Throwable $e ) {
126  try {
127  // Try and show the exception prettily, with the normal skin infrastructure
128  if ( $e instanceof MWException ) {
129  // Delegate to MWException until all subclasses are handled by
130  // MWExceptionRenderer and MWException::report() has been
131  // removed.
132  $e->report();
133  } else {
135  }
136  } catch ( Throwable $e2 ) {
137  // Exception occurred from within exception handler
138  // Show a simpler message for the original exception,
139  // don't try to invoke report()
141  }
142  }
143 
149  private static function rollbackPrimaryChanges() {
150  if ( !MediaWikiServices::hasInstance() ) {
151  // MediaWiki isn't fully initialized yet, it's not safe to access services.
152  // This also means that there's nothing to roll back yet.
153  return;
154  }
155 
156  $services = MediaWikiServices::getInstance();
157  if ( $services->isServiceDisabled( 'DBLoadBalancerFactory' ) ) {
158  // The DBLoadBalancerFactory is disabled, possibly because we are in the installer,
159  // or we are in the process of shutting MediaWiki. At this point, any DB transactions
160  // would already have been committed or rolled back.
161  return;
162  }
163 
164  // Roll back DBs to avoid transaction notices. This might fail
165  // to roll back some databases due to connection issues or exceptions.
166  // However, any sensible DB driver will roll back implicitly anyway.
167  try {
168  $lbFactory = $services->getDBLoadBalancerFactory();
169  $lbFactory->rollbackPrimaryChanges( __METHOD__ );
170  $lbFactory->flushPrimarySessions( __METHOD__ );
171  } catch ( DBError $e ) {
172  // If the DB is unreachable, rollback() will throw an error
173  // and the error report() method might need messages from the DB,
174  // which would result in an exception loop. PHP may escalate such
175  // errors to "Exception thrown without a stack frame" fatals, but
176  // it's better to be explicit here.
177  self::logException( $e, self::CAUGHT_BY_HANDLER );
178  }
179  }
180 
190  public static function rollbackPrimaryChangesAndLog(
191  Throwable $e,
192  $catcher = self::CAUGHT_BY_OTHER
193  ) {
194  self::rollbackPrimaryChanges();
195 
196  self::logException( $e, $catcher );
197  }
198 
204  public static function rollbackMasterChangesAndLog(
205  Throwable $e,
206  $catcher = self::CAUGHT_BY_OTHER
207  ) {
208  wfDeprecated( __METHOD__, '1.37' );
209  self::rollbackPrimaryChangesAndLog( $e, $catcher );
210  }
211 
218  public static function handleUncaughtException( Throwable $e ) {
219  self::handleException( $e, self::CAUGHT_BY_HANDLER );
220 
221  // Make sure we don't claim success on exit for CLI scripts (T177414)
222  if ( wfIsCLI() ) {
223  register_shutdown_function(
227  static function () {
228  exit( 255 );
229  }
230  );
231  }
232  }
233 
249  public static function handleException( Throwable $e, $catcher = self::CAUGHT_BY_OTHER ) {
250  self::rollbackPrimaryChangesAndLog( $e, $catcher );
251  self::report( $e );
252  }
253 
268  public static function handleError(
269  $level,
270  $message,
271  $file = null,
272  $line = null
273  ) {
274  // Map PHP error constant to a PSR-3 severity level.
275  // Avoid use of "DEBUG" or "INFO" levels, unless the
276  // error should evade error monitoring and alerts.
277  //
278  // To decide the log level, ask yourself: "Has the
279  // program's behaviour diverged from what the written
280  // code expected?"
281  //
282  // For example, use of a deprecated method or violating a strict standard
283  // has no impact on functional behaviour (Warning). On the other hand,
284  // accessing an undefined variable makes behaviour diverge from what the
285  // author intended/expected. PHP recovers from an undefined variables by
286  // yielding null and continuing execution, but it remains a change in
287  // behaviour given the null was not part of the code and is likely not
288  // accounted for.
289  switch ( $level ) {
290  case E_WARNING:
291  case E_CORE_WARNING:
292  case E_COMPILE_WARNING:
293  $prefix = 'PHP Warning: ';
294  $severity = LogLevel::ERROR;
295  break;
296  case E_NOTICE:
297  $prefix = 'PHP Notice: ';
298  $severity = LogLevel::ERROR;
299  break;
300  case E_USER_NOTICE:
301  // Used by wfWarn(), MWDebug::warning()
302  $prefix = 'PHP Notice: ';
303  $severity = LogLevel::WARNING;
304  break;
305  case E_USER_WARNING:
306  // Used by wfWarn(), MWDebug::warning()
307  $prefix = 'PHP Warning: ';
308  $severity = LogLevel::WARNING;
309  break;
310  case E_STRICT:
311  $prefix = 'PHP Strict Standards: ';
312  $severity = LogLevel::WARNING;
313  break;
314  case E_DEPRECATED:
315  $prefix = 'PHP Deprecated: ';
316  $severity = LogLevel::WARNING;
317  break;
318  case E_USER_DEPRECATED:
319  $prefix = 'PHP Deprecated: ';
320  $severity = LogLevel::WARNING;
321  $real = MWDebug::parseCallerDescription( $message );
322  if ( $real ) {
323  // Used by wfDeprecated(), MWDebug::deprecated()
324  // Apply caller offset from wfDeprecated() to the native error.
325  // This makes errors easier to aggregate and find in e.g. Kibana.
326  $file = $real['file'];
327  $line = $real['line'];
328  $message = $real['message'];
329  }
330  break;
331  default:
332  $prefix = 'PHP Unknown error: ';
333  $severity = LogLevel::ERROR;
334  break;
335  }
336 
337  // @phan-suppress-next-line PhanTypeMismatchArgumentNullableInternal False positive
338  $e = new ErrorException( $prefix . $message, 0, $level, $file, $line );
339  self::logError( $e, 'error', $severity, self::CAUGHT_BY_HANDLER );
340 
341  // If $propagateErrors is true return false so PHP shows/logs the error normally.
342  // Ignore $propagateErrors if track_errors is set
343  // (which means someone is counting on regular PHP error handling behavior).
344  return !( self::$propagateErrors || ini_get( 'track_errors' ) );
345  }
346 
361  public static function handleFatalError() {
362  // Free reserved memory so that we have space to process OOM
363  // errors
364  self::$reservedMemory = null;
365 
366  $lastError = error_get_last();
367  if ( $lastError === null ) {
368  return false;
369  }
370 
371  $level = $lastError['type'];
372  $message = $lastError['message'];
373  $file = $lastError['file'];
374  $line = $lastError['line'];
375 
376  if ( !in_array( $level, self::$fatalErrorTypes ) ) {
377  // Only interested in fatal errors, others should have been
378  // handled by MWExceptionHandler::handleError
379  return false;
380  }
381 
382  $msgParts = [
383  '[{reqId}] {exception_url} PHP Fatal Error',
384  ( $line || $file ) ? ' from' : '',
385  $line ? " line $line" : '',
386  ( $line && $file ) ? ' of' : '',
387  $file ? " $file" : '',
388  ": $message",
389  ];
390  $msg = implode( '', $msgParts );
391 
392  // Look at message to see if this is a class not found failure (Class 'foo' not found)
393  if ( preg_match( "/Class '\w+' not found/", $message ) ) {
394  // phpcs:disable Generic.Files.LineLength
395  $msg = <<<TXT
396 {$msg}
397 
398 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.
399 
400 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.
401 TXT;
402  // phpcs:enable
403  }
404 
405  $e = new ErrorException( "PHP Fatal Error: {$message}", 0, $level, $file, $line );
406  $logger = LoggerFactory::getInstance( 'exception' );
407  $logger->error( $msg, self::getLogContext( $e, self::CAUGHT_BY_HANDLER ) );
408 
409  return false;
410  }
411 
422  public static function getRedactedTraceAsString( Throwable $e ) {
423  $from = 'from ' . $e->getFile() . '(' . $e->getLine() . ')' . "\n";
424  return $from . self::prettyPrintTrace( self::getRedactedTrace( $e ) );
425  }
426 
435  public static function prettyPrintTrace( array $trace, $pad = '' ) {
436  $text = '';
437 
438  $level = 0;
439  foreach ( $trace as $level => $frame ) {
440  if ( isset( $frame['file'] ) && isset( $frame['line'] ) ) {
441  $text .= "{$pad}#{$level} {$frame['file']}({$frame['line']}): ";
442  } else {
443  // 'file' and 'line' are unset for calls from C code
444  // (T57634) This matches behaviour of
445  // Throwable::getTraceAsString to instead display "[internal
446  // function]".
447  $text .= "{$pad}#{$level} [internal function]: ";
448  }
449 
450  if ( isset( $frame['class'] ) && isset( $frame['type'] ) && isset( $frame['function'] ) ) {
451  $text .= $frame['class'] . $frame['type'] . $frame['function'];
452  } else {
453  $text .= $frame['function'] ?? 'NO_FUNCTION_GIVEN';
454  }
455 
456  if ( isset( $frame['args'] ) ) {
457  $text .= '(' . implode( ', ', $frame['args'] ) . ")\n";
458  } else {
459  $text .= "()\n";
460  }
461  }
462 
463  $level++;
464  $text .= "{$pad}#{$level} {main}";
465 
466  return $text;
467  }
468 
480  public static function getRedactedTrace( Throwable $e ) {
481  return static::redactTrace( $e->getTrace() );
482  }
483 
494  public static function redactTrace( array $trace ) {
495  return array_map( static function ( $frame ) {
496  if ( isset( $frame['args'] ) ) {
497  $frame['args'] = array_map( static function ( $arg ) {
498  return is_object( $arg ) ? get_class( $arg ) : gettype( $arg );
499  }, $frame['args'] );
500  }
501  return $frame;
502  }, $trace );
503  }
504 
512  public static function getURL() {
513  global $wgRequest;
514 
515  if ( !isset( $wgRequest ) || $wgRequest instanceof FauxRequest ) {
516  return false;
517  }
518  return $wgRequest->getRequestURL();
519  }
520 
532  public static function getLogMessage( Throwable $e ) {
533  $id = WebRequest::getRequestId();
534  $type = get_class( $e );
535  $message = $e->getMessage();
536  $url = self::getURL() ?: '[no req]';
537 
538  if ( $e instanceof DBQueryError ) {
539  $message = "A database query error has occurred. Did you forget to run"
540  . " your application's database schema updater after upgrading"
541  . " or after adding a new extension?\n\nPlease see"
542  . " https://www.mediawiki.org/wiki/Special:MyLanguage/Manual:Upgrading and"
543  . " https://www.mediawiki.org/wiki/Special:MyLanguage/Manual:How_to_debug"
544  . " for more information.\n\n"
545  . $message;
546  }
547 
548  return "[$id] $url $type: $message";
549  }
550 
560  public static function getLogNormalMessage( Throwable $e ) {
561  if ( $e instanceof INormalizedException ) {
562  $message = $e->getNormalizedMessage();
563  } else {
564  $message = $e->getMessage();
565  }
566  if ( !$e instanceof ErrorException ) {
567  // ErrorException is something we use internally to represent
568  // PHP errors (runtime warnings that aren't thrown or caught),
569  // don't bother putting it in the logs. Let the log message
570  // lead with "PHP Warning: " instead (see ::handleError).
571  $message = get_class( $e ) . ": $message";
572  }
573 
574  return "[{reqId}] {exception_url} $message";
575  }
576 
581  public static function getPublicLogMessage( Throwable $e ) {
582  $reqId = WebRequest::getRequestId();
583  $type = get_class( $e );
584  return '[' . $reqId . '] '
585  . gmdate( 'Y-m-d H:i:s' ) . ': '
586  . 'Fatal exception of type "' . $type . '"';
587  }
588 
601  public static function getLogContext( Throwable $e, $catcher = self::CAUGHT_BY_OTHER ) {
602  $context = [
603  'exception' => $e,
604  'exception_url' => self::getURL() ?: '[no req]',
605  // The reqId context key use the same familiar name and value as the top-level field
606  // provided by LogstashFormatter. However, formatters are configurable at run-time,
607  // and their top-level fields are logically separate from context keys and cannot be,
608  // substituted in a message, hence set explicitly here. For WMF users, these may feel,
609  // like the same thing due to Monolog V0 handling, which transmits "fields" and "context",
610  // in the same JSON object (after message formatting).
611  'reqId' => WebRequest::getRequestId(),
612  'caught_by' => $catcher
613  ];
614  if ( $e instanceof INormalizedException ) {
615  $context += $e->getMessageContext();
616  }
617  return $context;
618  }
619 
632  public static function getStructuredExceptionData(
633  Throwable $e,
634  $catcher = self::CAUGHT_BY_OTHER
635  ) {
636  $data = [
637  'id' => WebRequest::getRequestId(),
638  'type' => get_class( $e ),
639  'file' => $e->getFile(),
640  'line' => $e->getLine(),
641  'message' => $e->getMessage(),
642  'code' => $e->getCode(),
643  'url' => self::getURL() ?: null,
644  'caught_by' => $catcher
645  ];
646 
647  if ( $e instanceof ErrorException &&
648  ( error_reporting() & $e->getSeverity() ) === 0
649  ) {
650  // Flag suppressed errors
651  $data['suppressed'] = true;
652  }
653 
654  if ( self::$logExceptionBacktrace ) {
655  $data['backtrace'] = self::getRedactedTrace( $e );
656  }
657 
658  $previous = $e->getPrevious();
659  if ( $previous !== null ) {
660  $data['previous'] = self::getStructuredExceptionData( $previous, $catcher );
661  }
662 
663  return $data;
664  }
665 
720  public static function jsonSerializeException(
721  Throwable $e,
722  $pretty = false,
723  $escaping = 0,
724  $catcher = self::CAUGHT_BY_OTHER
725  ) {
726  return FormatJson::encode(
727  self::getStructuredExceptionData( $e, $catcher ),
728  $pretty,
729  $escaping
730  );
731  }
732 
744  public static function logException(
745  Throwable $e,
746  $catcher = self::CAUGHT_BY_OTHER,
747  $extraData = []
748  ) {
749  if ( !( $e instanceof MWException ) || $e->isLoggable() ) {
750  $logger = LoggerFactory::getInstance( 'exception' );
751  $context = self::getLogContext( $e, $catcher );
752  if ( $extraData ) {
753  $context['extraData'] = $extraData;
754  }
755  $logger->error(
756  self::getLogNormalMessage( $e ),
757  $context
758  );
759 
760  $json = self::jsonSerializeException( $e, false, FormatJson::ALL_OK, $catcher );
761  if ( $json !== false ) {
762  $logger = LoggerFactory::getInstance( 'exception-json' );
763  $logger->error( $json, [ 'private' => true ] );
764  }
765 
766  ( new HookRunner( MediaWikiServices::getInstance()->getHookContainer() ) )->onLogException( $e, false );
767  }
768  }
769 
778  private static function logError(
779  ErrorException $e,
780  $channel,
781  $level,
782  $catcher
783  ) {
784  // The set_error_handler callback is independent from error_reporting.
785  // Filter out unwanted errors manually (e.g. when
786  // AtEase::suppressWarnings is active).
787  $suppressed = ( error_reporting() & $e->getSeverity() ) === 0;
788  if ( !$suppressed ) {
789  $logger = LoggerFactory::getInstance( $channel );
790  $logger->log(
791  $level,
792  self::getLogNormalMessage( $e ),
793  self::getLogContext( $e, $catcher )
794  );
795  }
796 
797  // Include all errors in the json log (suppressed errors will be flagged)
798  $json = self::jsonSerializeException( $e, false, FormatJson::ALL_OK, $catcher );
799  if ( $json !== false ) {
800  $logger = LoggerFactory::getInstance( "{$channel}-json" );
801  // Unlike the 'error' channel, the 'error-json' channel is unfiltered,
802  // and emits messages even if wikimedia/at-ease was used to suppress the
803  // error. To avoid clobbering Logstash dashboards with these, make sure
804  // those have their level casted to DEBUG so that they are excluded by
805  // level-based filters automatically instead of requiring a dedicated filter
806  // for this channel. To be improved: T193472.
807  $unfilteredLevel = $suppressed ? LogLevel::DEBUG : $level;
808  $logger->log( $unfilteredLevel, $json, [ 'private' => true ] );
809  }
810 
811  ( new HookRunner( MediaWikiServices::getInstance()->getHookContainer() ) )->onLogException( $e, $suppressed );
812  }
813 }
wfIsCLI()
Check if we are running from the commandline.
wfDeprecated( $function, $version=false, $component=false, $callerOffset=2)
Logs a warning that a deprecated feature was used.
global $wgRequest
Definition: Setup.php:414
static encode( $value, $pretty=false, $escaping=0)
Returns the JSON representation of a value.
Definition: FormatJson.php:98
const ALL_OK
Skip escaping as many characters as reasonably possible.
Definition: FormatJson.php:57
static parseCallerDescription( $msg)
Append a caller description to an error message.
Definition: MWDebug.php:486
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:33
This class provides an implementation of the core hook interfaces, forwarding hook calls to HookConta...
Definition: HookRunner.php:568
PSR-3 logger instance factory.
Service locator for MediaWiki core services.
WebRequest clone which takes values from a provided array.
Definition: FauxRequest.php:42
The WebRequest class encapsulates getting at data passed in the URL or via a POSTed form stripping il...
Definition: WebRequest.php:50
The MediaWiki class is the helper class for the index.php entry point.
Definition: MediaWiki.php:50
Database error base class.
Definition: DBError.php:37
if(PHP_SAPI !='cli-server') if(!isset( $_SERVER['SCRIPT_FILENAME'])) $file
Item class for a filearchive table row.
Definition: router.php:42