MWExceptionHandler.php

Go to the documentation of this file.

<?php
use MediaWiki\Logger\LoggerFactory;
use MediaWiki\MediaWikiServices;

class MWExceptionHandler {

    protected static $reservedMemory;
    protected static $fatalErrorTypes = [
        E_ERROR, E_PARSE, E_CORE_ERROR, E_COMPILE_ERROR, E_USER_ERROR,
        /* HHVM's FATAL_ERROR level */ 16777217,
    ];
    protected static $handledFatalCallback = false;

    public static function installHandler() {
        set_exception_handler( 'MWExceptionHandler::handleException' );
        set_error_handler( 'MWExceptionHandler::handleError' );

        // Reserve 16k of memory so we can report OOM fatals
        self::$reservedMemory = str_repeat( ' ', 16384 );
        register_shutdown_function( 'MWExceptionHandler::handleFatalError' );
    }

    protected static function report( $e ) {
        try {
            // Try and show the exception prettily, with the normal skin infrastructure
            if ( $e instanceof MWException ) {
                // Delegate to MWException until all subclasses are handled by
                // MWExceptionRenderer and MWException::report() has been
                // removed.
                $e->report();
            } else {
                MWExceptionRenderer::output( $e, MWExceptionRenderer::AS_PRETTY );
            }
        } catch ( Exception $e2 ) {
            // Exception occurred from within exception handler
            // Show a simpler message for the original exception,
            // don't try to invoke report()
            MWExceptionRenderer::output( $e, MWExceptionRenderer::AS_RAW, $e2 );
        }
    }

    public static function rollbackMasterChangesAndLog( $e ) {
        $services = MediaWikiServices::getInstance();
        if ( $services->isServiceDisabled( 'DBLoadBalancerFactory' ) ) {
            return; // T147599
        }

        $lbFactory = $services->getDBLoadBalancerFactory();
        if ( $lbFactory->hasMasterChanges() ) {
            $logger = LoggerFactory::getInstance( 'Bug56269' );
            $logger->warning(
                'Exception thrown with an uncommited database transaction: ' .
                self::getLogMessage( $e ),
                self::getLogContext( $e )
            );
        }
        $lbFactory->rollbackMasterChanges( __METHOD__ );
    }

    public static function handleException( $e ) {
        try {
            // Rollback DBs to avoid transaction notices. This may fail
            // to rollback some DB due to connection issues or exceptions.
            // However, any sane DB driver will rollback implicitly anyway.
            self::rollbackMasterChangesAndLog( $e );
        } catch ( DBError $e2 ) {
            // If the DB is unreacheable, rollback() will throw an error
            // and the error report() method might need messages from the DB,
            // which would result in an exception loop. PHP may escalate such
            // errors to "Exception thrown without a stack frame" fatals, but
            // it's better to be explicit here.
            self::logException( $e2 );
        }

        self::logException( $e );
        self::report( $e );

        // Exit value should be nonzero for the benefit of shell jobs
        exit( 1 );
    }

    public static function handleError(
        $level, $message, $file = null, $line = null
    ) {
        if ( in_array( $level, self::$fatalErrorTypes ) ) {
            return call_user_func_array(
                'MWExceptionHandler::handleFatalError', func_get_args()
            );
        }

        // Map error constant to error name (reverse-engineer PHP error
        // reporting)
        switch ( $level ) {
            case E_RECOVERABLE_ERROR:
                $levelName = 'Error';
                break;
            case E_WARNING:
            case E_CORE_WARNING:
            case E_COMPILE_WARNING:
            case E_USER_WARNING:
                $levelName = 'Warning';
                break;
            case E_NOTICE:
            case E_USER_NOTICE:
                $levelName = 'Notice';
                break;
            case E_STRICT:
                $levelName = 'Strict Standards';
                break;
            case E_DEPRECATED:
            case E_USER_DEPRECATED:
                $levelName = 'Deprecated';
                break;
            default:
                $levelName = 'Unknown error';
                break;
        }

        $e = new ErrorException( "PHP $levelName: $message", 0, $level, $file, $line );
        self::logError( $e, 'error' );

        // This handler is for logging only. Return false will instruct PHP
        // to continue regular handling.
        return false;
    }

    public static function handleFatalError(
        $level = null, $message = null, $file = null, $line = null,
        $context = null, $trace = null
    ) {
        // Free reserved memory so that we have space to process OOM
        // errors
        self::$reservedMemory = null;

        if ( $level === null ) {
            // Called as a shutdown handler, get data from error_get_last()
            if ( static::$handledFatalCallback ) {
                // Already called once (probably as an error handler callback
                // under HHVM) so don't log again.
                return false;
            }

            $lastError = error_get_last();
            if ( $lastError !== null ) {
                $level = $lastError['type'];
                $message = $lastError['message'];
                $file = $lastError['file'];
                $line = $lastError['line'];
            } else {
                $level = 0;
                $message = '';
            }
        }

        if ( !in_array( $level, self::$fatalErrorTypes ) ) {
            // Only interested in fatal errors, others should have been
            // handled by MWExceptionHandler::handleError
            return false;
        }

        $msg = "[{exception_id}] PHP Fatal Error: {$message}";

        // Look at message to see if this is a class not found failure
        // HHVM: Class undefined: foo
        // PHP5: Class 'foo' not found
        if ( preg_match( "/Class (undefined: \w+|'\w+' not found)/", $msg ) ) {
            // @codingStandardsIgnoreStart Generic.Files.LineLength.TooLong
            $msg = <<<TXT
{$msg}

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.

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.
TXT;
            // @codingStandardsIgnoreEnd
        }

        // We can't just create an exception and log it as it is likely that
        // the interpreter has unwound the stack already. If that is true the
        // stacktrace we would get would be functionally empty. If however we
        // have been called as an error handler callback *and* HHVM is in use
        // we will have been provided with a useful stacktrace that we can
        // log.
        $trace = $trace ?: debug_backtrace();
        $logger = LoggerFactory::getInstance( 'fatal' );
        $logger->error( $msg, [
            'exception' => [
                'class' => 'ErrorException',
                'message' => "PHP Fatal Error: {$message}",
                'code' => $level,
                'file' => $file,
                'line' => $line,
                'trace' => static::redactTrace( $trace ),
            ],
            'exception_id' => wfRandomString( 8 ),
        ] );

        // Remember call so we don't double process via HHVM's fatal
        // notifications and the shutdown hook behavior
        static::$handledFatalCallback = true;
        return false;
    }

    public static function getRedactedTraceAsString( $e ) {
        return self::prettyPrintTrace( self::getRedactedTrace( $e ) );
    }

    public static function prettyPrintTrace( array $trace, $pad = '' ) {
        $text = '';

        $level = 0;
        foreach ( $trace as $level => $frame ) {
            if ( isset( $frame['file'] ) && isset( $frame['line'] ) ) {
                $text .= "{$pad}#{$level} {$frame['file']}({$frame['line']}): ";
            } else {
                // 'file' and 'line' are unset for calls via call_user_func
                // (bug 55634) This matches behaviour of
                // Exception::getTraceAsString to instead display "[internal
                // function]".
                $text .= "{$pad}#{$level} [internal function]: ";
            }

            if ( isset( $frame['class'] ) && isset( $frame['type'] ) && isset( $frame['function'] ) ) {
                $text .= $frame['class'] . $frame['type'] . $frame['function'];
            } elseif ( isset( $frame['function'] ) ) {
                $text .= $frame['function'];
            } else {
                $text .= 'NO_FUNCTION_GIVEN';
            }

            if ( isset( $frame['args'] ) ) {
                $text .= '(' . implode( ', ', $frame['args'] ) . ")\n";
            } else {
                $text .= "()\n";
            }
        }

        $level = $level + 1;
        $text .= "{$pad}#{$level} {main}";

        return $text;
    }

    public static function getRedactedTrace( $e ) {
        return static::redactTrace( $e->getTrace() );
    }

    public static function redactTrace( array $trace ) {
        return array_map( function ( $frame ) {
            if ( isset( $frame['args'] ) ) {
                $frame['args'] = array_map( function ( $arg ) {
                    return is_object( $arg ) ? get_class( $arg ) : gettype( $arg );
                }, $frame['args'] );
            }
            return $frame;
        }, $trace );
    }

    public static function getLogId( $e ) {
        wfDeprecated( __METHOD__, '1.27' );
        return WebRequest::getRequestId();
    }

    public static function getURL() {
        global $wgRequest;
        if ( !isset( $wgRequest ) || $wgRequest instanceof FauxRequest ) {
            return false;
        }
        return $wgRequest->getRequestURL();
    }

    public static function getLogMessage( $e ) {
        $id = WebRequest::getRequestId();
        $type = get_class( $e );
        $file = $e->getFile();
        $line = $e->getLine();
        $message = $e->getMessage();
        $url = self::getURL() ?: '[no req]';

        return "[$id] $url   $type from line $line of $file: $message";
    }

    public static function getPublicLogMessage( $e ) {
        $reqId = WebRequest::getRequestId();
        $type = get_class( $e );
        return '[' . $reqId . '] '
            . gmdate( 'Y-m-d H:i:s' ) . ': '
            . 'Fatal exception of type "' . $type . '"';
    }

    public static function getLogContext( $e ) {
        return [
            'exception' => $e,
            'exception_id' => WebRequest::getRequestId(),
        ];
    }

    public static function getStructuredExceptionData( $e ) {
        global $wgLogExceptionBacktrace;
        $data = [
            'id' => WebRequest::getRequestId(),
            'type' => get_class( $e ),
            'file' => $e->getFile(),
            'line' => $e->getLine(),
            'message' => $e->getMessage(),
            'code' => $e->getCode(),
            'url' => self::getURL() ?: null,
        ];

        if ( $e instanceof ErrorException &&
            ( error_reporting() & $e->getSeverity() ) === 0
        ) {
            // Flag surpressed errors
            $data['suppressed'] = true;
        }

        if ( $wgLogExceptionBacktrace ) {
            $data['backtrace'] = self::getRedactedTrace( $e );
        }

        $previous = $e->getPrevious();
        if ( $previous !== null ) {
            $data['previous'] = self::getStructuredExceptionData( $previous );
        }

        return $data;
    }

    public static function jsonSerializeException( $e, $pretty = false, $escaping = 0 ) {
        $data = self::getStructuredExceptionData( $e );
        return FormatJson::encode( $data, $pretty, $escaping );
    }

    public static function logException( $e ) {
        if ( !( $e instanceof MWException ) || $e->isLoggable() ) {
            $logger = LoggerFactory::getInstance( 'exception' );
            $logger->error(
                self::getLogMessage( $e ),
                self::getLogContext( $e )
            );

            $json = self::jsonSerializeException( $e, false, FormatJson::ALL_OK );
            if ( $json !== false ) {
                $logger = LoggerFactory::getInstance( 'exception-json' );
                $logger->error( $json, [ 'private' => true ] );
            }

            Hooks::run( 'LogException', [ $e, false ] );
        }
    }

    protected static function logError( ErrorException $e, $channel ) {
        // The set_error_handler callback is independent from error_reporting.
        // Filter out unwanted errors manually (e.g. when
        // MediaWiki\suppressWarnings is active).
        $suppressed = ( error_reporting() & $e->getSeverity() ) === 0;
        if ( !$suppressed ) {
            $logger = LoggerFactory::getInstance( $channel );
            $logger->error(
                self::getLogMessage( $e ),
                self::getLogContext( $e )
            );
        }

        // Include all errors in the json log (surpressed errors will be flagged)
        $json = self::jsonSerializeException( $e, false, FormatJson::ALL_OK );
        if ( $json !== false ) {
            $logger = LoggerFactory::getInstance( "{$channel}-json" );
            $logger->error( $json, [ 'private' => true ] );
        }

        Hooks::run( 'LogException', [ $e, $suppressed ] );
    }
}