From dedcb7cbe42dd94cd246161f0cdbe2a540a0e6fe Mon Sep 17 00:00:00 2001 From: Mike Bland Date: Sat, 22 Apr 2017 20:17:52 +0200 Subject: [PATCH 1/2] Fix Node v6.6.0+ UnhandledPromiseRejectionWarning Backported from mbland/hubot-slack-github-issues#7. As discovered in 18F/hubot-slack-github-issues#51, the `UnhandledPromiseRejectionWarning` and `PromiseRejectionHandledWarning` warnings were apparently added in v6.6.0 (https://nodejs.org/en/blog/release/v6.6.0/); specifically it was added by nodejs/node#8223. See also: nodejs/node#6439 nodejs/node#8217 https://nodejs.org/dist/latest-v6.x/docs/api/process.html#process_event_unhandledrejection https://nodejs.org/dist/latest-v6.x/docs/api/process.html#process_event_rejectionhandled https://nodejs.org/dist/latest-v6.x/docs/api/process.html#process_event_warning A test failure from `solutions/06-integration/test/integration-test.js` after upgrading to Node v6.9.1 showed output such as: ``` - "(node:87412) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 14): Error: failed to create a GitHub issue in 18F/handbook: received 500 response from GitHub API: {\"message\":\"test failure\"}\n" ``` This was happening because `scripts/slack-github-issues.js` ignored the return value from `Middleware.execute()`, whether it was undefined or a `Promise`. For consistency's sake (and to provide a clearer upgrade path to the current state of mbland/slack-github-issues), `Middleware.execute()` always returns a `Promise`, and `scripts/slack-github-issues.js` handles and ignores any rejected Promises. This fixed the `integration-test.js` error, but also required minor updates to `solutions/{05-middleware,complete}/test/middleware-test.js`. The next commit will update the tutorial narrative to account for this change. --- solutions/05-middleware/lib/middleware.js | 9 +++-- .../05-middleware/test/middleware-test.js | 36 ++++++++++--------- solutions/06-integration/lib/middleware.js | 9 +++-- .../scripts/slack-github-issues.js | 2 +- solutions/07-system/lib/middleware.js | 9 +++-- .../07-system/scripts/slack-github-issues.js | 2 +- solutions/complete/lib/middleware.js | 9 +++-- .../complete/scripts/slack-github-issues.js | 2 +- solutions/complete/test/middleware-test.js | 36 ++++++++++--------- 9 files changed, 65 insertions(+), 49 deletions(-) diff --git a/solutions/05-middleware/lib/middleware.js b/solutions/05-middleware/lib/middleware.js index 9c991b1..fa691e3 100644 --- a/solutions/05-middleware/lib/middleware.js +++ b/solutions/05-middleware/lib/middleware.js @@ -28,7 +28,8 @@ Middleware.prototype.execute = function(context, next, done) { JSON.stringify(context.response.message.rawMessage, null, 2); this.logger.error(null, errorMessage); context.response.reply(errorMessage); - return next(done); + next(done); + return Promise.reject(); } }; @@ -40,13 +41,15 @@ function doExecute(middleware, context, next, done) { finish; if (!rule) { - return next(done); + next(done); + return Promise.reject(); } msgId = messageId(message); if (middleware.inProgress[msgId]) { middleware.logger.info(msgId, 'already in progress'); - return next(done); + next(done); + return Promise.reject(); } middleware.inProgress[msgId] = true; diff --git a/solutions/05-middleware/test/middleware-test.js b/solutions/05-middleware/test/middleware-test.js index 3b861fc..520b2b0 100644 --- a/solutions/05-middleware/test/middleware-test.js +++ b/solutions/05-middleware/test/middleware-test.js @@ -142,8 +142,10 @@ describe('Middleware', function() { it('should ignore messages that do not match', function() { delete context.response.message.rawMessage; - expect(middleware.execute(context, next, hubotDone)).to.be.undefined; - next.calledWith(hubotDone).should.be.true; + middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined).then(function() { + next.calledWith(hubotDone).should.be.true; + }); }); it('should not file another issue for the same message when ' + @@ -151,20 +153,19 @@ describe('Middleware', function() { var result; result = middleware.execute(context, next, hubotDone); - expect(middleware.execute(context, next, hubotDone)).to.eql(undefined, - 'middleware.execute did not prevent filing a second issue ' + - 'when one was already in progress'); - - return result.should.become(helpers.ISSUE_URL).then(function() { - logger.info.args.should.include.something.that.deep.equals( - helpers.logArgs('already in progress')); - - // Make another call to ensure that the ID is cleaned up. Normally the - // message will have a successReaction after the first successful - // request, but we'll test that in another case. - return middleware.execute(context, next, hubotDone) - .should.become(helpers.ISSUE_URL); - }); + return middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined).then(function() { + logger.info.args.should.include.something.that.deep.equals( + helpers.logArgs('already in progress')); + next.calledWith(hubotDone).should.be.true; + return result.should.become(helpers.ISSUE_URL).then(function() { + // Make another call to ensure that the ID is cleaned up. Normally + // the message will have a successReaction after the first + // successful request, but we'll test that in another case. + return middleware.execute(context, next, hubotDone) + .should.become(helpers.ISSUE_URL); + }); + }); }); it('should not file another issue for the same message when ' + @@ -250,7 +251,8 @@ describe('Middleware', function() { JSON.stringify(helpers.reactionAddedMessage(), null, 2); slackClient.getChannelName.throws(); - expect(middleware.execute(context, next, hubotDone)).to.be.undefined; + middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined); next.calledWith(hubotDone).should.be.true; context.response.reply.args.should.eql([[errorMessage]]); logger.error.args.should.eql([[null, errorMessage]]); diff --git a/solutions/06-integration/lib/middleware.js b/solutions/06-integration/lib/middleware.js index 9c991b1..fa691e3 100644 --- a/solutions/06-integration/lib/middleware.js +++ b/solutions/06-integration/lib/middleware.js @@ -28,7 +28,8 @@ Middleware.prototype.execute = function(context, next, done) { JSON.stringify(context.response.message.rawMessage, null, 2); this.logger.error(null, errorMessage); context.response.reply(errorMessage); - return next(done); + next(done); + return Promise.reject(); } }; @@ -40,13 +41,15 @@ function doExecute(middleware, context, next, done) { finish; if (!rule) { - return next(done); + next(done); + return Promise.reject(); } msgId = messageId(message); if (middleware.inProgress[msgId]) { middleware.logger.info(msgId, 'already in progress'); - return next(done); + next(done); + return Promise.reject(); } middleware.inProgress[msgId] = true; diff --git a/solutions/06-integration/scripts/slack-github-issues.js b/solutions/06-integration/scripts/slack-github-issues.js index c331faf..bafcf1c 100644 --- a/solutions/06-integration/scripts/slack-github-issues.js +++ b/solutions/06-integration/scripts/slack-github-issues.js @@ -25,7 +25,7 @@ module.exports = function(robot) { logger); middleware = function(context, next, done) { - impl.execute(context, next, done); + impl.execute(context, next, done).catch(function() { }); }; middleware.impl = impl; robot.receiveMiddleware(middleware); diff --git a/solutions/07-system/lib/middleware.js b/solutions/07-system/lib/middleware.js index 9c991b1..fa691e3 100644 --- a/solutions/07-system/lib/middleware.js +++ b/solutions/07-system/lib/middleware.js @@ -28,7 +28,8 @@ Middleware.prototype.execute = function(context, next, done) { JSON.stringify(context.response.message.rawMessage, null, 2); this.logger.error(null, errorMessage); context.response.reply(errorMessage); - return next(done); + next(done); + return Promise.reject(); } }; @@ -40,13 +41,15 @@ function doExecute(middleware, context, next, done) { finish; if (!rule) { - return next(done); + next(done); + return Promise.reject(); } msgId = messageId(message); if (middleware.inProgress[msgId]) { middleware.logger.info(msgId, 'already in progress'); - return next(done); + next(done); + return Promise.reject(); } middleware.inProgress[msgId] = true; diff --git a/solutions/07-system/scripts/slack-github-issues.js b/solutions/07-system/scripts/slack-github-issues.js index c331faf..bafcf1c 100644 --- a/solutions/07-system/scripts/slack-github-issues.js +++ b/solutions/07-system/scripts/slack-github-issues.js @@ -25,7 +25,7 @@ module.exports = function(robot) { logger); middleware = function(context, next, done) { - impl.execute(context, next, done); + impl.execute(context, next, done).catch(function() { }); }; middleware.impl = impl; robot.receiveMiddleware(middleware); diff --git a/solutions/complete/lib/middleware.js b/solutions/complete/lib/middleware.js index 9c991b1..fa691e3 100644 --- a/solutions/complete/lib/middleware.js +++ b/solutions/complete/lib/middleware.js @@ -28,7 +28,8 @@ Middleware.prototype.execute = function(context, next, done) { JSON.stringify(context.response.message.rawMessage, null, 2); this.logger.error(null, errorMessage); context.response.reply(errorMessage); - return next(done); + next(done); + return Promise.reject(); } }; @@ -40,13 +41,15 @@ function doExecute(middleware, context, next, done) { finish; if (!rule) { - return next(done); + next(done); + return Promise.reject(); } msgId = messageId(message); if (middleware.inProgress[msgId]) { middleware.logger.info(msgId, 'already in progress'); - return next(done); + next(done); + return Promise.reject(); } middleware.inProgress[msgId] = true; diff --git a/solutions/complete/scripts/slack-github-issues.js b/solutions/complete/scripts/slack-github-issues.js index c331faf..bafcf1c 100644 --- a/solutions/complete/scripts/slack-github-issues.js +++ b/solutions/complete/scripts/slack-github-issues.js @@ -25,7 +25,7 @@ module.exports = function(robot) { logger); middleware = function(context, next, done) { - impl.execute(context, next, done); + impl.execute(context, next, done).catch(function() { }); }; middleware.impl = impl; robot.receiveMiddleware(middleware); diff --git a/solutions/complete/test/middleware-test.js b/solutions/complete/test/middleware-test.js index 3b861fc..520b2b0 100644 --- a/solutions/complete/test/middleware-test.js +++ b/solutions/complete/test/middleware-test.js @@ -142,8 +142,10 @@ describe('Middleware', function() { it('should ignore messages that do not match', function() { delete context.response.message.rawMessage; - expect(middleware.execute(context, next, hubotDone)).to.be.undefined; - next.calledWith(hubotDone).should.be.true; + middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined).then(function() { + next.calledWith(hubotDone).should.be.true; + }); }); it('should not file another issue for the same message when ' + @@ -151,20 +153,19 @@ describe('Middleware', function() { var result; result = middleware.execute(context, next, hubotDone); - expect(middleware.execute(context, next, hubotDone)).to.eql(undefined, - 'middleware.execute did not prevent filing a second issue ' + - 'when one was already in progress'); - - return result.should.become(helpers.ISSUE_URL).then(function() { - logger.info.args.should.include.something.that.deep.equals( - helpers.logArgs('already in progress')); - - // Make another call to ensure that the ID is cleaned up. Normally the - // message will have a successReaction after the first successful - // request, but we'll test that in another case. - return middleware.execute(context, next, hubotDone) - .should.become(helpers.ISSUE_URL); - }); + return middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined).then(function() { + logger.info.args.should.include.something.that.deep.equals( + helpers.logArgs('already in progress')); + next.calledWith(hubotDone).should.be.true; + return result.should.become(helpers.ISSUE_URL).then(function() { + // Make another call to ensure that the ID is cleaned up. Normally + // the message will have a successReaction after the first + // successful request, but we'll test that in another case. + return middleware.execute(context, next, hubotDone) + .should.become(helpers.ISSUE_URL); + }); + }); }); it('should not file another issue for the same message when ' + @@ -250,7 +251,8 @@ describe('Middleware', function() { JSON.stringify(helpers.reactionAddedMessage(), null, 2); slackClient.getChannelName.throws(); - expect(middleware.execute(context, next, hubotDone)).to.be.undefined; + middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined); next.calledWith(hubotDone).should.be.true; context.response.reply.args.should.eql([[errorMessage]]); logger.error.args.should.eql([[null, errorMessage]]); From 12f3bda21be186bf059844fabece26e57772c3f6 Mon Sep 17 00:00:00 2001 From: Mike Bland Date: Fri, 28 Apr 2017 12:13:05 +0200 Subject: [PATCH 2/2] Update text for UnhandledPromiseRejectionWarning --- _pages/components/middleware.md | 58 +++++++++++-------- _pages/testing-component-integration.md | 12 +++- .../05-middleware/test/middleware-test.js | 9 +-- .../scripts/slack-github-issues.js | 2 + .../07-system/scripts/slack-github-issues.js | 2 + .../complete/scripts/slack-github-issues.js | 2 + solutions/complete/test/middleware-test.js | 9 +-- 7 files changed, 58 insertions(+), 36 deletions(-) diff --git a/_pages/components/middleware.md b/_pages/components/middleware.md index f1c6f33..6430e5b 100644 --- a/_pages/components/middleware.md +++ b/_pages/components/middleware.md @@ -488,7 +488,8 @@ moving on to the next section. Now that `findMatchingRule` is in place, let's return to `execute` and begin to test it. As a base case, make sure that `execute` calls `next(done)` and -returns if no rule matches: +returns an empty rejected `Promise` if no rule matches, to signify that no +action was taken and no error occurred: ```js Middleware.prototype.execute = function(context, next, done) { @@ -497,7 +498,8 @@ Middleware.prototype.execute = function(context, next, done) { rule = this.findMatchingRule(message); if (!rule) { - return next(done); + next(done); + return Promise.reject(); } return 'not yet implemented'; }; @@ -575,8 +577,10 @@ parse a message and file an issue` case: ```js it('should ignore messages that do not match', function() { delete context.response.message.rawMessage; - expect(middleware.execute(context, next, hubotDone)).to.be.undefined; - next.calledWith(hubotDone).should.be.true; + middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined).then(function() {; + next.calledWith(hubotDone).should.be.true; + }); }); ``` @@ -643,7 +647,8 @@ Middleware.prototype.execute = function(context, next, done) { msgId; if (!rule) { - return next(done); + next(done); + return Promise.reject(); } msgId = messageId(message); @@ -1413,18 +1418,18 @@ should return `undefined`: ```js it('should not file another issue for the same message when ' + - 'one is in progress', function(done) { + 'one is in progress', function() { var result; result = middleware.execute(context, next, hubotDone); - if (middleware.execute(context, next, hubotDone) !== undefined) { - return done(new Error('middleware.execute did not prevent filing a ' + - 'second issue when one was already in progress')); - } - - result.should.become(helpers.ISSUE_URL).then(function() { - logger.info.args.should.contain(helpers.logArgs('already in progress')); - }); + return middleware.execute(context, next, hubotDone) + .should.be.rejectedWith(undefined).then(function() { + return result.should.become(helpers.ISSUE_URL).then(function() { + logger.info.args.should.include.something.that.deep.equals( + helpers.logArgs('already in progress')); + next.calledWith(hubotDone).should.be.true; + }); + }); }); ``` @@ -1493,7 +1498,8 @@ and add the message ID as a property inside `execute`: msgId = messageId(message); if (this.inProgress[msgId]) { this.logger(msgId, 'already in progress'); - return next(done); + next(done); + return Promise.reject(); } this.inProgress[msgId] = true; ``` @@ -1583,16 +1589,17 @@ one more `middleware.execute` call _inside the callback_, and return the result of the assertion: ```js - result.should.become(helpers.ISSUE_URL).then(function() { - logger.info.args.should.include.something.that.deep.equals( - helpers.logArgs('already in progress')); + return result.should.become(helpers.ISSUE_URL).then(function() { + logger.info.args.should.include.something.that.deep.equals( + helpers.logArgs('already in progress')); + next.calledWith(hubotDone).should.be.true; - // Make another call to ensure that the ID is cleaned up. Normally the - // message will have a successReaction after the first successful - // request, but we'll test that in another case. - return middleware.execute(context, next, hubotDone) - .should.become(helpers.ISSUE_URL); - }); + // Make another call to ensure that the ID is cleaned up. Normally + // the message will have a successReaction after the first + // successful request, but we'll test that in another case. + return middleware.execute(context, next, hubotDone) + .should.become(helpers.ISSUE_URL); + }); ``` Again, in frameworks other than Mocha that don't have native `Promise` @@ -2086,7 +2093,8 @@ Middleware.prototype.execute = function(context, next, done) { JSON.stringify(context.response.message.rawMessage, null, 2); this.logger.error(null, errorMessage); context.response.reply(errorMessage); - return next(done); + next(done); + return Promise.reject(); } }; ``` diff --git a/_pages/testing-component-integration.md b/_pages/testing-component-integration.md index fdedbe4..27bb0db 100644 --- a/_pages/testing-component-integration.md +++ b/_pages/testing-component-integration.md @@ -81,7 +81,9 @@ module.exports = function(robot) { logger); robot.receiveMiddleware(function(context, next, done) { - impl.execute(context, next, done); + // Catch rejected Promises to avoid the UnhandledPromiseRejectionWarning + // in Node.js v6.6.0 and higher. + impl.execute(context, next, done).catch(function() { }); }); logger.info(null, 'registered receiveMiddleware'); }; @@ -703,7 +705,9 @@ module.exports = function(robot) { logger); robot.receiveMiddleware(function(context, next, done) { - impl.execute(context, next, done); + // Catch rejected Promises to avoid the UnhandledPromiseRejectionWarning + // in Node.js v6.6.0 and higher. + impl.execute(context, next, done).catch(function() { }); }); logger.info(null, 'registered receiveMiddleware'); @@ -976,7 +980,9 @@ module.exports = function(robot) { logger); middleware = function(context, next, done) { - impl.execute(context, next, done); + // Catch rejected Promises to avoid the UnhandledPromiseRejectionWarning + // in Node.js v6.6.0 and higher. + impl.execute(context, next, done).catch(function() { }); }; middleware.impl = impl; robot.receiveMiddleware(middleware); diff --git a/solutions/05-middleware/test/middleware-test.js b/solutions/05-middleware/test/middleware-test.js index 520b2b0..a5373d6 100644 --- a/solutions/05-middleware/test/middleware-test.js +++ b/solutions/05-middleware/test/middleware-test.js @@ -155,12 +155,13 @@ describe('Middleware', function() { result = middleware.execute(context, next, hubotDone); return middleware.execute(context, next, hubotDone) .should.be.rejectedWith(undefined).then(function() { - logger.info.args.should.include.something.that.deep.equals( - helpers.logArgs('already in progress')); - next.calledWith(hubotDone).should.be.true; return result.should.become(helpers.ISSUE_URL).then(function() { + logger.info.args.should.include.something.that.deep.equals( + helpers.logArgs('already in progress')); + next.calledWith(hubotDone).should.be.true; + // Make another call to ensure that the ID is cleaned up. Normally - // the message will have a successReaction after the first + // the message will have a successReaction after the first // successful request, but we'll test that in another case. return middleware.execute(context, next, hubotDone) .should.become(helpers.ISSUE_URL); diff --git a/solutions/06-integration/scripts/slack-github-issues.js b/solutions/06-integration/scripts/slack-github-issues.js index bafcf1c..57839f1 100644 --- a/solutions/06-integration/scripts/slack-github-issues.js +++ b/solutions/06-integration/scripts/slack-github-issues.js @@ -25,6 +25,8 @@ module.exports = function(robot) { logger); middleware = function(context, next, done) { + // Catch rejected Promises to avoid the UnhandledPromiseRejectionWarning + // in Node.js v6.6.0 and higher. impl.execute(context, next, done).catch(function() { }); }; middleware.impl = impl; diff --git a/solutions/07-system/scripts/slack-github-issues.js b/solutions/07-system/scripts/slack-github-issues.js index bafcf1c..57839f1 100644 --- a/solutions/07-system/scripts/slack-github-issues.js +++ b/solutions/07-system/scripts/slack-github-issues.js @@ -25,6 +25,8 @@ module.exports = function(robot) { logger); middleware = function(context, next, done) { + // Catch rejected Promises to avoid the UnhandledPromiseRejectionWarning + // in Node.js v6.6.0 and higher. impl.execute(context, next, done).catch(function() { }); }; middleware.impl = impl; diff --git a/solutions/complete/scripts/slack-github-issues.js b/solutions/complete/scripts/slack-github-issues.js index bafcf1c..57839f1 100644 --- a/solutions/complete/scripts/slack-github-issues.js +++ b/solutions/complete/scripts/slack-github-issues.js @@ -25,6 +25,8 @@ module.exports = function(robot) { logger); middleware = function(context, next, done) { + // Catch rejected Promises to avoid the UnhandledPromiseRejectionWarning + // in Node.js v6.6.0 and higher. impl.execute(context, next, done).catch(function() { }); }; middleware.impl = impl; diff --git a/solutions/complete/test/middleware-test.js b/solutions/complete/test/middleware-test.js index 520b2b0..a5373d6 100644 --- a/solutions/complete/test/middleware-test.js +++ b/solutions/complete/test/middleware-test.js @@ -155,12 +155,13 @@ describe('Middleware', function() { result = middleware.execute(context, next, hubotDone); return middleware.execute(context, next, hubotDone) .should.be.rejectedWith(undefined).then(function() { - logger.info.args.should.include.something.that.deep.equals( - helpers.logArgs('already in progress')); - next.calledWith(hubotDone).should.be.true; return result.should.become(helpers.ISSUE_URL).then(function() { + logger.info.args.should.include.something.that.deep.equals( + helpers.logArgs('already in progress')); + next.calledWith(hubotDone).should.be.true; + // Make another call to ensure that the ID is cleaned up. Normally - // the message will have a successReaction after the first + // the message will have a successReaction after the first // successful request, but we'll test that in another case. return middleware.execute(context, next, hubotDone) .should.become(helpers.ISSUE_URL);