UnhandledPromiseRejectionWarning: Error: Protocol error (Runtime.callFunctionOn): Promise was collected

[benjaminBeganovic]

Once all tests finish successfully this exception occurs on the CI:

W20200612-14:11:02.429(0)? (STDERR) (node:642) UnhandledPromiseRejectionWarning: Error: Protocol error (Runtime.callFunctionOn): Promise was collected
W20200612-14:11:02.429(0)? (STDERR)     at Promise (/home/jenkins/humly-home/packages/hrm/node_modules/puppeteer/lib/Connection.js:183:56)
W20200612-14:11:02.429(0)? (STDERR)     at new Promise (<anonymous>)
W20200612-14:11:02.429(0)? (STDERR)     at CDPSession.send (/home/jenkins/humly-home/packages/hrm/node_modules/puppeteer/lib/Connection.js:182:12)
W20200612-14:11:02.429(0)? (STDERR)     at ExecutionContext._evaluateInternal (/home/jenkins/humly-home/packages/hrm/node_modules/puppeteer/lib/ExecutionContext.js:107:44)
W20200612-14:11:02.429(0)? (STDERR)     at ExecutionContext.evaluateHandle (/home/jenkins/humly-home/packages/hrm/node_modules/puppeteer/lib/ExecutionContext.js:57:17)
W20200612-14:11:02.430(0)? (STDERR)     at ExecutionContext.<anonymous> (/home/jenkins/humly-home/packages/hrm/node_modules/puppeteer/lib/helper.js:112:23)
W20200612-14:11:02.430(0)? (STDERR)     at WaitTask.rerun (/home/jenkins/humly-home/packages/hrm/node_modules/puppeteer/lib/DOMWorld.js:570:65)
W20200612-14:11:02.430(0)? (STDERR)     at <anonymous>
W20200612-14:11:02.430(0)? (STDERR)     at process._tickDomainCallback (internal/process/next_tick.js:229:7)
W20200612-14:11:02.430(0)? (STDERR)  => awaited here:
W20200612-14:11:02.430(0)? (STDERR)     at Function.Promise.await (/home/jenkins/.meteor/packages/promise/.0.11.2.1bomg6e.mbyx++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/promise_server.js:56:12)
W20200612-14:11:02.430(0)? (STDERR)     at Promise.asyncApply (packages/meteortesting:browser-tests/browser/puppeteer.js:64:5)
W20200612-14:11:02.430(0)? (STDERR)     at /home/jenkins/.meteor/packages/promise/.0.11.2.1bomg6e.mbyx++os+web.browser+web.browser.legacy+web.cordova/npm/node_modules/meteor-promise/fiber_pool.js:43:40
W20200612-14:11:02.430(0)? (STDERR) (node:642) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 9)
W20200612-14:11:02.431(0)? (STDERR) (node:642) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
 
Too long with no output (exceeded 1m0s): context deadline exceeded

After the investigation, I have found out that this is caused by unit tests using enzyme' shallow rendering. Once I remove these tests everything is fine, but I can't find anything wrong in them.
Also, this exception occurs every once in a few runs (2 - 3). Here is the typical unit test that makes this issue happen:

import React from "react";
import { expect } from "chai";
import { shallow, configure } from "enzyme";
import Adapter from "enzyme-adapter-react-16";
// import sinon from "sinon";

import ExampleView from "./ExampleView";

configure({ adapter: new Adapter() });

const defaultProps = {
    name: "test name",
    text: "test value",
};

describe(".../ExampleView", () => {
    before(() => {
        // methods stubs
    });

    after(() => {
        // restores
    });

    it("rendering component", () => {
        const props = {
            ...defaultProps,
        };

        const wrapper = shallow(<ExampleView {...props} />);
        const specificElement = wrapper.find(".specific-class-name");
        expect(specificElement.text()).to.be.equal(defaultProps.text);
    });
});

I think this is something related with meteortesting:mocha package and puppeteer, or maybe in between them. Here is the script I use to run unit tests on CI:

#!/bin/bash -eu

cd "$(dirname "${BASH_SOURCE[0]}")"/..

export PORT="${PORT:-5000}"
export ROOT_URL="http://localhost:${PORT}"
export TEST_BROWSER_DRIVER=puppeteer
export MOCHA_TIMEOUT=6000

cd node_modules/puppeteer/.local-chromium/linux-*/chrome-linux/
sudo chown root:root chrome_sandbox
sudo chmod 4755 chrome_sandbox
sudo cp -p chrome_sandbox /usr/local/sbin/chrome-devel-sandbox
export CHROME_DEVEL_SANDBOX=/usr/local/sbin/chrome-devel-sandbox
cd ../../../../../

meteor test --once --driver-package meteortesting:mocha --port "${PORT}" "$@"

I have tried with "-- --exit" in last command trying to force mocha to exit after all tests get done, but it does not help. Here is the list of versions I have:
meteor 1.8.3
node 8.17.0
puppeteer 1.20.0
meteortesting:[email protected]
meteortesting:[email protected]
meteortesting:[email protected]
react 16.12.0
sinon 7.5.0
chai 4.2.0
enzyme 3.10.0

Thanks in advance :)

[SimonSimCity]

Can you please create a small meteor application and upload it to github so I can have a look at it? I'm not all to familar with react or enzyme.

[make-github-pseudonymous-again]

Is it possible that this happens once you have so many tests that puppeteer times out?

[make-github-pseudonymous-again]

I've just reached a bit over 3 minutes of --full-app client tests and headless mode with puppeteer yields this after approximately 3 minutes. Also, might this be the responsibility of https://github.com/Meteor-Community-Packages/meteor-browser-tests ?

[make-github-pseudonymous-again]

Confirmed the source for the timeout is in puppeteer sources:

• https://github.com/puppeteer/puppeteer/blob/159513c8dbe2c9f51aa37dbe531d52b5daf1e106/packages/puppeteer-core/src/common/Connection.ts#L202
• https://github.com/puppeteer/puppeteer/blob/159513c8dbe2c9f51aa37dbe531d52b5daf1e106/packages/puppeteer-core/src/common/BrowserConnector.ts#L62-L67

One solution would be to allow configuring a different value for protocolTimeout here:

• https://github.com/Meteor-Community-Packages/meteor-browser-tests/blob/4993e1cce766c075ba13eb07e489c2c02412e21e/browser/puppeteer.js#L31-L34