Repository: mochajs/mocha

Problem statement:
Misleading source info in "done() called multiple times" message
The error message "done() called multiple times" will be associated with whatever part of the test suite that's currently running. This can lead to a lot of confusion for the uninitiated developer.

For example, consider the following suite:

``` javascript
describe("a simple test suite", function () {
    beforeEach(function (done) {
        setTimeout(done, 150);
    });
    afterEach(function (done) {
        setTimeout(done, 50);
        setTimeout(done, 100);
    });
    it("has a simple test", function (done) {
        setTimeout(done, 100);
    });
    it("has another simple test", function (done) {
        setTimeout(done, 100);
    });
});
```

Running `mocha done-message.js` will result in:

```
  ․․

  1 passing (356ms)
  1 failing

  1) a simple test suite "before each" hook:
     Uncaught Error: done() called multiple times
      at multiple (/usr/local/lib/node_modules/mocha/lib/runnable.js:175:31)
      at done (/usr/local/lib/node_modules/mocha/lib/runnable.js:181:26)
      at null._onTimeout (/usr/local/lib/node_modules/mocha/lib/runnable.js:197:9)
      at Timer.listOnTimeout [as ontimeout] (timers.js:110:15)
```

Note how the "done() called multiple times" will be listed having the `beforeEach` hook as the point where it came from. This is of course wrong, the `beforeEach` simply happens to be the active code part when the second `done()` call is being run. Additionally, the second test gets marked as a failure, even though it did nothing wrong!

I don't know Mocha's internals, so I don't know whether this can be fixed easily at all.  Some ideas:
- Pass a new `done` callback to the tests each time, that has the source information as a closure variable?
- Change the error reporting so that the `done` error message is not associated to any code part at all?
- Make it clear in the error message that this message can literally come from everywhere?
- Make double-done-calling a fatal error that causes the entire suite to stop and tell the user that the second call to `done` can come from anywhere?

Tested with Mocha 1.15.1. This issue may or may not be related to #990.

---

More examples:

``` javascript
describe("a simple test suite", function () {
    beforeEach(function (done) {
        setTimeout(done, 150);
    });
    afterEach(function (done) {
        setTimeout(done, 200);
        done();
    });
    it("has a simple test", function (done) {
        setTimeout(done, 100);
    });
    it("has another simple test", function (done) {
        setTimeout(done, 100);
    });
});
```

This will cause the error to be associated to the second test.

---

``` javascript
describe("a simple test suite", function () {
    beforeEach(function (done) {
        setTimeout(done, 150);
    });
    afterEach(function (done) {
        done();
        done();
    });
    it("has a simple test", function (done) {
        setTimeout(done, 100);
    });
    it("has another simple test", function (done) {
        setTimeout(done, 100);
    });
});
```

This will result in no error at all, even though `done` gets called multiple times!



Hints:
I ran into the same issue. Will be nice mocha can fix this. 

+1

Seeing this in version 1.19.0 as well. This does look to be the same issue as #990 but this report has simple code examples that demonstrate the problem. Perhaps @hallas won't dismiss this issue with obstinacy.

For me this turned out to be a library, sailsjs (based on express), that I was using calling its done callback multiple times.

Originally, my `after()` block looked like:

``` javascript
  after(function(done) {
    app.lower(done);
  });
```

I added in a check and arbitrary wait time:

``` javascript
after(function(done) {
  var done_called = false;
  app.lower(function() {
    if (!done_called) {
      done_called = true;
      setTimeout(function() {
          sails.log.debug("inside app.lower, callback not called yet. calling.");
          done();
      }, 1000);
    } else {
      sails.log.debug("inside app.lower, callback already called.");
    }
  });
});
```

This is not perfect but it allows me to call done once and use the `watch` feature of mocha. 


Patch:
diff --git a/lib/runnable.js b/lib/runnable.js
--- a/lib/runnable.js
+++ b/lib/runnable.js
@@ -45,6 +45,7 @@ function Runnable(title, fn) {
   this._slow = 75;
   this._enableTimeouts = true;
   this.timedOut = false;
+  this._trace = new Error('done() called multiple times')
 }
 
 /**
@@ -190,14 +191,14 @@ Runnable.prototype.run = function(fn){
   function multiple(err) {
     if (emitted) return;
     emitted = true;
-    self.emit('error', err || new Error('done() called multiple times'));
+    self.emit('error', err || new Error('done() called multiple times; stacktrace may be inaccurate'));
   }
 
   // finished
   function done(err) {
     var ms = self.timeout();
     if (self.timedOut) return;
-    if (finished) return multiple(err);
+    if (finished) return multiple(err || self._trace);
     self.clearTimeout();
     self.duration = new Date - start;
     finished = true;


Test patch:
diff --git a/test/acceptance/multiple.done.js b/test/acceptance/multiple.done.js
--- a/test/acceptance/multiple.done.js
+++ b/test/acceptance/multiple.done.js
@@ -12,4 +12,12 @@ describe('multiple calls to done()', function(){
       // done();
     });
   })
+
+  it('should produce a reasonable trace', function (done) {
+    process.nextTick(function() {
+      done();
+      // uncomment
+      // done()
+    })
+  });
 })