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