Fix #1798: Correctly attribute mutiple done err with hooks #1889

danielstjules · 2015-09-13T21:13:27Z

$ cat test.js
describe('suite', function() {
  before(function(done) {
    setTimeout(done, 30);
    setTimeout(done, 60);
  });

  it('test', function(done) {
    setTimeout(done, 100);
  });
});

// -------------------------------------------------------------
// Before PR, the error is incorrectly attributed to the spec,
// rather than the before hook. Furthermore, the error was
// uncaught, so that suite would stop
// -------------------------------------------------------------
$ mocha test.js


  suite
    1) test


  0 passing (67ms)
  1 failing

  1) suite test:
     Uncaught Error: done() called multiple times

// -------------------------------------------------------------
// After the PR, the error is correctly attributed to the hook
// -------------------------------------------------------------
$ mocha test.js


  ․․

  1 passing (141ms)
  1 failing

  1) suite "before all" hook:
     Error: done() called multiple times

danielstjules · 2015-09-13T21:37:26Z

setMaxListeners is to avoid some noise:

(node) warning: possible EventEmitter memory leak detected. 11 error listeners added. Use emitter.setMaxListeners() to increase limit.

I think this is preferable to the original solution: e673963

dasilvacontin · 2015-09-13T21:52:09Z

So hooks will end up having as many 'error' listeners as tests are run*? (in case of a 'beforeEach)

I don't even get why we set up the 'error' listener once each time before we run the hook. Why not set them up before running the suites and remove them after the suites are done/finished? The callback is always the same, afaik.

dasilvacontin · 2015-09-13T22:04:09Z

Yep, I just checked, and the "multiple done" error is the only 'error' event Runnable emits.

danielstjules · 2015-09-13T22:11:09Z

Just realized I could instead move hook.removeAllListeners('error'); which does a better job with beforeEach. Updated and pushed.

danielstjules · 2015-09-13T22:11:57Z

Why not set them up before running the suites and remove them after the suites are done/finished?

Because they could still emit an error after the suite finished, during a different suite's execution. Without leaving those listeners active, that'd result in an uncaught error

danielstjules · 2015-09-13T22:15:05Z

So hooks will end up having as many 'error' listeners as tests are run*? (in case of a 'beforeEach)

Updated code will have the same number of listeners as what's currently in master, except it won't remove the listeners once hook execution has completed (preventing the uncaught error issue)

dasilvacontin · 2015-09-14T06:04:34Z

Weird, locally, tests are stopping after 'acceptance/timeout.js'. After SIGINT: make: *** [test-jsapi] Interrupt: 2.

Works fine on Travis.

danielstjules · 2015-09-14T10:05:05Z

Does that happen on master for you as well? Or only this branch?

Edit: Ran off master and this branch, both succeeded with the same running time. So I think it's unrelated to this PR.

danielstjules · 2015-09-14T10:08:37Z

+1? :)

dasilvacontin · 2015-09-14T10:58:55Z

It does happen in master as well.. weird.

➜  mocha git:(master) node -v
v0.12.7

dasilvacontin · 2015-09-14T11:32:11Z

test/integration/multiple.done.js

+
+    it('results in a failure', function() {
+      assert.equal(res.stats.pending, 0);
+      assert.equal(res.stats.passes, 1);


Why is passes 1?

➜ mocha git:(danielstjules-issue-1798) ✗ mocha test/integration/fixtures/multiple.done.before.js ․ 0 passing (41ms) 1 failing 1) suite test1: Uncaught Error: done() called multiple times at Suite.<anonymous> (test/integration/fixtures/multiple.done.before.js:2:3) at Object.<anonymous> (test/integration/fixtures/multiple.done.before.js:1:63) at Array.forEach (native) at node.js:814:3

(same thing for most other tests)

More clear even:

➜ mocha git:(danielstjules-issue-1798) ✗ mocha test/integration/fixtures/multiple.done.before.js --reporter JSON { "stats": { "suites": 1, "tests": 1, "passes": 0, "pending": 0, "failures": 1, "start": "2015-09-14T11:33:37.794Z", "end": "2015-09-14T11:33:37.834Z", "duration": 40 },

Why is passes 1?

You're using the wrong bin. Use the project's local bin, rather than global mocha. Otherwise you're not actually running the branches' changes.

danielstjules:~/git/mocha (issue-1798) $ ./bin/mocha test/integration/fixtures/multiple.done.before.js --reporter JSON { "stats": { "suites": 1, "tests": 1, "passes": 1, "pending": 0, "failures": 1, "start": "2015-09-14T16:28:29.589Z", "end": "2015-09-14T16:28:29.658Z", "duration": 69 },

Since those hook errors were previously uncaught, the suite would exit. Now that they can be handled by the error listener, a given suite will continue to run. That's why we go from 0 to 1 passes.

I see. Since (at least in this case) we know that the before hook has failed before the test has finished running, couldn't we ignore the outcome of the test?

I mean, we obviously could ignore it, but what do you think about doing so?

I mean, we obviously could ignore it, but what do you think about doing so?

I don't think it's ideal. I think that leads to the same confusing output we see in scenarios like:

$ cat test.js beforeEach(function(done) { done(new Error('error')); }); it('test1', function(done) { setTimeout(done, 20); }); it('test1', function(done) { setTimeout(done, 20); }); $ mocha test.js 1) "before each" hook for "test1" 0 passing (11ms) 1 failing 1) "before each" hook for "test1": Error: error at Context.<anonymous> (test.js:2:8)

I'd also rather keep the scope of this PR small and push for a patch release, rather than make any major changes to runner behavior

I agree to keep the scope of the PR small. I'd like to discuss about it in a issue then. :)

dasilvacontin · 2015-09-14T12:15:28Z

Because they could still emit an error after the suite finished, during a different suite's execution. Without leaving those listeners active, that'd result in an uncaught error

Good point. Okay, then setting them up once and not removing them? How does that sound?

As a proof of concept, this passes your tests:

diff --git a/lib/runner.js b/lib/runner.js
index 1c91712..09cd414 100644
--- a/lib/runner.js
+++ b/lib/runner.js
@@ -285,13 +285,14 @@ Runner.prototype.hook = function(name, fn) {
     self.currentRunnable = hook;

     hook.ctx.currentTest = self.test;
-    hook.removeAllListeners('error');

     self.emit('hook', hook);

-    hook.on('error', function(err) {
-      self.failHook(hook, err);
-    });
+    if (EventEmitter.listenerCount(hook, 'error') === 0) {
+      hook.on('error', function(err) {
+        self.failHook(hook, err);
+      });
+    }

     hook.run(function(err) {
       var testError = hook.error();

danielstjules · 2015-09-14T16:45:22Z

Sure, that works :)

danielstjules · 2015-09-14T16:45:32Z

Updated the branch with that change

danielstjules · 2015-09-14T16:52:46Z

Used hook.listeners for node 0.8 support https://nodejs.org/docs/v0.8.0/api/events.html#events_emitter_listeners_event

danielstjules · 2015-09-14T18:19:30Z

@dasilvacontin @boneskull anymore feedback? :) Would love to merge this in

dasilvacontin · 2015-09-14T18:46:12Z

Used hook.listeners for node 0.8 support https://nodejs.org/docs/v0.8.0/api/events.html#events_emitter_listeners_event

Cool, I hadn't seen that one.

Well, that was just for showing it worked. What about setting up the hook listeners in a loop before running the suite? It'd be cleaner imo. Something similar to this, but extracted in a nice documented function. (this also passes tests)

@@ -630,6 +624,17 @@ Runner.prototype.runSuite = function(suite, fn) {

   this.nextSuite = next;

+  var hookNames = ['beforeAll', 'beforeEach', 'afterEach', 'afterAll']
+  hookNames.forEach(function (hookName) {
+    var hooks = self.suite['_' + hookName]
+    if (!hooks.length) return
+    hooks.forEach(function (hook) {
+      hook.on('error', function (err) {
+        self.failHook(hook, err)
+      })
+    })
+  })
+
   this.hook('beforeAll', function(err) {
     if (err) {
       return done();

danielstjules · 2015-09-14T18:52:05Z

Sounds like a later PR could address that if it's just refactoring :) I like that this was almost a one line change haha

Edit: Would need to get rid of both forEach since we don't have an ES5 shim for old IEs. So my vote is to save that for another PR :)

dasilvacontin · 2015-09-14T19:01:03Z

Just refactoring. :)

LGTM then, good job!

Fix #1798: Correctly attribute mutiple done err with hooks

dasilvacontin reviewed Sep 14, 2015
View reviewed changes

Fix #1798: Correctly attribute mutiple done err with hooks

10e8604

danielstjules mentioned this pull request Sep 14, 2015

specify type of runnable in multiple done error #1890

Closed

dasilvacontin added a commit that referenced this pull request Sep 14, 2015

Merge pull request #1889 from danielstjules/issue-1798

23b2955

Fix #1798: Correctly attribute mutiple done err with hooks

dasilvacontin merged commit 23b2955 into mochajs:master Sep 14, 2015

danielstjules deleted the issue-1798 branch September 14, 2015 19:02

marekventur mentioned this pull request Dec 14, 2015

Update "mocha" to version ~2.3.4 gluckgames/pixi-packer#17

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix #1798: Correctly attribute mutiple done err with hooks #1889

Fix #1798: Correctly attribute mutiple done err with hooks #1889

danielstjules commented Sep 13, 2015

danielstjules commented Sep 13, 2015

dasilvacontin commented Sep 13, 2015

dasilvacontin commented Sep 13, 2015

danielstjules commented Sep 13, 2015

danielstjules commented Sep 13, 2015

danielstjules commented Sep 13, 2015

dasilvacontin commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

dasilvacontin commented Sep 14, 2015

dasilvacontin Sep 14, 2015

dasilvacontin Sep 14, 2015

danielstjules Sep 14, 2015

danielstjules Sep 14, 2015

dasilvacontin Sep 14, 2015

dasilvacontin Sep 14, 2015

danielstjules Sep 14, 2015

danielstjules Sep 14, 2015

dasilvacontin Sep 14, 2015

dasilvacontin commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

dasilvacontin commented Sep 14, 2015

danielstjules commented Sep 14, 2015

dasilvacontin commented Sep 14, 2015

Fix #1798: Correctly attribute mutiple done err with hooks #1889

Fix #1798: Correctly attribute mutiple done err with hooks #1889

Conversation

danielstjules commented Sep 13, 2015

danielstjules commented Sep 13, 2015

dasilvacontin commented Sep 13, 2015

dasilvacontin commented Sep 13, 2015

danielstjules commented Sep 13, 2015

danielstjules commented Sep 13, 2015

danielstjules commented Sep 13, 2015

dasilvacontin commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

dasilvacontin commented Sep 14, 2015

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

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dasilvacontin commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

danielstjules commented Sep 14, 2015

dasilvacontin commented Sep 14, 2015

danielstjules commented Sep 14, 2015

dasilvacontin commented Sep 14, 2015