From 2dadb9e2b0ba26223ed83a30af620ce3e62e245f Mon Sep 17 00:00:00 2001 From: Moti Zilberman Date: Wed, 31 Jul 2019 02:28:40 -0700 Subject: [PATCH] Move React error message formatting into ExceptionsManager Summary: # Context In https://github.com/facebook/react/pull/16141 we imported `ReactFiberErrorDialog` unchanged from React. That implementation was not idempotent: if passed the same error instance multiple times, it would amend its `message` property every time, eventually leading to bloat and low-signal logs. The message bloat problem is most evident when rendering multiple `lazy()` components that expose the same Error reference to React (e.g. due to some cache that vends the same rejected Promise multiple times). More broadly, there's a need for structured, machine-readable logging to replace stringly-typed interfaces in both the production and development use cases. # This diff * We leave the user-supplied `message` field intact and instead do all the formatting inside `ExceptionsManager`. To avoid needless complexity, this **doesn't** always have the exact same output as the old code (but it does come close). See tests for the specifics. * The only mutation we do on React-captured error instances is setting the `componentStack` expando property. This replaces any previously-captured component stack rather than adding to it, and so doesn't create bloat. * We also report the exception fields `componentStack`, unformatted `message` (as `originalMessage`) and `name` directly to `NativeExceptionsManager` for future use. Reviewed By: cpojer Differential Revision: D16331228 fbshipit-source-id: 7b0539c2c83c7dd4e56db8508afcf367931ac71d --- Libraries/Core/Devtools/parseErrorStack.js | 1 + Libraries/Core/ExceptionsManager.js | 49 ++++++-- Libraries/Core/NativeExceptionsManager.js | 3 + Libraries/Core/ReactFiberErrorDialog.js | 32 +++--- .../Core/__tests__/ExceptionsManager-test.js | 106 ++++++++++++++++-- .../FBReactNativeSpec/FBReactNativeSpec.h | 18 +++ .../RCTLoggingTests.m | 4 +- 7 files changed, 171 insertions(+), 42 deletions(-) diff --git a/Libraries/Core/Devtools/parseErrorStack.js b/Libraries/Core/Devtools/parseErrorStack.js index e3f4317a67cce5..6c9ffb710e4953 100644 --- a/Libraries/Core/Devtools/parseErrorStack.js +++ b/Libraries/Core/Devtools/parseErrorStack.js @@ -16,6 +16,7 @@ export type ExtendedError = Error & { framesToPop?: number, jsEngine?: string, preventSymbolication?: boolean, + componentStack?: string, }; function parseErrorStack(e: ExtendedError): Array { diff --git a/Libraries/Core/ExceptionsManager.js b/Libraries/Core/ExceptionsManager.js index d9a8157fd2513d..0521548dcae180 100644 --- a/Libraries/Core/ExceptionsManager.js +++ b/Libraries/Core/ExceptionsManager.js @@ -12,6 +12,10 @@ import type {ExtendedError} from './Devtools/parseErrorStack'; +class SyntheticError extends Error { + name = ''; +} + /** * Handles the developer-visible aspect of errors and exceptions */ @@ -22,10 +26,35 @@ function reportException(e: ExtendedError, isFatal: boolean) { const parseErrorStack = require('./Devtools/parseErrorStack'); const stack = parseErrorStack(e); const currentExceptionID = ++exceptionID; - const message = - e.jsEngine == null ? e.message : `${e.message}, js engine: ${e.jsEngine}`; + const originalMessage = e.message || ''; + let message = originalMessage; + if (e.componentStack != null) { + message += `\n\nThis error is located at:${e.componentStack}`; + } + const namePrefix = e.name == null || e.name === '' ? '' : `${e.name}: `; + const isFromConsoleError = e.name === 'console.error'; + + if (!message.startsWith(namePrefix)) { + message = namePrefix + message; + } + + // Errors created by `console.error` have already been printed. + if (!isFromConsoleError) { + if (console._errorOriginal) { + console._errorOriginal(message); + } else { + console.error(message); + } + } + + message = + e.jsEngine == null ? message : `${message}, js engine: ${e.jsEngine}`; NativeExceptionsManager.reportException({ message, + originalMessage: message === originalMessage ? null : originalMessage, + name: e.name == null || e.name === '' ? null : e.name, + componentStack: + typeof e.componentStack === 'string' ? e.componentStack : null, stack, id: currentExceptionID, isFatal, @@ -77,25 +106,22 @@ function handleException(e: Error, isFatal: boolean) { // `throw ''` somewhere in your codebase. if (!e.message) { // $FlowFixMe - cannot reassign constant, explanation above - e = new Error(e); - } - if (console._errorOriginal) { - console._errorOriginal(e.message); - } else { - console.error(e.message); + e = new SyntheticError(e); } reportException(e, isFatal); } function reactConsoleErrorHandler() { - console._errorOriginal.apply(console, arguments); if (!console.reportErrorsAsExceptions) { + console._errorOriginal.apply(console, arguments); return; } if (arguments[0] && arguments[0].stack) { + // reportException will console.error this with high enough fidelity. reportException(arguments[0], /* isFatal */ false); } else { + console._errorOriginal.apply(console, arguments); const stringifySafe = require('../Utilities/stringifySafe'); const str = Array.prototype.map.call(arguments, stringifySafe).join(', '); if (str.slice(0, 10) === '"Warning: ') { @@ -104,7 +130,8 @@ function reactConsoleErrorHandler() { // (Note: Logic duplicated in polyfills/console.js.) return; } - const error: ExtendedError = new Error('console.error: ' + str); + const error: ExtendedError = new SyntheticError(str); + error.name = 'console.error'; error.framesToPop = 1; reportException(error, /* isFatal */ false); } @@ -129,4 +156,4 @@ function installConsoleErrorReporter() { } } -module.exports = {handleException, installConsoleErrorReporter}; +module.exports = {handleException, installConsoleErrorReporter, SyntheticError}; diff --git a/Libraries/Core/NativeExceptionsManager.js b/Libraries/Core/NativeExceptionsManager.js index 525d020d06960f..7ec74bfb003e3d 100644 --- a/Libraries/Core/NativeExceptionsManager.js +++ b/Libraries/Core/NativeExceptionsManager.js @@ -23,6 +23,9 @@ export type StackFrame = {| export type ExceptionData = { message: string, + originalMessage: ?string, + name: ?string, + componentStack: ?string, stack: Array, id: number, isFatal: boolean, diff --git a/Libraries/Core/ReactFiberErrorDialog.js b/Libraries/Core/ReactFiberErrorDialog.js index 5d798d4647acd7..936f716e6a507d 100644 --- a/Libraries/Core/ReactFiberErrorDialog.js +++ b/Libraries/Core/ReactFiberErrorDialog.js @@ -5,7 +5,7 @@ * LICENSE file in the root directory of this source tree. * * @format - * @flow strict-local + * @flow */ export type CapturedError = { @@ -18,36 +18,30 @@ export type CapturedError = { +willRetry: boolean, }; -import {handleException} from './ExceptionsManager'; +import type {ExtendedError} from './Devtools/parseErrorStack'; + +import {handleException, SyntheticError} from './ExceptionsManager'; /** * Intercept lifecycle errors and ensure they are shown with the correct stack * trace within the native redbox component. */ -export function showErrorDialog(capturedError: CapturedError): boolean { +function showErrorDialog(capturedError: CapturedError): boolean { const {componentStack, error} = capturedError; - let errorToHandle: Error; + let errorToHandle; // Typically Errors are thrown but eg strings or null can be thrown as well. if (error instanceof Error) { - const {message, name} = error; - - const summary = message ? `${name}: ${message}` : name; - - errorToHandle = error; - - try { - errorToHandle.message = `${summary}\n\nThis error is located at:${componentStack}`; - } catch (e) {} + errorToHandle = (error: ExtendedError); } else if (typeof error === 'string') { - errorToHandle = new Error( - `${error}\n\nThis error is located at:${componentStack}`, - ); + errorToHandle = (new SyntheticError(error): ExtendedError); } else { - errorToHandle = new Error(`Unspecified error at:${componentStack}`); + errorToHandle = (new SyntheticError('Unspecified error'): ExtendedError); } - + try { + errorToHandle.componentStack = componentStack; + } catch (e) {} handleException(errorToHandle, false); // Return false here to prevent ReactFiberErrorLogger default behavior of @@ -56,3 +50,5 @@ export function showErrorDialog(capturedError: CapturedError): boolean { // done above by calling ExceptionsManager. return false; } + +module.exports = {showErrorDialog}; diff --git a/Libraries/Core/__tests__/ExceptionsManager-test.js b/Libraries/Core/__tests__/ExceptionsManager-test.js index 10c7194c52acb5..ea4cb0705a0b23 100644 --- a/Libraries/Core/__tests__/ExceptionsManager-test.js +++ b/Libraries/Core/__tests__/ExceptionsManager-test.js @@ -57,7 +57,7 @@ describe('ExceptionsManager', () => { test('forwards error instance to reportException', () => { const error = new ReferenceError('Some error happened'); // Copy all the data we care about before any possible mutation. - const {message} = error; + const {message, name} = error; const logToConsoleInReact = ReactFiberErrorDialog.showErrorDialog({ ...capturedErrorDefaults, @@ -73,6 +73,11 @@ describe('ExceptionsManager', () => { 'This error is located at:' + capturedErrorDefaults.componentStack; expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.originalMessage).toBe(message); + expect(exceptionData.name).toBe(name); + expect(exceptionData.componentStack).toBe( + capturedErrorDefaults.componentStack, + ); expect(getLineFromFrame(exceptionData.stack[0])).toBe( "const error = new ReferenceError('Some error happened');", ); @@ -149,6 +154,10 @@ describe('ExceptionsManager', () => { 'This error is located at:' + capturedErrorDefaults.componentStack; expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.originalMessage).toBe(message); + expect(exceptionData.componentStack).toBe( + capturedErrorDefaults.componentStack, + ); expect(exceptionData.stack[0].file).toMatch(/ReactFiberErrorDialog\.js$/); expect(exceptionData.isFatal).toBe(false); expect(logToConsoleInReact).toBe(false); @@ -164,8 +173,16 @@ describe('ExceptionsManager', () => { expect(nativeReportException.mock.calls.length).toBe(1); const exceptionData = nativeReportException.mock.calls[0][0]; const formattedMessage = - 'Unspecified error at:' + capturedErrorDefaults.componentStack; + 'Unspecified error' + + '\n\n' + + 'This error is located at:' + + capturedErrorDefaults.componentStack; expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.originalMessage).toBe('Unspecified error'); + expect(exceptionData.name).toBe(null); + expect(exceptionData.componentStack).toBe( + capturedErrorDefaults.componentStack, + ); expect(exceptionData.stack[0].file).toMatch(/ReactFiberErrorDialog\.js$/); expect(exceptionData.isFatal).toBe(false); expect(logToConsoleInReact).toBe(false); @@ -186,6 +203,55 @@ describe('ExceptionsManager', () => { "const error = Object.freeze(new Error('Some error happened'));", ); }); + + test('does not mutate the message', () => { + const error = new ReferenceError('Some error happened'); + const {message} = error; + + ReactFiberErrorDialog.showErrorDialog({ + ...capturedErrorDefaults, + error, + }); + + expect(nativeReportException).toHaveBeenCalled(); + expect(error.message).toBe(message); + }); + + test('can safely process the same error multiple times', () => { + const error = new ReferenceError('Some error happened'); + // Copy all the data we care about before any possible mutation. + const {message} = error; + const componentStacks = [ + '\n in A\n in B\n in C', + '\n in X\n in Y\n in Z', + ]; + for (const componentStack of componentStacks) { + nativeReportException.mockClear(); + const formattedMessage = + 'ReferenceError: ' + + message + + '\n\n' + + 'This error is located at:' + + componentStack; + const logToConsoleInReact = ReactFiberErrorDialog.showErrorDialog({ + ...capturedErrorDefaults, + componentStack, + error, + }); + + expect(nativeReportException.mock.calls.length).toBe(1); + const exceptionData = nativeReportException.mock.calls[0][0]; + expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.originalMessage).toBe(message); + expect(exceptionData.componentStack).toBe(componentStack); + expect(getLineFromFrame(exceptionData.stack[0])).toBe( + "const error = new ReferenceError('Some error happened');", + ); + expect(exceptionData.isFatal).toBe(false); + expect(logToConsoleInReact).toBe(false); + expect(console.error).toBeCalledWith(formattedMessage); + } + }); }); describe('console.error handler', () => { @@ -208,19 +274,22 @@ describe('ExceptionsManager', () => { test('logging an Error', () => { const error = new Error('Some error happened'); - const {message} = error; + const {message, name} = error; console.error(error); expect(nativeReportException.mock.calls.length).toBe(1); const exceptionData = nativeReportException.mock.calls[0][0]; - expect(exceptionData.message).toBe(message); + const formattedMessage = 'Error: ' + message; + expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.originalMessage).toBe(message); + expect(exceptionData.name).toBe(name); expect(getLineFromFrame(exceptionData.stack[0])).toBe( "const error = new Error('Some error happened');", ); expect(exceptionData.isFatal).toBe(false); expect(mockError.mock.calls[0]).toHaveLength(1); - expect(mockError.mock.calls[0][0]).toBe(error); + expect(mockError.mock.calls[0][0]).toBe(formattedMessage); }); test('logging a string', () => { @@ -230,8 +299,11 @@ describe('ExceptionsManager', () => { expect(nativeReportException.mock.calls.length).toBe(1); const exceptionData = nativeReportException.mock.calls[0][0]; - const formattedMessage = 'console.error: "Some error happened"'; - expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.message).toBe( + 'console.error: "Some error happened"', + ); + expect(exceptionData.originalMessage).toBe('"Some error happened"'); + expect(exceptionData.name).toBe('console.error'); expect(getLineFromFrame(exceptionData.stack[0])).toBe( 'console.error(message);', ); @@ -249,6 +321,10 @@ describe('ExceptionsManager', () => { expect(exceptionData.message).toBe( 'console.error: 42, true, ["symbol" failed to stringify], {"y":null}', ); + expect(exceptionData.originalMessage).toBe( + '42, true, ["symbol" failed to stringify], {"y":null}', + ); + expect(exceptionData.name).toBe('console.error'); expect(getLineFromFrame(exceptionData.stack[0])).toBe( 'console.error(...args);', ); @@ -317,13 +393,16 @@ describe('ExceptionsManager', () => { expect(nativeReportException.mock.calls.length).toBe(1); const exceptionData = nativeReportException.mock.calls[0][0]; - expect(exceptionData.message).toBe(message); + const formattedMessage = 'Error: ' + message; + expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.originalMessage).toBe(message); + expect(exceptionData.name).toBe('Error'); expect(getLineFromFrame(exceptionData.stack[0])).toBe( "const error = new Error('Some error happened');", ); expect(exceptionData.isFatal).toBe(true); expect(console.error.mock.calls[0]).toHaveLength(1); - expect(console.error.mock.calls[0][0]).toBe(message); + expect(console.error.mock.calls[0][0]).toBe(formattedMessage); }); test('handling a non-fatal Error', () => { @@ -334,13 +413,16 @@ describe('ExceptionsManager', () => { expect(nativeReportException.mock.calls.length).toBe(1); const exceptionData = nativeReportException.mock.calls[0][0]; - expect(exceptionData.message).toBe(message); + const formattedMessage = 'Error: ' + message; + expect(exceptionData.message).toBe(formattedMessage); + expect(exceptionData.originalMessage).toBe(message); + expect(exceptionData.name).toBe('Error'); expect(getLineFromFrame(exceptionData.stack[0])).toBe( "const error = new Error('Some error happened');", ); expect(exceptionData.isFatal).toBe(false); expect(console.error.mock.calls[0]).toHaveLength(1); - expect(console.error.mock.calls[0][0]).toBe(message); + expect(console.error.mock.calls[0][0]).toBe(formattedMessage); }); test('handling a thrown string', () => { @@ -351,6 +433,8 @@ describe('ExceptionsManager', () => { expect(nativeReportException.mock.calls.length).toBe(1); const exceptionData = nativeReportException.mock.calls[0][0]; expect(exceptionData.message).toBe(message); + expect(exceptionData.originalMessage).toBe(null); + expect(exceptionData.name).toBe(null); expect(exceptionData.stack[0].file).toMatch(/ExceptionsManager\.js$/); expect(exceptionData.isFatal).toBe(true); expect(console.error.mock.calls[0]).toEqual([message]); diff --git a/Libraries/FBReactNativeSpec/FBReactNativeSpec/FBReactNativeSpec.h b/Libraries/FBReactNativeSpec/FBReactNativeSpec/FBReactNativeSpec.h index 5708b9d3eedd89..1a038aac085122 100644 --- a/Libraries/FBReactNativeSpec/FBReactNativeSpec/FBReactNativeSpec.h +++ b/Libraries/FBReactNativeSpec/FBReactNativeSpec/FBReactNativeSpec.h @@ -850,6 +850,9 @@ namespace JS { namespace NativeExceptionsManager { struct ExceptionData { NSString *message() const; + NSString *originalMessage() const; + NSString *name() const; + NSString *componentStack() const; facebook::react::LazyVector stack() const; double id_() const; bool isFatal() const; @@ -2520,6 +2523,21 @@ inline NSString *JS::NativeExceptionsManager::ExceptionData::message() const id const p = _v[@"message"]; return RCTBridgingToString(p); } +inline NSString *JS::NativeExceptionsManager::ExceptionData::originalMessage() const +{ + id const p = _v[@"originalMessage"]; + return RCTBridgingToString(p); +} +inline NSString *JS::NativeExceptionsManager::ExceptionData::name() const +{ + id const p = _v[@"name"]; + return RCTBridgingToString(p); +} +inline NSString *JS::NativeExceptionsManager::ExceptionData::componentStack() const +{ + id const p = _v[@"componentStack"]; + return RCTBridgingToString(p); +} inline facebook::react::LazyVector JS::NativeExceptionsManager::ExceptionData::stack() const { id const p = _v[@"stack"]; diff --git a/RNTester/RNTesterIntegrationTests/RCTLoggingTests.m b/RNTester/RNTesterIntegrationTests/RCTLoggingTests.m index e1ed8b0b80fcb2..165f32f4acda28 100644 --- a/RNTester/RNTesterIntegrationTests/RCTLoggingTests.m +++ b/RNTester/RNTesterIntegrationTests/RCTLoggingTests.m @@ -91,7 +91,7 @@ - (void)testLogging XCTAssertEqual(_lastLogLevel, RCTLogLevelError); XCTAssertEqual(_lastLogSource, RCTLogSourceJavaScript); - XCTAssertEqualObjects(_lastLogMessage, @"Invariant failed"); + XCTAssertEqualObjects(_lastLogMessage, @"Invariant Violation: Invariant failed"); [_bridge enqueueJSCall:@"LoggingTestModule.logErrorToConsole" args:@[@"Invoking console.error"]]; dispatch_semaphore_wait(_logSem, DISPATCH_TIME_FOREVER); @@ -115,7 +115,7 @@ - (void)testLogging XCTAssertEqual(_lastLogLevel, RCTLogLevelError); XCTAssertEqual(_lastLogSource, RCTLogSourceJavaScript); - XCTAssertEqualObjects(_lastLogMessage, @"Throwing an error"); + XCTAssertEqualObjects(_lastLogMessage, @"Error: Throwing an error"); } @end