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