From f8853fa7f0193d96d07ba3c871261996739adc6c Mon Sep 17 00:00:00 2001 From: Dominic Kramer Date: Wed, 17 May 2017 00:29:06 -0700 Subject: [PATCH 1/6] error-reporting: Fix bug with errors not published This commit fixes a bug where if `errors.event().setMessage(string)` was used to build an error to report, the error wouldn't appear in the error reporting console. --- .../error-reporting/src/interfaces/manual.js | 4 ++ .../system-test/testAuthClient.js | 50 +++++++++++++------ 2 files changed, 40 insertions(+), 14 deletions(-) diff --git a/packages/error-reporting/src/interfaces/manual.js b/packages/error-reporting/src/interfaces/manual.js index e2dbc74e495..15939cb99c4 100644 --- a/packages/error-reporting/src/interfaces/manual.js +++ b/packages/error-reporting/src/interfaces/manual.js @@ -74,6 +74,10 @@ function handlerSetup(client, config) { } if (err instanceof ErrorMessage) { + var fauxError = new Error(err.message); + var fullStack = fauxError.stack.split('\n'); + var cleanedStack = fullStack.slice(0, 1).concat(fullStack.slice(2)).join('\n'); + err.setMessage(cleanedStack); em = err; } else { em = new ErrorMessage(); diff --git a/packages/error-reporting/system-test/testAuthClient.js b/packages/error-reporting/system-test/testAuthClient.js index dde00dc2cf0..8a51faa9219 100644 --- a/packages/error-reporting/system-test/testAuthClient.js +++ b/packages/error-reporting/system-test/testAuthClient.js @@ -361,10 +361,9 @@ describe('Expected Behavior', function() { }); describe('error-reporting', function() { - const TIMESTAMP = Date.now(); const BASE_NAME = 'error-reporting-system-test'; function buildName(suffix) { - return [TIMESTAMP, BASE_NAME, suffix].join('_'); + return [Date.now(), BASE_NAME, suffix].join('_'); } const SERVICE_NAME = buildName('service-name'); @@ -390,15 +389,8 @@ describe('error-reporting', function() { }); }); - it('Should correctly publish errors', function(done) { - // After an error is reported, this test waits TIMEOUT ms before - // verifying the error has been reported to ensure the system had - // enough time to receive the error report and process it. - // As such, this test is set to fail due to a timeout only if sufficiently - // more than TIMEOUT ms has elapsed to avoid test fragility. - this.timeout(TIMEOUT * 2); - var errorId = buildName('message'); - errors.report(new Error(errorId), function(err, response, body) { + function verifyReporting(errOb, expectedMessage, timeout, cb) { + errors.report(errOb, function(err, response, body) { assert.ifError(err); assert(isObject(response)); assert.deepEqual(body, {}); @@ -410,7 +402,7 @@ describe('error-reporting', function() { var matchedErrors = groups.filter(function(errItem) { return errItem && errItem.representative && - errItem.representative.message.startsWith('Error: ' + errorId); + errItem.representative.message.startsWith(expectedMessage); }); // The error should have been reported exactly once @@ -424,9 +416,39 @@ describe('error-reporting', function() { assert.ok(context); assert.strictEqual(context.service, SERVICE_NAME); assert.strictEqual(context.version, SERVICE_VERSION); - done(); + cb(); }); - }, TIMEOUT); + }, timeout); }); + } + + // For each test below, after an error is reported, the test waits + // TIMEOUT ms before verifying the error has been reported to ensure + // the system had enough time to receive the error report and process it. + // As such, each test is set to fail due to a timeout only if sufficiently + // more than TIMEOUT ms has elapsed to avoid test fragility. + + it('Should correctly publish errors using the Error constructor', + function(done) { + this.timeout(TIMEOUT * 2); + var errorId = buildName('message'); + var errOb = new Error(errorId); + var expectedMessage = 'Error: ' + errorId; + verifyReporting(errOb, expectedMessage, TIMEOUT, done); + }); + + it('Should correctly publish errors using a string', function(done) { + this.timeout(TIMEOUT * 2); + var errorId = buildName('message'); + verifyReporting(errorId, errorId, TIMEOUT, done); + }); + + it('Should correctly publish errors using an error builder', function(done) { + this.timeout(TIMEOUT * 2); + var errorId = buildName('message'); + var expectedMessage = 'Error: ' + errorId; + var errOb = errors.event() + .setMessage(errorId); + verifyReporting(errOb, expectedMessage, TIMEOUT, done); }); }); \ No newline at end of file From 5f04257403dd416bfe8f675bd76d7a546bccd12e Mon Sep 17 00:00:00 2001 From: Dominic Kramer Date: Wed, 17 May 2017 00:53:39 -0700 Subject: [PATCH 2/6] Fix unit tests and improve system tests --- packages/error-reporting/system-test/testAuthClient.js | 6 +++--- packages/error-reporting/test/unit/interfaces/manual.js | 4 ++-- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/packages/error-reporting/system-test/testAuthClient.js b/packages/error-reporting/system-test/testAuthClient.js index 8a51faa9219..4208156c7e8 100644 --- a/packages/error-reporting/system-test/testAuthClient.js +++ b/packages/error-reporting/system-test/testAuthClient.js @@ -431,7 +431,7 @@ describe('error-reporting', function() { it('Should correctly publish errors using the Error constructor', function(done) { this.timeout(TIMEOUT * 2); - var errorId = buildName('message'); + var errorId = buildName('with-error-constructor'); var errOb = new Error(errorId); var expectedMessage = 'Error: ' + errorId; verifyReporting(errOb, expectedMessage, TIMEOUT, done); @@ -439,13 +439,13 @@ describe('error-reporting', function() { it('Should correctly publish errors using a string', function(done) { this.timeout(TIMEOUT * 2); - var errorId = buildName('message'); + var errorId = buildName('with-string'); verifyReporting(errorId, errorId, TIMEOUT, done); }); it('Should correctly publish errors using an error builder', function(done) { this.timeout(TIMEOUT * 2); - var errorId = buildName('message'); + var errorId = buildName('with-error-builder'); var expectedMessage = 'Error: ' + errorId; var errOb = errors.event() .setMessage(errorId); diff --git a/packages/error-reporting/test/unit/interfaces/manual.js b/packages/error-reporting/test/unit/interfaces/manual.js index e5544d0675a..f86d77c40f0 100644 --- a/packages/error-reporting/test/unit/interfaces/manual.js +++ b/packages/error-reporting/test/unit/interfaces/manual.js @@ -142,7 +142,7 @@ describe('Manual handler', function() { it('Should accept builder inst as only argument', function() { var msg = 'test'; var r = report(new ErrorMessage().setMessage(msg)); - assert.strictEqual(r.message, msg, + assert(r.message.startsWith('Error: ' + msg), 'string message should propagate from error message inst'); }); it('Should accept builder and request as arguments', function() { @@ -153,7 +153,7 @@ describe('Manual handler', function() { new ErrorMessage().setMessage(msg).consumeRequestInformation(oldReq), newReq ); - assert.strictEqual(r.message, msg, + assert(r.message.startsWith('Error: ' + msg), 'string message should propagate from error message inst'); assert.strictEqual(r.context.httpRequest.method, newReq.method, [ From 82c115efe3b4ea5c19f6324629e3ce9bbf128d61 Mon Sep 17 00:00:00 2001 From: Dominic Kramer Date: Wed, 17 May 2017 11:11:00 -0700 Subject: [PATCH 3/6] Add code comments --- packages/error-reporting/src/interfaces/manual.js | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/packages/error-reporting/src/interfaces/manual.js b/packages/error-reporting/src/interfaces/manual.js index 15939cb99c4..92d7b32646d 100644 --- a/packages/error-reporting/src/interfaces/manual.js +++ b/packages/error-reporting/src/interfaces/manual.js @@ -74,6 +74,13 @@ function handlerSetup(client, config) { } if (err instanceof ErrorMessage) { + // The API expects the error to contain a stack trace, but the + // user does not explicitly provide one. Instead, the code below + // creates an error with the user supplied message and updates + // the stack trace to not include the second line of the stack trace + // since that line only involves the internals of the error-reporting + // library. The stack trace without the error-reporting internals + // is then used as the stack trace for the message. var fauxError = new Error(err.message); var fullStack = fauxError.stack.split('\n'); var cleanedStack = fullStack.slice(0, 1).concat(fullStack.slice(2)).join('\n'); From a06ce2637dfb65043e5c9ccc5060e138478f188f Mon Sep 17 00:00:00 2001 From: Dominic Kramer Date: Fri, 19 May 2017 11:13:03 -0700 Subject: [PATCH 4/6] Custom errors now use definition site stack trace Previously the stack trace at the point `errors.report` was called was used. --- packages/error-reporting/src/index.js | 2 +- .../error-reporting/src/interfaces/manual.js | 31 +++++++++++------- .../src/interfaces/message-builder.js | 19 ++++++++++- .../system-test/testAuthClient.js | 32 +++++++++++++------ .../test/unit/interfaces/manual.js | 28 ++++++++++++---- 5 files changed, 82 insertions(+), 30 deletions(-) diff --git a/packages/error-reporting/src/index.js b/packages/error-reporting/src/index.js index 519e6ebbae5..b2038350e05 100644 --- a/packages/error-reporting/src/index.js +++ b/packages/error-reporting/src/index.js @@ -106,7 +106,7 @@ function Errors(initConfiguration) { * console.log('done!'); * }); */ - this.report = manual(this._client, this._config); + this.report = manual(this._client, this._config, this._logger); /** * @example * // Use to create and report errors manually with a high-degree diff --git a/packages/error-reporting/src/interfaces/manual.js b/packages/error-reporting/src/interfaces/manual.js index 92d7b32646d..9f8ed6f1126 100644 --- a/packages/error-reporting/src/interfaces/manual.js +++ b/packages/error-reporting/src/interfaces/manual.js @@ -33,10 +33,12 @@ var errorHandlerRouter = require('../error-router.js'); * @param {AuthClient} client - an initialized API client * @param {NormalizedConfigurationVariables} config - the environmental * configuration + * @param {Object} logger - The logger instance created when the library API has + * been initialized. * @returns {reportManualError} - a bound version of the reportManualError * function */ -function handlerSetup(client, config) { +function handlerSetup(client, config, logger) { /** * The interface for manually reporting errors to the Google Error API in * application code. @@ -74,17 +76,22 @@ function handlerSetup(client, config) { } if (err instanceof ErrorMessage) { - // The API expects the error to contain a stack trace, but the - // user does not explicitly provide one. Instead, the code below - // creates an error with the user supplied message and updates - // the stack trace to not include the second line of the stack trace - // since that line only involves the internals of the error-reporting - // library. The stack trace without the error-reporting internals - // is then used as the stack trace for the message. - var fauxError = new Error(err.message); - var fullStack = fauxError.stack.split('\n'); - var cleanedStack = fullStack.slice(0, 1).concat(fullStack.slice(2)).join('\n'); - err.setMessage(cleanedStack); + // The API expects the error to contain a stack trace. Thus we + // append the stack trace of the point where the error was constructed. + // See the `message-builder.js` file for more details. + if (err._autoGeneratedStackTrace) { + err.setMessage(err.message + '\n' + err._autoGeneratedStackTrace); + // Delete the property so that if the ErrorMessage is reported a second + // time, the stack trace is not appended a second time. Also, the API + // will not accept the ErrorMessage if it has additional properties. + delete err._autoGeneratedStackTrace; + } + else { + logger.warn('Encountered a manually constructed error with message \"'+ + err.message + '\" but without a construction site ' + + 'stack trace. This error might not be visible in the ' + + 'error reporting console.'); + } em = err; } else { em = new ErrorMessage(); diff --git a/packages/error-reporting/src/interfaces/message-builder.js b/packages/error-reporting/src/interfaces/message-builder.js index c22f3c11cc0..90783819fb8 100644 --- a/packages/error-reporting/src/interfaces/message-builder.js +++ b/packages/error-reporting/src/interfaces/message-builder.js @@ -33,9 +33,26 @@ function handlerSetup(config) { * @returns {ErrorMessage} - returns a new instance of the ErrorMessage class */ function newMessage() { - return new ErrorMessage().setServiceContext( + // The API expects a reported error to contain a stack trace. + // However, users do not need to provide a stack trace for stack + // traces built using the message builder. Instead, here we store + // the stack trace with the parts that reference the error-reporting's + // internals removed. Then when the error is reported, the stored + // stack trace will be appended to the user's message for the error. + // + // Note: The stack trace at the point where the user constructed the + // error is used instead of the stack trace where the error is + // reported to be consistent with the behavior of reporting a + // an error when reporting an actual Node.js Error object. + var fauxError = new Error(''); + var fullStack = fauxError.stack.split('\n'); + var cleanedStack = fullStack.slice(2).join('\n'); + + var em = new ErrorMessage().setServiceContext( config.getServiceContext().service, config.getServiceContext().version); + em._autoGeneratedStackTrace = cleanedStack; + return em; } return newMessage; diff --git a/packages/error-reporting/system-test/testAuthClient.js b/packages/error-reporting/system-test/testAuthClient.js index 4208156c7e8..8678a2b0d3f 100644 --- a/packages/error-reporting/system-test/testAuthClient.js +++ b/packages/error-reporting/system-test/testAuthClient.js @@ -389,7 +389,7 @@ describe('error-reporting', function() { }); }); - function verifyReporting(errOb, expectedMessage, timeout, cb) { + function verifyReporting(errOb, messageTest, timeout, cb) { errors.report(errOb, function(err, response, body) { assert.ifError(err); assert(isObject(response)); @@ -402,7 +402,7 @@ describe('error-reporting', function() { var matchedErrors = groups.filter(function(errItem) { return errItem && errItem.representative && - errItem.representative.message.startsWith(expectedMessage); + messageTest(errItem.representative.message); }); // The error should have been reported exactly once @@ -433,22 +433,36 @@ describe('error-reporting', function() { this.timeout(TIMEOUT * 2); var errorId = buildName('with-error-constructor'); var errOb = new Error(errorId); - var expectedMessage = 'Error: ' + errorId; - verifyReporting(errOb, expectedMessage, TIMEOUT, done); + verifyReporting(errOb, function(message) { + return message.startsWith('Error: ' + errorId); + }, TIMEOUT, done); }); it('Should correctly publish errors using a string', function(done) { this.timeout(TIMEOUT * 2); var errorId = buildName('with-string'); - verifyReporting(errorId, errorId, TIMEOUT, done); + verifyReporting(errorId, function(message) { + return message.startsWith(errorId); + }, TIMEOUT, done); }); it('Should correctly publish errors using an error builder', function(done) { this.timeout(TIMEOUT * 2); var errorId = buildName('with-error-builder'); - var expectedMessage = 'Error: ' + errorId; - var errOb = errors.event() - .setMessage(errorId); - verifyReporting(errOb, expectedMessage, TIMEOUT, done); + var errOb = (function definitionSiteFunction() { + return errors.event() + .setMessage(errorId); + })(); + (function callingSiteFunction() { + verifyReporting(errOb, function(message) { + // Verify that the stack trace of the constructed error + // uses the stack trace at the point where the error was constructed + // and not the stack trace at the point where the `report` method + // was called. + return message.startsWith(errorId) && + message.indexOf('callingSiteFunction') === -1 && + message.indexOf('definitionSiteFunction') !== -1; + }, TIMEOUT, done); + })(); }); }); \ No newline at end of file diff --git a/packages/error-reporting/test/unit/interfaces/manual.js b/packages/error-reporting/test/unit/interfaces/manual.js index f86d77c40f0..3216148cef8 100644 --- a/packages/error-reporting/test/unit/interfaces/manual.js +++ b/packages/error-reporting/test/unit/interfaces/manual.js @@ -37,7 +37,21 @@ describe('Manual handler', function() { } } }; - var report = manual(client, config); + var report = manual(client, config, { + warn: function(message) { + // The use of `report` in this class should issue the following warning + // becasue the `report` class is used directly and, as such, cannot + // by itself have information where a ErrorMesasge was constructed. It + // only knows that an error has been reported. + // Thus, the ErrorMessage objects given to the `report` method in the + // tests do not have construction site information to verify that if + // that information is not available, the user is issued a warning. + assert.strictEqual(message, 'Encountered a manually constructed error ' + + 'with message "builder test" but without a construction site stack ' + + 'trace. This error might not be visible in the error reporting ' + + 'console.'); + } + }); describe('Report invocation behaviour', function() { it('Should allow argument-less invocation', function() { var r = report(); @@ -140,20 +154,20 @@ describe('Manual handler', function() { describe('Custom Payload Builder', function() { it('Should accept builder inst as only argument', function() { - var msg = 'test'; + var msg = 'builder test'; var r = report(new ErrorMessage().setMessage(msg)); - assert(r.message.startsWith('Error: ' + msg), + assert(r.message.startsWith(msg), 'string message should propagate from error message inst'); }); it('Should accept builder and request as arguments', function() { - var msg = 'test'; + var msg = 'builder test'; var oldReq = {method: 'GET'}; var newReq = {method: 'POST'}; var r = report( new ErrorMessage().setMessage(msg).consumeRequestInformation(oldReq), newReq ); - assert(r.message.startsWith('Error: ' + msg), + assert(r.message.startsWith(msg), 'string message should propagate from error message inst'); assert.strictEqual(r.context.httpRequest.method, newReq.method, [ @@ -163,7 +177,7 @@ describe('Manual handler', function() { ); }); it('Should accept message and additional message params as', function() { - var oldMsg = 'test'; + var oldMsg = 'builder test'; var newMsg = 'analysis'; var r = report( new ErrorMessage().setMessage(oldMsg), @@ -176,7 +190,7 @@ describe('Manual handler', function() { ].join('\n')); }); it('Should accept message and callback function', function(done) { - var oldMsg = 'test'; + var oldMsg = 'builder test'; report( new ErrorMessage().setMessage(oldMsg), function() { done(); } From f60eefc653f9174fad7da20ef7aa9d9b47a59b60 Mon Sep 17 00:00:00 2001 From: Dominic Kramer Date: Mon, 22 May 2017 12:45:47 -0700 Subject: [PATCH 5/6] Address GitHub comments * Updated docs * Fixed some code comments * Fixed some code formatting --- packages/error-reporting/README.md | 11 ++++++++--- packages/error-reporting/src/interfaces/manual.js | 3 +-- .../error-reporting/src/interfaces/message-builder.js | 4 ++-- 3 files changed, 11 insertions(+), 7 deletions(-) diff --git a/packages/error-reporting/README.md b/packages/error-reporting/README.md index 38cc7649694..da4b60fb151 100644 --- a/packages/error-reporting/README.md +++ b/packages/error-reporting/README.md @@ -145,19 +145,24 @@ var errors = require('@google-cloud/error-reporting')({ ```js var errors = require('@google-cloud/error-reporting')(); -// Use the error message builder to custom set all message fields +// Use the error message builder to customize all fields ... var errorEvt = errors.event() .setMessage('My error message') .setUser('root@nexus'); errors.report(errorEvt, () => console.log('done!')); -// Or just use a regular error +// or just use a regular error ... errors.report(new Error('My error message'), () => console.log('done!')); -// One can even just use a string +// or one can even just use a string. errors.report('My error message'); ``` +The stack trace associated with an error can be viewed in the error reporting console. +* If the `errors.report` method is given an `ErrorMessage` object built using the `errors.event` method, the stack trace at the point where the error event was constructed will be used. +* If the `errors.report` method is given an `Error` object, the stack trace where the error originated will be used. +* If the `errors.report` method is given a string, the stack trace at the point where `errors.report` is invoked will be used. + ### Using Express ```js diff --git a/packages/error-reporting/src/interfaces/manual.js b/packages/error-reporting/src/interfaces/manual.js index 9f8ed6f1126..5be883c979f 100644 --- a/packages/error-reporting/src/interfaces/manual.js +++ b/packages/error-reporting/src/interfaces/manual.js @@ -85,8 +85,7 @@ function handlerSetup(client, config, logger) { // time, the stack trace is not appended a second time. Also, the API // will not accept the ErrorMessage if it has additional properties. delete err._autoGeneratedStackTrace; - } - else { + } else { logger.warn('Encountered a manually constructed error with message \"'+ err.message + '\" but without a construction site ' + 'stack trace. This error might not be visible in the ' + diff --git a/packages/error-reporting/src/interfaces/message-builder.js b/packages/error-reporting/src/interfaces/message-builder.js index 90783819fb8..3a539d3b3be 100644 --- a/packages/error-reporting/src/interfaces/message-builder.js +++ b/packages/error-reporting/src/interfaces/message-builder.js @@ -34,8 +34,8 @@ function handlerSetup(config) { */ function newMessage() { // The API expects a reported error to contain a stack trace. - // However, users do not need to provide a stack trace for stack - // traces built using the message builder. Instead, here we store + // However, users do not need to provide a stack trace for ErrorMessage + // objects built using the message builder. Instead, here we store // the stack trace with the parts that reference the error-reporting's // internals removed. Then when the error is reported, the stored // stack trace will be appended to the user's message for the error. From 3250f76b8b947a4500079961079104b48bd2a0e5 Mon Sep 17 00:00:00 2001 From: Dominic Kramer Date: Mon, 22 May 2017 13:49:00 -0700 Subject: [PATCH 6/6] Fix the wording of stack trace usage --- packages/error-reporting/README.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/packages/error-reporting/README.md b/packages/error-reporting/README.md index da4b60fb151..ce2a0bc923d 100644 --- a/packages/error-reporting/README.md +++ b/packages/error-reporting/README.md @@ -160,7 +160,7 @@ errors.report('My error message'); The stack trace associated with an error can be viewed in the error reporting console. * If the `errors.report` method is given an `ErrorMessage` object built using the `errors.event` method, the stack trace at the point where the error event was constructed will be used. -* If the `errors.report` method is given an `Error` object, the stack trace where the error originated will be used. +* If the `errors.report` method is given an `Error` object, the stack trace where the error was instantiated will be used. * If the `errors.report` method is given a string, the stack trace at the point where `errors.report` is invoked will be used. ### Using Express