promise: warn on unhandled rejections #6439

benjamingr · 2016-04-28T08:11:37Z

Moderator's note (Fishrock123): If you leave "+1" comments, I will remove them. Please use a reaction (the thumbs up button) on this post. Thanks.

I think that we all agree that the current default behavior in node for unhandled rejections is very wrong, people running code that behaved well in browsers suddenly get their exceptions swallowed by default and have to read the process docs and dig up an API. Programmer errors are swallowed by default and are very hard to find.

This makes NodeJS a lot less approachable to promise users* which are slowly but surely becoming a majority as web APIs switch to promises and a lot already have.

This pull request suggests

We log the exception with a GUID when unhandledRejection happens and the text "Warning: Possibly unhandled rejection in ...". It is treated as a warning and not an error - we use the new process.warning API that @jasnell has suggested so it is treated like a warning and not an error.
We log a "Possibly unhandled rejection eventually handled" message (also, as a warning) when that error is taken care of.

This approach has the following advantages:

Most backwards compatible with the current behavior while solving the issue for 99% of users.
This takes care of the "always right" issue as it's a warning and there might be valid use cases for not handling it. Kind of like the very helpful EventEmitter # of subscribers warning.
Users hooking on warnings have this dealt with like other warnings, they can suppress it in production, deal with it or do anything else.
Users installing custom handlers have nothing broken in their code and everything proceeds as normal.
Easy to override this behavior either at the promise or warning level.

@jasnell

I think that we all _agree_ that the current default behavior in node for unhandled rejections is very wrong, people running code that behaved well in browsers suddenly get their exceptions swallowed by default and have to read the process docs and dig up an API. Programmer errors are swallowed by default and are very hard to find. This makes NodeJS a lot less approachable to promise users* which are slowly but surely becoming a majority as web APIs switch to promises and a lot already have. This pull request suggests - We log the exception with a GUID when `unhandledRejection` happens and the text "Warning: Possibly unhandled rejection in ...". It is treated as a _warning_ and not an error - we use the new `process.warning` API that @jasnell has suggested so it is treated like a warning and not an error. - We log a "Possibly unhandled rejection eventually handled" message (also, as a warning) when that error is taken care of. This approach has the following advantages: - Most backwards compatible with the current behavior while solving the issue for 99% of users. - This takes care of the "always right" issue as it's a warning and there might be valid use cases for not handling it. Kind of like the very helpful EventEmitter # of subscribers warning. - Users hooking on warnings have this dealt with like other warnings, they can suppress it in production, deal with it or do anything else. - Users installing custom handlers have nothing broken in their code and everything proceeds as normal. - Easy to override this behavior either at the promise or warning level.

benjamingr · 2016-04-28T08:13:22Z

@trevnorris @vkurchatkin @jasnell @petkaantonov @chrisdickinson @ChALkeR

Also for context #6375
Also for context #830
Also for context nodejs/promises#26

Fishrock123 · 2016-04-28T13:46:41Z

As I've previously mentioned this sets us up for further inconsistency, and should only be considered for branches that cannot take breaking changes.

(Formally: -1 on master, -1 on other branches without a better solution on master.)

sagivo · 2016-04-28T15:43:50Z

lib/internal/process/promises.js

@@ -2,6 +2,8 @@

 const promiseRejectEvent = process._promiseRejectEvent;
 const hasBeenNotifiedProperty = new WeakMap();
+const promiseToGuidProperty = new WeakMap();
+var lastPromiseId = 1;


maybe let ?

jasnell · 2016-04-28T16:18:51Z

While I would definitely prefer a longer term solution, I think this works well for an interim approach.

trevnorris · 2016-04-28T16:45:36Z

I think this is a reasonable approach, but may agree with @Fishrock123 that this should probably be more for branches that can't receive breaking changes. i.e. Can land in master, but this should be considered the long-term solution.

jasnell · 2016-04-28T16:47:21Z

just a quick note: process.emitWarning exists in v6 and v5 but not v4 (afaik).

Fishrock123 · 2016-04-28T16:48:43Z

@jasnell Maybe we should add the internal logic to older versions, but not expose it? I don't think that is worth backporting.

Fishrock123 · 2016-04-28T16:50:19Z

lib/internal/process/promises.js

        if (!process.emit('unhandledRejection', reason, promise)) {
-          // Nobody is listening.
-          // TODO(petkaantonov) Take some default action, see #830
+          process.emitWarning('Possibly unhandled promise rejection ' 


I don't think we should double emit. Why not just print it, or use the internal warning logic directly?

I also definitely don't think this should be "catchable" in the warning event handler. People should use unhandledRejection directly for these, whatever our final conclusion is.

Well, the point of this PR was to use @jasnell's idea of treating them as warnings.

If we consider them warning and not errors initially I see double benefit:

A) It's theoretically sound, since we're not claiming it's an error but a warning (like adding a lot of listeners to an EventEmitter).
B) It's easy to turn off in production or log cleanly using whatever infrastructure people use for warnings.

Note that rejections are pretty rare (like actual exceptions) and unhandled rejections even more so - so the performance penalty here is negligible.

By emitting a warning rather than directly printing an error - I think we're leaving a much bigger opportunity for a long term solution: people realize warnings might go away, can be turned off, can be reported to another channel than errors and so on.

This does not contradict a "throw on unhandled GC" or another "long term" solution. It does solve the problem of promises being terribly hard for users to debug with the current default which is what people always complain about in StackOverflow and forums.

I think it's a reasonable compromise and that we haven't been fair to our users since we landed 'unhandledRejection'. I take personal blame for not pushing harder on a reasonable solution for users for over a year.

We could potentially check the listener count for unhandledRejection first and only emit if it's greater than zero, otherwise emit the warning.

This is precisely the kind of thing emitWarning is for. -1 for printing directly.

I'm happy with emitWarning here — the value in double emitting is that, as a user of a system that is designed around NDJSON-based logs, I can easily hook into the warning system and turn this message into a JSON log (vs. having to rely on patching out console.)

I'd quibble that we should probably log this as an Unhandled promise rejection, versus "possibly unhandled promise rejection." At the moment of logging, the promise is unhandled, and we cannot say whether or not it will be handled in the future. If it is possible for the rejection to become handled, that case will be caught by the "rejection handled" warning.

@jasnell what you are describing is exactly the behavior in this PR, emitWarning is only called if there are no unhandledRejection listeners :)

@chrisdickinson's point makes sense.

jasnell · 2016-04-28T16:52:02Z

Agree that it's not worth porting process.emitWarning() back to v4 but the basic internals could easily be backported and an internal version of emitWarning() provided. The only difference would be that we can't do deprecations using it, so there would definitely be some differences.

chrisdickinson · 2016-04-28T21:01:47Z

I note that, if we decide to crash on unhandled rejection by default, it'd have to be in a major version, and the changes represented by this PR would serve as an excellent deprecation warning ahead of time. (I am aware we haven't agreed on that direction, though!)

I'm going to plan on revisiting the PR this evening after thinking about it more.

chrisdickinson · 2016-04-29T05:47:07Z

OK! Revisiting now, as promised!

Aside from some minor wording nits which I'll get to after this comment, I am in favor of these changes landing on v5 and v6. I'm +0 on landing these on v4, depending on how complicated it is to backport the warning logic. I'm still pretty convinced that ultimately we should crash on unhandled rejection by default, but that's something we can revisit and maybe we run an impromptu hangout about.

jasnell · 2016-04-29T06:08:48Z

The code change itself LGTM pending CI .. update: And a test! Almost forgot to mention this needs a test case to verify the warning is emitted.
The overall direction is +1 so long as we keep working towards a better long term approach.

ChALkeR · 2016-04-29T06:30:03Z

-1 on v4, +1 on other branches (including master until we have a better solution, if there would be any), +1 on v4 behind a flag.

I don't think that introducing such additional warnings without a flag on LTS would be a great idea.

jasnell · 2016-04-29T06:33:04Z

@ChALkeR ... I tend to agree with regards to v4

ChALkeR · 2016-04-29T06:34:23Z

Btw, +1 to throwing on unhandled rejection in the next major, but only if this warning would be landed in v6.

petkaantonov · 2016-04-29T11:43:22Z

As I've previously mentioned this sets us up for further inconsistency

Node already has a precedent for warnings that can be false positive, the event emitter warning about 10 listeners. I even expect this PR to give less false positives than the event emitter warning. It would also be the primary way of discovering that it's possible to attach the 'unhandledRejection' event listener, people don't really discover it through docs.

benjamingr · 2016-04-29T16:52:57Z

I'm -1 on backporting it to v4 or v5 without letting it stay in v6 for at least 2-3 weeks first. While I believe reception of this will be very positive I'd rather wait a little first and see how things go.

Also note I commented inline to #6439 (comment) in code comments.

Copying most of my post from nodejs/promises#26 :

My proposal is to use the new process.emitWarning API to treat unhandled rejections as warnings (but not errors), this is effectively a relaxation of the "log on unhandled rejection" option since it is treated as a warning and not an error and can be handled with either installing a unhandledRejection handler or by disabling warnings in Node (for example in production). It is meant to address the ergonomics point of view.

@Fishrock123 's proposal is to abort on unhandled rejections once we are absolutely sure they are unhandled (by hooking into garbage collection), this is effectively a relaxation of "throwing an error" option addressing the problem in that option of not being sure 100% it is thrown - aligning it with regular exceptions.

Please drop by at these issues and leave a comment.

jasnell · 2016-04-29T18:08:47Z

@benjamingr ... can definitely live with that

benjamingr · 2016-05-01T16:04:07Z

All the nits handled. PTAL.

I'm ready to merge.

jasnell · 2016-05-01T17:57:44Z

CI: https://ci.nodejs.org/job/node-test-pull-request/2452/

Is it possible to include a test case? (#6439 (comment))

benjamingr · 2016-05-01T19:14:32Z

@jasnell cool, I'll fix the lint errors - I'm definitely in favor of a test but I'm not sure what the correct way to write one would be. Would something like:

Promise.reject();
process.on("warning", function(err) {
   assert(err instanceof UnhandledPromiseRejectionWarning);
});

Or something of the sort be sufficient? (to /test/parallel) do I add to https://github.com/nodejs/node/blob/master/test/parallel/test-promises-unhandled-rejections.js instead?

I deliberately put the branch on nodejs/node in case anyone else wants to weigh in - so feel free to add tests before the merge or I will but I would appreciate guidance.

I'd also love a +1 from @Fishrock123 (under the assumption we are going to continue work on more long term solutions). It would mean a lot to me personally even if we already have a lot of +1s and I would rather not merge until we exhausted discussion.

jasnell · 2016-05-01T19:55:37Z

test-promises-unhandled-rejections.js is already pretty massive. If I were doing it, I'd just create a new test with something similar to what you suggest. You'd need to watch for:

process.on('warning', common.mustCall((warning) => {
  /* check the warning in here */
});

The warning object passed to the warning event is just an Error object so you can look at the name, message and stack. message is the one you'll want to pay attention to.

jasnell · 2016-05-01T19:57:33Z

Btw, when you call process.emitWarning(), you can pass a second argument in that sets the name of the warning .. so if you wanted it to be something like UnhandledPromiseRejectionWarning, you can call process.emitWarning(message, 'UnhandledPromiseRejectionWarning').

benjamingr · 2016-05-05T09:39:47Z

@Fishrock123 ping

Fishrock123 · 2016-05-05T15:15:23Z

lib/internal/process/promises.js

      if (hasBeenNotified === true) {
        process.nextTick(function() {
-          process.emit('rejectionHandled', promise);
+          if(!process.emit('rejectionHandled', promise)) {
+            process.emitWarning('Promise Rejection Handled Asynchronously'


feels a bit weird that this warns?

Fishrock123 · 2016-05-05T15:16:00Z

I'd prefer the warnings to be UnhandledRejectionWarning and RejectionHandledWarning... bit weird that the last is a warning tho

Fishrock123 · 2016-05-05T15:16:51Z

lib/internal/process/promises.js

 const pendingUnhandledRejections = [];
+let lastPromiseId = 1;


var is a little more efficient still iirc

Fishrock123 · 2016-05-05T15:20:20Z

Seems ok. We should probably discuss a bit if we want to do anything further after this before landing..

@chrisdickinson Have you thought about this more?

Fishrock123 · 2016-05-05T15:21:17Z

Oh and, also needs tests.

Additionally, I'd like to actually try it but I don't have time at the current moment.

jasnell · 2016-06-07T14:21:45Z

Anything further on this?

benjamingr · 2016-06-07T14:25:33Z

I need to make a few small fixes and then we can land this, sadly I'm at a location where I don't have the source checked out and have a problem checking it out so I can't land or modify anything.

If you (or anyone) feels like taking over (basically - fixint the lint nits, adding a test and landing) I would appreciate it - otherwise it will be around 2 more weeks. I think this change would help a lot of users.

If you're interested let me know and I'll give you collaborator at benjamingr/io.js

Fishrock123 · 2016-06-15T15:48:12Z

We should state in the docs that this is the default but that we may change to throwing in the future (see await/async discussion I think)

jasnell · 2016-08-05T22:44:35Z

ping @benjamingr ... just checking in on this. No rush. If you're not able to get to it then I can take a look at it next week.

jasnell · 2016-08-21T22:41:43Z

Continuing the work on this here: #8217

As discovered in 18F#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 Test failures from `test/integration-test.js` after upgrading to Node v6.9.1 showed extra output such as: ``` (node:39696) UnhandledPromiseRejectionWarning: Unhandled promise rejection (rejection id: 2): null (node:39696) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 2) ``` This was happening because `scripts/slack-github-issues.js` created a Hubot listener that returned a `Promise` so that the integration test could use `.should.be.rejectedWith` assertions. Rather than jump through hoops to quash the warnings, this change now causes the listener's `catch` handler to return the result of the rejected `Promise`, converting it to a fulfilled `Promise` in the process. Since Hubot never used the result anyway, the only effect it has in production is to eliminate the warning messages. The tests now just check that the `Promise` returned by the listener callback is fulfilled with the expected error result, with practically no loss in clarity.

Add a configuration flag that prevents mdb_v8.so from being built. The default behavior is still the same and mdb_v8.so is built by default on Solaris based platforms such as SmartOS. Using --without-mdb fixes build issues on Solaris based platforms where libproc.h is not available or not compatible with the one shipped by SmartOS. Fixes nodejs#6439. Reviewed-By: Julien Gilli <[email protected]> PR-URL: nodejs/node-v0.x-archive#25707

TimothyGu · 2017-02-27T03:18:02Z

Deleting the stale branch.

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.

benjamingr added process Issues and PRs related to the process subsystem. promises Issues and PRs related to ECMAScript promises. labels Apr 28, 2016

yosuke-furukawa mentioned this pull request Apr 28, 2016

promise: Add --throw-unhandled-rejection and --trace-unhandled-rejection #6355

Closed

4 tasks

benjamingr mentioned this pull request Apr 28, 2016

lib,src: "throw" on unhandled promise rejections #6375

Closed

4 tasks

sagivo reviewed Apr 28, 2016
View reviewed changes

Fishrock123 reviewed Apr 28, 2016
View reviewed changes

benjamingr self-assigned this Apr 29, 2016

Fishrock123 added the semver-minor PRs that contain new features and should be released in the next minor version. label Apr 29, 2016

benjamingr mentioned this pull request Apr 29, 2016

Default Unhandled Rejection Behavior nodejs/promises#26

Closed

address feedback

cbe6780

Fishrock123 reviewed May 5, 2016
View reviewed changes

vkurchatkin mentioned this pull request May 6, 2016

What’s the status of Promises in the core? nodejs/promises#27

Closed

jasnell self-assigned this Aug 18, 2016

jasnell mentioned this pull request Aug 21, 2016

promise: warning on unhandled rejection #8217

Closed

3 tasks

jasnell closed this Aug 21, 2016

mbland mentioned this pull request Dec 1, 2016

Integration test fixes in light of new Promise warnings mbland/hubot-slack-github-issues#7

Merged

TimothyGu deleted the log-unhandled branch February 27, 2017 03:18

		const pendingUnhandledRejections = [];
		let lastPromiseId = 1;

promise: warn on unhandled rejections #6439

promise: warn on unhandled rejections #6439

Conversation

benjamingr commented Apr 28, 2016 • edited by Fishrock123 Loading

benjamingr commented Apr 28, 2016

Fishrock123 commented Apr 28, 2016 • edited Loading

Choose a reason for hiding this comment

jasnell commented Apr 28, 2016

trevnorris commented Apr 28, 2016

jasnell commented Apr 28, 2016

Fishrock123 commented Apr 28, 2016

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

jasnell commented Apr 28, 2016 • edited Loading

chrisdickinson commented Apr 28, 2016

chrisdickinson commented Apr 29, 2016

jasnell commented Apr 29, 2016 • edited Loading

ChALkeR commented Apr 29, 2016

jasnell commented Apr 29, 2016

ChALkeR commented Apr 29, 2016

petkaantonov commented Apr 29, 2016 • edited Loading

benjamingr commented Apr 29, 2016 • edited Loading

jasnell commented Apr 29, 2016

benjamingr commented May 1, 2016

jasnell commented May 1, 2016

benjamingr commented May 1, 2016 • edited Loading

jasnell commented May 1, 2016

jasnell commented May 1, 2016

benjamingr commented May 5, 2016

Choose a reason for hiding this comment

Fishrock123 commented May 5, 2016

Choose a reason for hiding this comment

Fishrock123 commented May 5, 2016 • edited Loading

Fishrock123 commented May 5, 2016

jasnell commented Jun 7, 2016

benjamingr commented Jun 7, 2016 • edited Loading

Fishrock123 commented Jun 15, 2016

jasnell commented Aug 5, 2016

jasnell commented Aug 21, 2016

TimothyGu commented Feb 27, 2017

benjamingr commented Apr 28, 2016 •

edited by Fishrock123

Loading

Fishrock123 commented Apr 28, 2016 •

edited

Loading

jasnell commented Apr 28, 2016 •

edited

Loading

jasnell commented Apr 29, 2016 •

edited

Loading

petkaantonov commented Apr 29, 2016 •

edited

Loading

benjamingr commented Apr 29, 2016 •

edited

Loading

benjamingr commented May 1, 2016 •

edited

Loading

Fishrock123 commented May 5, 2016 •

edited

Loading

benjamingr commented Jun 7, 2016 •

edited

Loading