Mocha ignores timeout on Promise test functions

[jasonswearingen]

Prerequisites

• [ X] Checked that your issue hasn't already been filed by cross-referencing issues with the faq label
• [ X] 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.
• [ x] '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
• [x ] 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 avoiding the use of globally installed Mocha.

Description

Mocha does not respect specifying a timeout for tests that return promises.

I want to set a max timeout by invoking mochaTest.timeout(1000) but it is ignored.

Steps to Reproduce

describe( "reproduce promise timeout ignores", function () {

	it( "should timeout", function () {
		this.timeout( 1000 );
		return new Promise( function ( resolve, reject ) {
			setTimeout( function () {
				resolve();
			}, 3000 );
		} );
	} );

	const test = it( "should timeout2", function () {
		return new Promise( function ( resolve, reject ) {
			setTimeout( function () {
				resolve();
			}, 3000 );
		} );
	} );
	test.timeout( 1000 );

} );

Expected behavior: [What you expect to happen]
expect the tests to fail after 1000ms due to timeout. I can understand why the first "should timeout" test might not work with my desired timeout (setting the timeout inside the async method) but the second "should timeout2" should work as desired.

Actual behavior: [What actually happens]
tests pass after aprox 3000ms

  reproduce promise timeout ignores
    √ should timeout (3006ms)
    √ should timeout2 (3001ms)

  2 passing (6s)

Reproduces how often: [What percentage of the time does it reproduce?]
all the time

Versions

mocha --version
5.2.0

node_modules/.bin/mocha --version
5.2.0

node --version
v8.11.4

os:
win10 x64 v1803 b17134.345

shell:
cmd and/or powershell

browser ver:
N/A

mocha modules:
N/A

transpiled via:
N/A

Additional Information

my full commandline for running the tests:

'C:\Users\jason\AppData\Roaming\npm\mocha.cmd' '--watch' '--colors' '--trace-warnings' '--inspect-brk=45370' './dist/**/mocha.test.js'

[jasonswearingen]

my workaround code, using typescript, xlib and bluebird, so you'll need to adjust it slightly based on your promise library of choice, and ditch the function name reflection code I'm using from xlib.

/** hack fix for mocha bug, unable to have a timeout for async tests */
function it2( testFcn: () => Promise<any> ) {
	const testName = xlib.reflection.getTypeName( testFcn );
	return it( testName, async function () {
		const timeoutMs = this.timeout();
		return xlib.promise.bluebird.resolve( testFcn.apply( this ) ).timeout( timeoutMs, new xlib.promise.bluebird.TimeoutError( `operation timed out.  Max of ${ timeoutMs }ms exceeded` ) );
	} );
}

[juergba]

If mochaTest.timeout(1000) were ignored then the default timeout of 2000ms would be activ. Therefore your test should fail with or without timeout of 1000. The problem is hidden somewhere else.

[juergba]

I'm using NodeJS v10.5.0 and Mocha 5.2.0 and your example is working perfectly without any change.

[plroebuck]

OS: macOS 10.13.6 (17G65)
Node: v10.3.0
Mocha: 5.2.0 (master trunk)

$ /var/tmp/mocha/bin/_mocha nakedeyes.js 

  reproduce promise timeout ignores
    1) should timeout
    2) should timeout2

  0 passing (2s)
  2 failing

  1) reproduce promise timeout ignores
       should timeout:
     Error: Timeout of 1000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves. (/private/tmp/nakedeyes.js)
      at Test.Runnable._timeoutError (/private/var/tmp/mocha/lib/runnable.js:440:10)
      at Timeout.<anonymous> (/private/var/tmp/mocha/lib/runnable.js:251:24)

  2) reproduce promise timeout ignores
       should timeout2:
     Error: Timeout of 1000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves. (/private/tmp/nakedeyes.js)
      at Test.Runnable._timeoutError (/private/var/tmp/mocha/lib/runnable.js:440:10)
      at Timeout.<anonymous> (/private/var/tmp/mocha/lib/runnable.js:251:24)

[plroebuck]

Please fill in the Versions information above as originally requested for submitting a new issue.

[jasonswearingen]

mocha --version
5.2.0

node_modules/.bin/mocha --version
5.2.0

node --version
v8.11.4

os:
win10 x64 v1803 b17134.345

shell:
cmd and/or powershell

browser ver:
N/A

mocha modules:
N/A

transpiled via:
N/A

[plroebuck]

Dunno since we have proven on both Window and macOS using Node-10.

You're not telling us something...

• How your Typescript solution fixes things, but you don't mention it in 'transpiled via' nor include --require ts-node/register and --watch-extentions ts?
• Why would your unit tests be in a "dist" directory?
  • Maybe use either this or idea from here

Are you able to try running with Node-10 so we could compare against Juerg's results?

[jasonswearingen]

@plroebuck regarding your questions:

• typescript? No. Though I use typescript to write code, I am running mocha against the transpiled javascript directly. The only difference in my actual .js file from the repo code I gave is that the .js file has a "use strict"; line at the top and a //# sourceMappingURL=mocha.test.js.map line at the bottom. I do not think those lines are relevant. I do not use ts-node or anything of the sort.

• dist dir? at "build time" I emit javascript to the /dist/ folder. Again, this is just normal javascript, identical to my example code reproducing the error (with the exception of an additional first and last line, as explained above)

• Node 10? I see that the node LTS has been updated to 10.x so I'll give that a try. will write back later once that's done.

[plroebuck]

Fair enough (concerning Typescript), but I can't explain how you could run the same version of Mocha against the exact file above (even with a different version of Node) and get different results.

[jasonswearingen]

when i update node to 10.x I'll also check if there's something weird getting loaded in from node_modules (purge globals and run in an empty local folder) will let you know then!

[jasonswearingen]

I narrowed the problem down. it's somehow related to using the v8 inspector debug protocol. When I run mocha ./dist/mocha.test.js it runs as expected (timeout failures after 1000ms) but when I add --inspect it does not timeout.

So in my example, If I run the following, I see the problem:

mocha --inspect ./dist/mocha.test.js

this was tested on node 10.x lts

[juergba]

I confirm this error with --inspect. This flag is passed through from Mocha to Node, but I suppose it's not a Node's problem.

Promise.race([
    new Promise(function(resolve) {
        setTimeout(resolve, 3000, "promise1")
    }),
    new Promise(function(resolve) {
        setTimeout(resolve, 1000, "promise2")
    })
])
.then( (msg) => console.log(msg));

Above timeout is working correctly with and without --inspect.

[juergba]

mocha --timeout --inspect is giving the correct result and the tests are failing.

This is strange since --timeout is expecting a parameter ms.
mocha --timeout as expected results in: error: option -t, --timeout <ms> argument missing

mocha --timeout 0 and mocha --inspect show exactly the same results, tests are passing.

My guess is the value of timeout is lost somewhere when used with --inspect.

[plroebuck]

I narrowed the problem down. it's somehow related to using the v8 inspector debug protocol. When I run mocha ./dist/mocha.test.js it runs as expected (timeout failures after 1000ms) but when I add --inspect it does not timeout.

So in my example, If I run the following, I see the problem:

mocha --inspect ./dist/mocha.test.js

By design. See here in "/bin/mocha".

[plroebuck]

mocha --timeout --inspect is giving the correct result and the tests are failing.

This is strange since --timeout is expecting a parameter ms.
mocha --timeout as expected results in: error: option -t, --timeout <ms> argument missing

mocha --timeout 0 and mocha --inspect show exactly the same results, tests are passing.

My guess is the value of timeout is lost somewhere when used with --inspect.

They [--timeout/--no-timeouts] cancelled each other out.

[jasonswearingen]

ok, but maybe should add docs for that. https://mochajs.org/ has docs decribing how timeouts are disabled for --debug but nothing is mentioned for --inspect

[plroebuck]

As requested, now documented in usage