Mocha silently skips tests when an async error is thrown

[rsimha]

@jpettitt reported this while running the following test:

amphtml/extensions/amp-user-notification/0.1/test/test-amp-user-notification.js

Lines 80 to 88 in 97847f2

	it('should require an id', () => {
	const el = getUserNotification({
	'data-show-if-href': 'https://www.ampproject.org/get/here',
	'data-dismiss-href': 'https://www.ampproject.org/post/here',
	'layout': 'nodisplay',
	});
	const impl = el.implementation_;
	expect(impl.buildCallback.bind(impl)).to.throw(/should have an id/);
	});

The error at the end of the test gets thrown asynchronously, by which time the test has completed. So Mocha makes it look like the test has passed, but the thrown error prevents it from running subsequent tests.

See mochajs/mocha#3223 and mochajs/mocha#3257 for more info on why this is a mocha problem.

[rsimha]

@jpettitt From looking at the mocha documentation at https://mochajs.org/#asynchronous-code, I wonder if these tests should be calling done() in order to get mocha to wait until the error is thrown.

[rsimha]

Another theory: Here are the last few lines of buildCallback(). Notice that userNotificationManagerPromise is being created, but not returned. I wonder if this explains the async behavior that's tripping up mocha.

amphtml/extensions/amp-user-notification/0.1/amp-user-notification.js

Lines 165 to 172 in acc1927

	const userNotificationManagerPromise =
	/** @type {!Promise<!UserNotificationManager>} */
	(getServicePromiseForDoc(ampdoc, SERVICE_ID));
	userNotificationManagerPromise.then(manager => {
	manager.registerUserNotification(
	dev().assertString(this.elementId_), this);
	});
	}

[dreamofabear]

/cc @choumx

[zhouyx]

Found the same issue with amp-iframe test as well.

[zhouyx]

For test-amp-iframe

amphtml/extensions/amp-iframe/0.1/amp-iframe.js

Lines 165 to 177 in 1c555f2

	assertPosition_() {
	const pos = this.element.getLayoutBox();
	const minTop = Math.min(600, this.getViewport().getSize().height * .75);
	user().assert(pos.top >= minTop,
	'<amp-iframe> elements must be positioned outside the first 75% ' +
	'of the viewport or 600px from the top (whichever is smaller): %s ' +
	' Current position %s. Min: %s' +
	'Positioning rules don\'t apply for iframes that use `placeholder`.' +
	'See https://github.com/ampproject/amphtml/blob/master/extensions/' +
	'amp-iframe/amp-iframe.md#iframe-with-placeholder for details.',
	this.element,
	pos.top,
	minTop);

Looks like user().assert calls reportError which will rethrow an async error. I am stubbing the #reportError function to fix this.

[rsimha]

Seems like several AMP tests do asynchronous stuff (like throwing errors), but don't correctly use the done() callback to indicate that the asynchronous tasks have completed. I'm looking for a centralized way to detect such anti-patterns, and isolate / fail tests that contain them.

[rsimha]

After some investigation, it turns out that functions like user().error and user().assert call reportError, which asynchronously throws the same error that we're throwing during tests when console.error is called.

One potential fix for this issue is to stub out reportError during tests at times when console.error will throw an error. This means the normal reportError behavior is restored inside allowConsoleError blocks, where console.error will not throw an error.

[rsimha]

/cc @dvoytenko for comment on this, since we might have to grapple with complications due to how describes works.

[dreamofabear]

I can probably help here since I'm familiar with describes. What's the question?

[rsimha]

@zhouyx brought up the possibility of describes using an inner context, with separate console and error instances.

[dreamofabear]

IIUC, I don't think shadowing globals is generally a good idea. We should just use standard testing mechanisms e.g. stubbing.

[zhouyx]

@choumx Here's what I found yesterday.

We stub window.console before every test. However every test is using the same global window. Even we call sandbox.restore after a test, an async error from it can still results in the failure of its following test. This is flaky and hard to debug I think. Given some of the unit tests are designed to test error cases. We need to make sure that async errors from those tests are well scoped within their context.

Using done() callback would be able to solve that problem. But the issue here is that we won't be able to know when to call that in the async test environment.

[rsimha]

This is still happening, as reported today by @gmajoulet

Repro steps:

git checkout master
git reset --hard 6eac7cba0
gulp css
gulp test --files=extensions/amp-story/1.0/test/test-amp-story.js --nobuild --verbose --watch

At this point, Karma reports 16 tests completed, 3 tests skipped. However, if you click the "Debug" button in the Karma window and rerun all the tests, it runs 38 tests with one failure that mocha seems to be silently swallowing in non-debug mode.

Error: Uncaught Error: The node must be attached to request ampdoc.
    The test "amp-story   amp-story consent should pause the story if there is a consent" resulted in a call to console.error. (See above line.)
    ⤷ If the error is not expected, fix the code that generated the error.
    ⤷ If the error is expected (and synchronous), use the following pattern to wrap the test code that generated the error:
        'allowConsoleError(() => { <code that generated the error> });'
    ⤷ If the error is expected (and asynchronous), use the following pattern at the top of the test:
        'expectAsyncConsoleError(<string or regex>[, number of times the error message repeats]);' (http://localhost:9876/absolute/tmp/74d83432dea64e9c0c70667075884f40.browserify:55771)

[rsimha]

This is still an issue. See mochajs/mocha#94 for reference.

[dvoytenko]

I think our best bet to resolve this issue in the intermediate-term is by setting up our test runner to intercept the error and unhandledrejection window event handlers. We can record them and clearly log when they happen. We can add expectUnhandledError(matcher) to skip the known errors that we expect. At the very least this should prevent us from being completely in the blind why something has got stuck. At a maximum this could give us a path to prevent "stuck" states for tests.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.