logger: Produce traces for all Throwables
authorBrad Jorsch <bjorsch@wikimedia.org>
Thu, 23 May 2019 14:19:06 +0000 (10:19 -0400)
committerBrad Jorsch <bjorsch@wikimedia.org>
Thu, 23 May 2019 14:39:39 +0000 (10:39 -0400)
The code was checking for `Exception` to decide whether to produce traces,
so it wasn't providing them for PHP 7's new Errors. The code itself
works fine with any Throwable.

We have to keep parallel checks for Exception too for the time being,
because HHVM as used in Wikimedia production doesn't have Throwable.

Bug: T187147
Change-Id: Iec8a6718beb7ec09e45e332ee5762d0644ce17ab

includes/debug/logger/LegacyLogger.php
includes/debug/logger/monolog/LineFormatter.php
tests/phpunit/includes/debug/logger/LegacyLoggerTest.php
tests/phpunit/includes/debug/logger/monolog/LineFormatterTest.php

index bbcd33a..72c7643 100644 (file)
 namespace MediaWiki\Logger;
 
 use DateTimeZone;
+use Error;
 use Exception;
 use WikiMap;
 use MWDebug;
 use MWExceptionHandler;
 use Psr\Log\AbstractLogger;
 use Psr\Log\LogLevel;
+use Throwable;
 use UDPTransport;
 
 /**
@@ -269,7 +271,7 @@ class LegacyLogger extends AbstractLogger {
                        $e = $context['exception'];
                        $backtrace = false;
 
-                       if ( $e instanceof Exception ) {
+                       if ( $e instanceof Throwable || $e instanceof Exception ) {
                                $backtrace = MWExceptionHandler::getRedactedTrace( $e );
 
                        } elseif ( is_array( $e ) && isset( $e['trace'] ) ) {
@@ -405,8 +407,9 @@ class LegacyLogger extends AbstractLogger {
                        return $item->format( 'c' );
                }
 
-               if ( $item instanceof Exception ) {
-                       return '[Exception ' . get_class( $item ) . '( ' .
+               if ( $item instanceof Throwable || $item instanceof Exception ) {
+                       $which = $item instanceof Error ? 'Error' : 'Exception';
+                       return '[' . $which . ' ' . get_class( $item ) . '( ' .
                                $item->getFile() . ':' . $item->getLine() . ') ' .
                                $item->getMessage() . ']';
                }
index 8537d71..d0748bc 100644 (file)
 
 namespace MediaWiki\Logger\Monolog;
 
+use Error;
 use Exception;
 use Monolog\Formatter\LineFormatter as MonologLineFormatter;
 use MWExceptionHandler;
+use Throwable;
 
 /**
  * Formats incoming records into a one-line string.
@@ -32,7 +34,7 @@ use MWExceptionHandler;
  * excluded from '%context%' output if the '%exception%' placeholder is
  * present.
  *
- * Exceptions that are logged with this formatter will optional have their
+ * Throwables that are logged with this formatter will optional have their
  * stack traces appended. If that is done, MWExceptionHandler::redactedTrace()
  * will be used to redact the trace information.
  *
@@ -75,7 +77,7 @@ class LineFormatter extends MonologLineFormatter {
                        $e = $record['context']['exception'];
                        unset( $record['context']['exception'] );
 
-                       if ( $e instanceof Exception ) {
+                       if ( $e instanceof Throwable || $e instanceof Exception ) {
                                $prettyException = $this->normalizeException( $e );
                        } elseif ( is_array( $e ) ) {
                                $prettyException = $this->normalizeExceptionArray( $e );
@@ -93,9 +95,9 @@ class LineFormatter extends MonologLineFormatter {
        }
 
        /**
-        * Convert an Exception to a string.
+        * Convert a Throwable to a string.
         *
-        * @param Exception $e
+        * @param Exception|Throwable $e
         * @return string
         */
        protected function normalizeException( $e ) {
@@ -103,12 +105,12 @@ class LineFormatter extends MonologLineFormatter {
        }
 
        /**
-        * Convert an exception to an array of structured data.
+        * Convert a throwable to an array of structured data.
         *
-        * @param Exception $e
+        * @param Exception|Throwable $e
         * @return array
         */
-       protected function exceptionAsArray( Exception $e ) {
+       protected function exceptionAsArray( $e ) {
                $out = [
                        'class' => get_class( $e ),
                        'message' => $e->getMessage(),
@@ -127,7 +129,7 @@ class LineFormatter extends MonologLineFormatter {
        }
 
        /**
-        * Convert an array of Exception data to a string.
+        * Convert an array of Throwable data to a string.
         *
         * @param array $e
         * @return string
@@ -142,7 +144,8 @@ class LineFormatter extends MonologLineFormatter {
                ];
                $e = array_merge( $defaults, $e );
 
-               $str = "\n[Exception {$e['class']}] (" .
+               $which = is_a( $e['class'], Error::class, true ) ? 'Error' : 'Exception';
+               $str = "\n[$which {$e['class']}] (" .
                        "{$e['file']}:{$e['line']}) {$e['message']}";
 
                if ( $this->includeStacktraces && $e['trace'] ) {
@@ -154,7 +157,8 @@ class LineFormatter extends MonologLineFormatter {
                        $prev = $e['previous'];
                        while ( $prev ) {
                                $prev = array_merge( $defaults, $prev );
-                               $str .= "\nCaused by: [Exception {$prev['class']}] (" .
+                               $which = is_a( $prev['class'], Error::class, true ) ? 'Error' : 'Exception';
+                               $str .= "\nCaused by: [$which {$prev['class']}] (" .
                                        "{$prev['file']}:{$prev['line']}) {$prev['message']}";
 
                                if ( $this->includeStacktraces && $prev['trace'] ) {
index 37a28c3..6c2fdda 100644 (file)
@@ -124,6 +124,26 @@ class LegacyLoggerTest extends MediaWikiTestCase {
                ];
        }
 
+       /**
+        * @covers MediaWiki\Logger\LegacyLogger::interpolate
+        */
+       public function testInterpolate_Error() {
+               // @todo Merge this into provideInterpolate once we drop HHVM support
+               if ( !class_exists( \Error::class ) ) {
+                       $this->markTestSkipped( 'Error class does not exist' );
+               }
+
+               $err = new \Error( 'Test error' );
+               $message = '{exception}';
+               $context = [ 'exception' => $err ];
+               $expect = '[Error ' . get_class( $err ) . '( ' .
+                       $err->getFile() . ':' . $err->getLine() . ') ' .
+                       $err->getMessage() . ']';
+
+               $this->assertEquals(
+                       $expect, LegacyLogger::interpolate( $message, $context ) );
+       }
+
        /**
         * @covers MediaWiki\Logger\LegacyLogger::shouldEmit
         * @dataProvider provideShouldEmit
index 2768d32..bdd5c81 100644 (file)
@@ -20,6 +20,7 @@
 
 namespace MediaWiki\Logger\Monolog;
 
+use AssertionError;
 use InvalidArgumentException;
 use LengthException;
 use LogicException;
@@ -72,4 +73,50 @@ class LineFormatterTest extends MediaWikiTestCase {
                $this->assertContains( "\nCaused by: [Exception LogicException]", $out );
                $this->assertContains( "\n  #0", $out );
        }
+
+       /**
+        * @covers MediaWiki\Logger\Monolog\LineFormatter::normalizeException
+        */
+       public function testNormalizeExceptionErrorNoTrace() {
+               if ( !class_exists( AssertionError::class ) ) {
+                       $this->markTestSkipped( 'AssertionError class does not exist' );
+               }
+
+               $fixture = new LineFormatter();
+               $fixture->includeStacktraces( false );
+               $fixture = TestingAccessWrapper::newFromObject( $fixture );
+               $boom = new InvalidArgumentException( 'boom', 0,
+                       new LengthException( 'too long', 0,
+                               new AssertionError( 'Spock wuz here' )
+                       )
+               );
+               $out = $fixture->normalizeException( $boom );
+               $this->assertContains( "\n[Exception InvalidArgumentException]", $out );
+               $this->assertContains( "\nCaused by: [Exception LengthException]", $out );
+               $this->assertContains( "\nCaused by: [Error AssertionError]", $out );
+               $this->assertNotContains( "\n  #0", $out );
+       }
+
+       /**
+        * @covers MediaWiki\Logger\Monolog\LineFormatter::normalizeException
+        */
+       public function testNormalizeExceptionErrorTrace() {
+               if ( !class_exists( AssertionError::class ) ) {
+                       $this->markTestSkipped( 'AssertionError class does not exist' );
+               }
+
+               $fixture = new LineFormatter();
+               $fixture->includeStacktraces( true );
+               $fixture = TestingAccessWrapper::newFromObject( $fixture );
+               $boom = new InvalidArgumentException( 'boom', 0,
+                       new LengthException( 'too long', 0,
+                               new AssertionError( 'Spock wuz here' )
+                       )
+               );
+               $out = $fixture->normalizeException( $boom );
+               $this->assertContains( "\n[Exception InvalidArgumentException]", $out );
+               $this->assertContains( "\nCaused by: [Exception LengthException]", $out );
+               $this->assertContains( "\nCaused by: [Error AssertionError]", $out );
+               $this->assertContains( "\n  #0", $out );
+       }
 }