🐛 Bug: Negative functional tests started to throw "Uncaught Error" after mocha update to 8.2.0

[mykola-mokhnach]

Prerequisites

• Checked that your issue hasn't already been filed by cross-referencing issues with the faq label
• 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.
• '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.

Description

After the recent mocha bump to 8.2.0 our functional tests on CI started to throw unexpected "Uncaught Error" failures while before everything was working kist fine.

Steps to Reproduce

1. Checkout the https://github.com/appium/appium-espresso-driver repository
2. Run npm i on it
3. Start Android Emulator named "Android"
4. Mark only the test should not work if getting an attribute that does not exist for execution to save the time
5. Run gulp transpile to transpile the source
6. Run mocha: npx mocha --timeout 6000000 --reporter mocha-multi-reporters --reporter-options config-file=./ci-jobs/mocha-config.json --recursive build/test/functional/ -g @skip-ci -i --exit

Expected behavior: [What you expect to happen]
The test should pass

Actual behavior: [What actually happens]

The test is shown twice as passing and failing with an "Unexpected error" exception:

  2 passing (1m)
  2 failing

  1) element attributes
       getAttribute
         should not work if getting an attribute that does not exist:
     Uncaught Error: [element.getAttribute("some-fake-property")] Error response status: 13, , UnknownError - An unknown server-side error occurred while processing the command. Selenium error: An unknown server-side error occurred while processing the command. Original error: Attribute name should be one of [content-desc, class, text, package, checkable, checked, clickable, enabled, focusable, focused, scrollable, long-clickable, password, selected, visible, no-multiline-buttons, no-overlaps, no-ellipsized-text, bounds, resource-id, instance, index, adapters, adapter-type, hint, view-tag]. 'some-fake-property' is given instead
      at exports.newError (node_modules/wd/lib/utils.js:152:13)
      at /Users/elf/code/appium-espresso-driver/node_modules/wd/lib/callbacks.js:94:19
      at /Users/elf/code/appium-espresso-driver/node_modules/wd/lib/webdriver.js:205:5
      at Request._callback (node_modules/wd/lib/http-utils.js:89:7)
      at Request.self.callback (node_modules/request/request.js:185:22)
      at Request.<anonymous> (node_modules/request/request.js:1161:10)
      at IncomingMessage.<anonymous> (node_modules/request/request.js:1083:12)
      at endReadableNT (_stream_readable.js:1201:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21)

  2) element attributes
       getAttribute
         should not work if getting an attribute that does not exist:
     Uncaught Error: [element.getAttribute("some-fake-property")] Error response status: 13, , UnknownError - An unknown server-side error occurred while processing the command. Selenium error: An unknown server-side error occurred while processing the command. Original error: Attribute name should be one of [content-desc, class, text, package, checkable, checked, clickable, enabled, focusable, focused, scrollable, long-clickable, password, selected, visible, no-multiline-buttons, no-overlaps, no-ellipsized-text, bounds, resource-id, instance, index, adapters, adapter-type, hint, view-tag]. 'some-fake-property' is given instead
      at exports.newError (node_modules/wd/lib/utils.js:152:13)
      at /Users/elf/code/appium-espresso-driver/node_modules/wd/lib/callbacks.js:94:19
      at /Users/elf/code/appium-espresso-driver/node_modules/wd/lib/webdriver.js:205:5
      at Request._callback (node_modules/wd/lib/http-utils.js:89:7)
      at Request.self.callback (node_modules/request/request.js:185:22)
      at Request.<anonymous> (node_modules/request/request.js:1161:10)
      at IncomingMessage.<anonymous> (node_modules/request/request.js:1083:12)
      at endReadableNT (_stream_readable.js:1201:12)
      at processTicksAndRejections (internal/process/task_queues.js:84:21)

The results of full CI run: https://dev.azure.com/AppiumCI/Appium%20CI/_build/results?buildId=11913&view=logs&j=ea3a8326-8ae1-5392-57d8-7054c454cdab&t=bf55eb97-8c00-5287-3ece-aba70d92322c&l=8299

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

Always

Versions

• The output of mocha --version and node node_modules/.bin/mocha --version: 8.2.0
• The output of node --version: Tried locally with v13.12.0 and CI (v10)
• Your operating system
  • name and version: Mac OS 10.15.6
  • architecture (32 or 64-bit): 64
• Your shell (e.g., bash, zsh, PowerShell, cmd): zsh
• Your browser and version (if running browser tests):
• Any third-party Mocha-related modules (and their versions):
• Any code transpiler (e.g., TypeScript, CoffeeScript, Babel) being used (and its version): Babel v7.12.1

Additional Information

Downgrading mocha to 8.1.0 solves the issue

[true-eye]

For me, Downgrading mocha to 8.1.3 figures it out

[bugagashen6ka]

We experience the same issue with mocha upgrade to 8.2.0

[ghost]

We are also experiencing the same issue, we have a simple test like the one below that fails after upgrading. After downgrading the test succeeds reliably.

let error;

try {
  await foo();
} catch(err) {
 error = err;
}

should.exist(error);

[fennen529]

We are also experiencing this issue!!!

[nescalante]

Tried bumping to 8.2.0 in several projects, in some of them we were experiencing this issue so we downgraded to 8.1.3 in some of them. By using 8.1.3 it solved the issue, this is definitely a breaking change.

[boneskull]

For everyone other than the original reporter in this issue: I need more information. Please provide:

• how you are launching Mocha
• your Mocha configuration file, if any
• any other apps/libs used with mocha
• node version, platform, and whether the tests run in Node or Browser
• whether or not your tests are using promises (async/await)

@StefanSafeguard I can't reproduce that:

// test.js
const should = require('should');
  
it('should do a thing', async function() {
  
  let error;
  
  try {
    await foo();
  } catch(err) {
   error = err;
  }
  
  should.exist(error);
  
});

Used mocha v8.2.0 and the latest version of should, then ran via mocha test.js.

[boneskull]

I am pretty sure that this is because Mocha v8.2.0 needs to trap unhandled rejections.

It's very likely that what's happening is this:

Previously to v8.2.0, your test (or code-under-test) was raising an unhandled rejection and was being silently ignored. Now it is not. I'm going to test this theory on the appium-espresso-driver repo; hopefully it won't be to onerous to get a dev environment going.

[boneskull]

It's going to be too difficult to debug that appium driver, so... I really need a minimal, complete, verifiable example for this. If it's a webdriver-specific thing, a repo with the proper dependencies, configuration, and a single test should do it.

[mykola-mokhnach]

@boneskull Thank you for checking this issue. Unfortunately I was not able to reproduce it by just awaiting a generic function that is expected to be rejected. It must be some complex interaction that happens in wd module while it is sending its requests.

[boneskull]

@mykola-mokhnach yeah, I think that's probably the case. but I also think I'm probably right about the unhandled rejection behavior. Mocha really ought to be delegating what to do in this case to Node. I am going to propose a workaround... maybe you can test it for me?

[boneskull]

will have a PR up soon

[mykola-mokhnach]

Mocha really ought to be delegating what to do in this case to Node. I am going to propose a workaround... maybe you can test it for me?

Of course, Just tell me what to do. Unfortunately I'm in a different time zone (CET), so my responses might arrive late

[mceachen]

@boneskull I'm PDT, have an affected project, and can help test as well. Thanks for looking into this!

[boneskull]

Please checkout #4489 and see if it works better for you.

[boneskull]

perhaps wd depends upon the pre-Node.js-v15 behavior of warning on unhandled rejections. given that's no longer the default in Node.js, they may want to decide to emit these warnings some other way, or encourage its users to run with --unhandled-rejections=warn. #4489 will cause Mocha to respect that for rejections that come out of user code

[mykola-mokhnach]

I've checked out the boneskull/issue/4481-uncaught branch, replaced mocha 8.2.0 in node_modules with these sources and it seems like the current issue is no more reproducible 🎉

[mykola-mokhnach]

Btw, I got some interesting traceback while playing with version 8.2.0:

/Users/elf/code/appium-espresso-driver/node_modules/mocha/lib/runner.js:936
    throw err;
    ^

Error: done() called multiple times in hook <element attributes "after all" hook in "element attributes"> of file /Users/elf/code/appium-espresso-driver/build/test/functional/commands/attributes-e2e-specs.js
    at createMultipleDoneError (/Users/elf/code/appium-espresso-driver/node_modules/mocha/lib/errors.js:364:13)
    at multiple (/Users/elf/code/appium-espresso-driver/node_modules/mocha/lib/runnable.js:288:24)
    at done (/Users/elf/code/appium-espresso-driver/node_modules/mocha/lib/runnable.js:299:14)
    at /Users/elf/code/appium-espresso-driver/node_modules/mocha/lib/runnable.js:369:11 {
  code: 'ERR_MOCHA_MULTIPLE_DONE',
  valueType: 'undefined',
  value: undefined
}

[boneskull]

ok good

[boneskull]

hmm no that doesn't seem right either.

[boneskull]

I don't think it's wise to merge #4489 or any fixes here until I have a minimal case I can debug with, sorry. Hopefully somebody can provide this.

[boneskull]

@mykola-mokhnach wait, is that "multiple done" coming from v8.2.0 proper, or my branch?

[mykola-mokhnach]

@boneskull Your branch is fine. That error was coming from the currently released 8.2.0 version

[boneskull]

ok, I'll reconsider not merging the fix.

[JoshuaKGoldberg]

Marking this as fixed by #4489. By "fixed" I mean, the reported cases are behaving as Mocha thinks they should, and nobody's reported anything since. If you're reading this and think this is still an issue for you then please do file a new issue with a minimum reproduction we can work with. Cheers!