Async Express.js function with invalid reference hangs Mocha without an error or stack trace

[codingthat]

Prerequisites

• Checked that your issue hasn't already been filed by cross-referencing issues with the faq label
• (sort of? it is a bug in my code, but like this, debugging is overly complicated) Checked next-gen ES issues and syntax problems by using the same environment and/or transpiler configuration without Mocha to ensure it isn't just a feature that actually isn't supported in the environment in question or a bug in your code.
• (ibid) 'Smoke tested' the code to be tested by running it outside the real test suite to get a better sense of whether the problem is in the code under test, your usage of Mocha, or Mocha itself
• Ensured that there is no discrepancy between the locally and globally installed versions of Mocha. You can find them with: node node_modules/.bin/mocha --version(Local) and mocha --version(Global). We recommend that you not install Mocha globally. ← confirmed Mocha is not installed globally; local is at latest 8.3.2

Description

If an async function is serving up an Express.js endpoint, and that function causes a runtime TypeError, Mocha times out, then hangs, and never displays the real error nor a stack trace.

Without async in the same situation, Mocha displays the error and a stack trace, and exits properly.

Steps to Reproduce

I've created a minimal repo at https://github.com/codingthat/mocha-supertest-async-hang-repro-repo

Expected behavior:

  the server
    1) should respond to a GET at /
TypeError: Cannot read property 'idontexist' of undefined
[full stack trace is then printed]

Actual behavior: [What actually happens]

the server
    1) should respond to a GET at /
    2) "after all" hook for "should respond to a GET at /"


  0 passing (4s)
  2 failing

  1) the server
       should respond to a GET at /:
     Error: Timeout of 2000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves. (/home/me/mocha-supertest-async-hang-repro-repo/test/index.test.ts)
      at listOnTimeout (internal/timers.js:554:17)
      at processTimers (internal/timers.js:497:7)

  2) the server
       "after all" hook for "should respond to a GET at /":
     Error: Timeout of 2000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves. (/home/me/mocha-supertest-async-hang-repro-repo/test/index.test.ts)
      at listOnTimeout (internal/timers.js:554:17)
      at processTimers (internal/timers.js:497:7)

[at this point the process hangs indefinitely, and neither the TypeError nor its stack trace appear]

Reproduces how often: 100%

Versions

• The output of mocha --version and node node_modules/.bin/mocha --version: (apt "not installed" message) and 8.3.2
• The output of node --version: v14.16.1
• Your operating system
  • name and version: Linux Mint 19.3
  • architecture (32 or 64-bit): 64-bit
• Your shell (e.g., bash, zsh, PowerShell, cmd): bash
• Your browser and version (if running browser tests): n/a
• Any third-party Mocha-related modules (and their versions): latest supertest (6.1.3) and chai (4.3.4), plus express 4.17.1
• Any code transpiler (e.g., TypeScript, CoffeeScript, Babel) being used (and its version): TypeScript 3.7.5

Additional Information

I think this is important, because Express.js controller functions often need to be async to be able to await database calls. As it currently is, a mere typo in such a function can mean a lengthy process of recreating an E2E test by hand just to get at the real error that's occurring. Non-async controllers behave much better with Mocha, letting you already debug from Mocha's output without any additional (and tedious) steps. But avoiding async/await in controllers just because of this would be a step backward.

I admit I'm not sure if this is a Mocha bug or perhaps a bug with Supertest or another dependency. Please let me know if I should report it elsewhere—this was as minimal an example as I could manage.

[juergba]

What is the result if you replace const res = await request.get('/').send(); with ... await Promise.reject(new TypeError('...'))?
There is a similar issue with supertest/jest (697), have you seen this one?

[codingthat]

With or without async on the server function, that change gives me a proper error and stack trace:

  the server
    1) should respond to a GET at /


  0 passing (18ms)
  1 failing

  1) the server
       should respond to a GET at /:
     TypeError: ...
      at Context.<anonymous> (test/index.test.ts:15:42)
      at Generator.next (<anonymous>)
[...]

Thanks for the lead, I was unaware and will check that out!

[codingthat]

@juergba I checked into ladjs/supertest#697 . It may be related, but I'm not sure that exactly the same thing is going on here, for two reasons:

1. Along the lines of the third example cited there, using just const res = request.get('/').send() (no expect calls) as our test, all tests pass immediately without an error or stack trace being printed before Mocha exits, which is also not a great result, since actually the back end is encountering a runtime error.
2. Along the lines of the second example, chaining to a .then() call hangs Mocha without a stack trace.

Also, in their case, they don't talk about what's actually happening in the back end, whereas in my example, taking async out of the back end fixes the problem.

[juergba]

Along the lines of the third example cited there, using just const res = request.get('/').send() [...]

I can't reproduce this one. There is no difference in outcome with or without the expect lines. The program execution never finishes const res = await request.get('/').send();. There is no promise returned, the await keeps waiting.

• add console.log(res), it won't be called ever.
• set this.timeout(20000), doesn't help either, no promise returned.

[...] hangs Mocha without a stack trace.

The after hook fails, therefore the server isn't closed. You can add the --exit option, directly in your npm script or
by npm run test -- --exit.

[codingthat]

@juergba Please note my point in 1. following the other issue has no await in it (it's just ...res = request...). Can you reproduce the results then? Also, can you reproduce the originally described behaviour by cloning https://github.com/codingthat/mocha-supertest-async-hang-repro-repo and running npm i then npm run test?

I had read that --exit is a deprecated solution to situations like these, and one to be avoided in normal circumstances—and hopefully debugging a typo in a back end is considered a normal circumstance. :) It's precisely because --exit can hide the fact that something is actually wrong that it's not a sustainable approach.

So...is my original (reproducible, on my end) example a problem with Mocha, or Supertest, or the interaction between them, or something else? As a mere user of these libraries, I can only tell that the stack isn't working (in what I would consider a common debugging scenario), not which part(s) may need changes for it to work.

[juergba]

Please note my point in 1. following the other issue has no await in it (it's just ...res = request...). Can you reproduce the results then?

I'm not going to reproduce this case. Trying to handle a promise the synchronous way just doesn't make sense. That's javascript basics. And yes, I did clone your repo and can reproduce your results.

--exit is a valid Mocha option and hasn't been deprecated. It's not a nice option, if you need to use it, you should check your test code critically.

So...is my original (reproducible, on my end) example a problem with Mocha, or Supertest, or the interaction between them [...]

Your await request.get('/').send(); promise is never being resolved. That's not a Mocha problem, IMO.
To narrow the problem down, you (not me) could:

• use npm test -- --unhandled-rejections=strict, then you get your stack trace.
• swap from async/await to done callback and see wether it works. Does Supertest support async/await? No docs.
• write yout test without any test framework as shown in Supertest docs.

[codingthat]

Fair enough (re the sync case)—makes sense, I was rather blindly just following the other issue. Thanks for confirming that you can reproduce my original issue. ✔

Ah, sorry, I misspoke about --exit. Not deprecated, you're right, but not a nice option as you say, and turned off by default for good reasons.

Thank you, I really appreciate your explanation and especially your tip to use --unhandled-rejections=strict, which worked perfectly!

As for Supertest and async/await, there's a PR to add this (apparently supported feature?) to the docs: https://github.com/visionmedia/supertest/pull/713/files It seems to mirror the approach taken in my example repo here, if I'm not missing anything.

Thanks again! =)

[codingthat]

As for a Supertest-only example, here's what I have:

package.json:

{
  "name": "supertest-async-hang-repro",
  "version": "1.0.0",
  "description": "",
  "main": "index.js",
  "scripts": {
    "start": "node ./app.js",
    "test": "mocha -r ts-node/register 'test/**/*.test.ts' --unhandled-rejections=strict"
  },
  "author": "",
  "license": "ISC",
  "dependencies": {
    "express": "^4.17.1"
  },
  "devDependencies": {
    "supertest": "^6.1.3"
  }
}

app.js:

const request = require('supertest');
const express = require('express');

const app = express();

app.get('/user', async function(req, res) {
  console.log('starting response');
  req.body.idontexist;
  res.status(200).json({ name: 'john' });
  console.log('done 200');
});

(async function() {
    await request(app)
    .get('/user')
    .expect('Content-Type', /json/)
    .expect('Content-Length', '15')
    .expect(200);
})();
console.log('requested OK');

Result of npm i && npm start:

requested OK
starting response
(node:21415) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'idontexist' of undefined
[stack trace follows]

So...is there something Mocha could help with after all, then, given that the option you recommended is for Node.js, not Mocha? Or should it just be documented as something of a best practice, along the lines of "BTW, Node.js has deprecated unhandled promises, so if you async/await throughout your stack, you'll want to use their --unhandled-rejections=strict until that becomes their default..."?

[juergba]

In first place it's your code which produces an unhandled rejection. So you should emphasis on fixing this issue, probably that has to be done in the express part. It's not a good practice to produce uncaught exceptions or unhandled rejections and expect Mocha to fix this for you.

Mocha is not documenting Node's option, this is a bottomless task we are not going to start with. And there is nothing Mocha can do, if you instruct: "wait for this promise to be resolved", but your code (or your dependencies) prints a soft warning only.

Now you have to give me a good reason not to close this issue.

[codingthat]

Absolutely, it's my code where the problem lies. However, the situation affects the developer UX of working with the Mocha/Supertest stack, making fixing such an issue (which can be brought about by stale code, or something as little as a typo) take quite a bit longer than it needs to, but now I'm just repeating my opening report. Wrapping every function in try/catch seems like a lot of boilerplate just to get a normal stack trace during testing—something your Node.js option suggestion more or less takes care of without all that hassle, so again +1 for that solution. :)

I appreciate you confirming there's nothing Mocha can do (and for taking the time to clarify things above). Even if I might wish for best practices / workable developer environments to be part of documentation in general, I understand not "going down the rabbit hole" of documenting Node.js' option, and I respect the boundary you just set. Thanks again for your insights and for Mocha! 🙌