process: add multipleResolves event

This adds the `multipleResolves` event to track promises that resolve more than once or that reject after resolving. It is important to expose this to the user to make sure the application runs as expected. Without such warnings it would be very hard to debug these situations. PR-URL: #22218 Fixes: nodejs/promises-debugging#8 Reviewed-By: Matteo Collina <[email protected]> Reviewed-By: Benjamin Gruenbaum <[email protected]> Reviewed-By: Franziska Hinkelmann <[email protected]> Reviewed-By: Anatoli Papirovski <[email protected]>
nodejs · Sep 25, 2018 · 66484b8 · 66484b8
1 parent f66e9ab
commit 66484b8
Show file tree

Hide file tree

Showing 6 changed files with 177 additions and 35 deletions.
diff --git a/doc/api/process.md b/doc/api/process.md
@@ -97,6 +97,59 @@ the child process.
 The message goes through serialization and parsing. The resulting message might
 not be the same as what is originally sent.
 
+### Event: 'multipleResolves'
+<!-- YAML
+added: REPLACEME
+-->
+
+* `type` {string} The error type. One of `'resolve'` or `'reject'`.
+* `promise` {Promise} The promise that resolved or rejected more than once.
+* `value` {any} The value with which the promise was either resolved or
+  rejected after the original resolve.
+
+The `'multipleResolves'` event is emitted whenever a `Promise` has been either:
+
+* Resolved more than once.
+* Rejected more than once.
+* Rejected after resolve.
+* Resolved after reject.
+
+This is useful for tracking errors in your application while using the promise
+constructor. Otherwise such mistakes are silently swallowed due to being in a
+dead zone.
+
+It is recommended to end the process on such errors, since the process could be
+in an undefined state. While using the promise constructor make sure that it is
+guaranteed to trigger the `resolve()` or `reject()` functions exactly once per
+call and never call both functions in the same call.
+
+```js
+process.on('multipleResolves', (type, promise, reason) => {
+  console.error(type, promise, reason);
+  setImmediate(() => process.exit(1));
+});
+
+async function main() {
+  try {
+    return await new Promise((resolve, reject) => {
+      resolve('First call');
+      resolve('Swallowed resolve');
+      reject(new Error('Swallowed reject'));
+    });
+  } catch {
+    throw new Error('Failed');
+  }
+}
+
+main().then(console.log);
+// resolve: Promise { 'First call' } 'Swallowed resolve'
+// reject: Promise { 'First call' } Error: Swallowed reject
+//     at Promise (*)
+//     at new Promise (<anonymous>)
+//     at main (*)
+// First call
+```
+
 ### Event: 'rejectionHandled'
 <!-- YAML
 added: v1.4.1

diff --git a/lib/internal/process/promises.js b/lib/internal/process/promises.js
@@ -5,15 +5,37 @@ const { safeToString } = process.binding('util');
 const maybeUnhandledPromises = new WeakMap();
 const pendingUnhandledRejections = [];
 const asyncHandledRejections = [];
+const promiseRejectEvents = {};
 let lastPromiseId = 0;
 
 exports.setup = setupPromises;
 
 function setupPromises(_setupPromises) {
-  _setupPromises(unhandledRejection, handledRejection);
+  _setupPromises(handler, promiseRejectEvents);
   return emitPromiseRejectionWarnings;
 }
 
+function handler(type, promise, reason) {
+  switch (type) {
+    case promiseRejectEvents.kPromiseRejectWithNoHandler:
+      return unhandledRejection(promise, reason);
+    case promiseRejectEvents.kPromiseHandlerAddedAfterReject:
+      return handledRejection(promise);
+    case promiseRejectEvents.kPromiseResolveAfterResolved:
+      return resolveError('resolve', promise, reason);
+    case promiseRejectEvents.kPromiseRejectAfterResolved:
+      return resolveError('reject', promise, reason);
+  }
+}
+
+function resolveError(type, promise, reason) {
+  // We have to wrap this in a next tick. Otherwise the error could be caught by
+  // the executed promise.
+  process.nextTick(() => {
+    process.emit('multipleResolves', type, promise, reason);
+  });
+}
+
 function unhandledRejection(promise, reason) {
   maybeUnhandledPromises.set(promise, {
     reason,
@@ -45,16 +67,6 @@ function handledRejection(promise) {
 
 const unhandledRejectionErrName = 'UnhandledPromiseRejectionWarning';
 function emitWarning(uid, reason) {
-  try {
-    if (reason instanceof Error) {
-      process.emitWarning(reason.stack, unhandledRejectionErrName);
-    } else {
-      process.emitWarning(safeToString(reason), unhandledRejectionErrName);
-    }
-  } catch (e) {
-    // ignored
-  }
-
   // eslint-disable-next-line no-restricted-syntax
   const warning = new Error(
     'Unhandled promise rejection. This error originated either by ' +
@@ -66,10 +78,12 @@ function emitWarning(uid, reason) {
   try {
     if (reason instanceof Error) {
       warning.stack = reason.stack;
+      process.emitWarning(reason.stack, unhandledRejectionErrName);
+    } else {
+      process.emitWarning(safeToString(reason), unhandledRejectionErrName);
     }
-  } catch (err) {
-    // ignored
-  }
+  } catch {}
+
   process.emitWarning(warning);
   emitDeprecationWarning();
 }

diff --git a/src/bootstrapper.cc b/src/bootstrapper.cc
@@ -12,8 +12,13 @@ using v8::Context;
 using v8::Function;
 using v8::FunctionCallbackInfo;
 using v8::Isolate;
+using v8::kPromiseHandlerAddedAfterReject;
+using v8::kPromiseRejectAfterResolved;
+using v8::kPromiseRejectWithNoHandler;
+using v8::kPromiseResolveAfterResolved;
 using v8::Local;
 using v8::MaybeLocal;
+using v8::Number;
 using v8::Object;
 using v8::Promise;
 using v8::PromiseRejectEvent;
@@ -61,34 +66,40 @@ void PromiseRejectCallback(PromiseRejectMessage message) {
   PromiseRejectEvent event = message.GetEvent();
 
   Environment* env = Environment::GetCurrent(isolate);
+
   if (env == nullptr) return;
-  Local<Function> callback;
+
+  Local<Function> callback = env->promise_handler_function();
   Local<Value> value;
+  Local<Value> type = Number::New(env->isolate(), event);
 
-  if (event == v8::kPromiseRejectWithNoHandler) {
-    callback = env->promise_reject_unhandled_function();
+  if (event == kPromiseRejectWithNoHandler) {
     value = message.GetValue();
-
-    if (value.IsEmpty())
-      value = Undefined(isolate);
-
     unhandledRejections++;
-  } else if (event == v8::kPromiseHandlerAddedAfterReject) {
-    callback = env->promise_reject_handled_function();
+    TRACE_COUNTER2(TRACING_CATEGORY_NODE2(promises, rejections),
+                  "rejections",
+                  "unhandled", unhandledRejections,
+                  "handledAfter", rejectionsHandledAfter);
+  } else if (event == kPromiseHandlerAddedAfterReject) {
     value = Undefined(isolate);
-
     rejectionsHandledAfter++;
+    TRACE_COUNTER2(TRACING_CATEGORY_NODE2(promises, rejections),
+                  "rejections",
+                  "unhandled", unhandledRejections,
+                  "handledAfter", rejectionsHandledAfter);
+  } else if (event == kPromiseResolveAfterResolved) {
+    value = message.GetValue();
+  } else if (event == kPromiseRejectAfterResolved) {
+    value = message.GetValue();
   } else {
     return;
   }
 
-  TRACE_COUNTER2(TRACING_CATEGORY_NODE2(promises, rejections),
-                 "rejections",
-                 "unhandled", unhandledRejections,
-                 "handledAfter", rejectionsHandledAfter);
-
+  if (value.IsEmpty()) {
+    value = Undefined(isolate);
+  }
 
-  Local<Value> args[] = { promise, value };
+  Local<Value> args[] = { type, promise, value };
   MaybeLocal<Value> ret = callback->Call(env->context(),
                                          Undefined(isolate),
                                          arraysize(args),
@@ -103,11 +114,17 @@ void SetupPromises(const FunctionCallbackInfo<Value>& args) {
   Isolate* isolate = env->isolate();
 
   CHECK(args[0]->IsFunction());
-  CHECK(args[1]->IsFunction());
+  CHECK(args[1]->IsObject());
+
+  Local<Object> constants = args[1].As<Object>();
+
+  NODE_DEFINE_CONSTANT(constants, kPromiseRejectWithNoHandler);
+  NODE_DEFINE_CONSTANT(constants, kPromiseHandlerAddedAfterReject);
+  NODE_DEFINE_CONSTANT(constants, kPromiseResolveAfterResolved);
+  NODE_DEFINE_CONSTANT(constants, kPromiseRejectAfterResolved);
 
   isolate->SetPromiseRejectCallback(PromiseRejectCallback);
-  env->set_promise_reject_unhandled_function(args[0].As<Function>());
-  env->set_promise_reject_handled_function(args[1].As<Function>());
+  env->set_promise_handler_function(args[0].As<Function>());
 }
 
 #define BOOTSTRAP_METHOD(name, fn) env->SetMethod(bootstrapper, #name, fn)

diff --git a/src/env.h b/src/env.h
@@ -342,8 +342,7 @@ struct PackageConfig {
   V(performance_entry_callback, v8::Function)                                 \
   V(performance_entry_template, v8::Function)                                 \
   V(process_object, v8::Object)                                               \
-  V(promise_reject_handled_function, v8::Function)                            \
-  V(promise_reject_unhandled_function, v8::Function)                          \
+  V(promise_handler_function, v8::Function)                                   \
   V(promise_wrap_template, v8::ObjectTemplate)                                \
   V(push_values_to_array_function, v8::Function)                              \
   V(sab_lifetimepartner_constructor_template, v8::FunctionTemplate)           \

diff --git a/test/message/unhandled_promise_trace_warnings.out b/test/message/unhandled_promise_trace_warnings.out
@@ -34,6 +34,7 @@
     at *
 (node:*) PromiseRejectionHandledWarning: Promise rejection was handled asynchronously (rejection id: 1)
     at handledRejection (internal/process/promises.js:*)
+    at handler (internal/process/promises.js:*)
     at Promise.then *
     at Promise.catch *
     at Immediate.setImmediate (*test*message*unhandled_promise_trace_warnings.js:*)

diff --git a/test/parallel/test-promise-swallowed-event.js b/test/parallel/test-promise-swallowed-event.js
@@ -0,0 +1,58 @@
+'use strict';
+
+const common = require('../common');
+const assert = require('assert');
+
+const rejection = new Error('Swallowed reject');
+const rejection2 = new TypeError('Weird');
+const resolveMessage = 'First call';
+const rejectPromise = new Promise((r) => setTimeout(r, 10, rejection2));
+const swallowedResolve = 'Swallowed resolve';
+const swallowedResolve2 = 'Foobar';
+
+process.on('multipleResolves', common.mustCall(handler, 4));
+
+const p1 = new Promise((resolve, reject) => {
+  resolve(resolveMessage);
+  resolve(swallowedResolve);
+  reject(rejection);
+});
+
+const p2 = new Promise((resolve, reject) => {
+  reject(rejectPromise);
+  resolve(swallowedResolve2);
+  reject(rejection2);
+}).catch(common.mustCall((exception) => {
+  assert.strictEqual(exception, rejectPromise);
+}));
+
+const expected = [
+  'resolve',
+  p1,
+  swallowedResolve,
+  'reject',
+  p1,
+  rejection,
+  'resolve',
+  p2,
+  swallowedResolve2,
+  'reject',
+  p2,
+  rejection2
+];
+
+let count = 0;
+
+function handler(type, promise, reason) {
+  assert.strictEqual(type, expected.shift());
+  // In the first two cases the promise is identical because it's not delayed.
+  // The other two cases are not identical, because the `promise` is caught in a
+  // state when it has no knowledge about the `.catch()` handler that is
+  // attached to it right afterwards.
+  if (count++ < 2) {
+    assert.strictEqual(promise, expected.shift());
+  } else {
+    assert.notStrictEqual(promise, expected.shift());
+  }
+  assert.strictEqual(reason, expected.shift());
+}