[🐛 Bug]: Unable to take screenshot from the afterTest hook on a mocha timeout

SOLariss commented 6 months ago

Have you read the Contributing Guidelines on issues?

[X] I have read the Contributing Guidelines on issues.

WebdriverIO Version

8.32.2

Node.js Version

20.9.0

Mode

Standalone Mode

Which capabilities are you using?

{
browserName: 'chrome',
browserVersion: '121.0.6167.184'
}

What happened?

If the last mocha test fails with a timeout, browser.takeScreenshot() from the wdio afterTest hook is unable to take screenshot (save the file).

We are using wdio, mocha and allure for making reports. "@wdio/allure-reporter": "^8.32.2", "@wdio/cli": "^8.32.2", "@wdio/local-runner": "^8.32.2", "@wdio/mocha-framework": "^8.32.2", "@wdio/spec-reporter": "^8.32.2",

Sometimes tests may fail due to a timeout. In case if the failing test is the last in the suit, an error is thrown and screenshot is not saved. From a limited investigation it seems to happen because there is not enough time between triggering wdio timeout error and mocha failing with its timeout. According to this code the difference between mocha and wdio timeouts will always be 3ms, that is not enough in our case. The problem is that there is no way to adjust this buffer time. So what happens on timeout is:

Wdio timeout is triggered by this line
afterTest hook is triggered (and starts taking screenshot) async afterTest(test, context, { passed }) { if (!passed) { await browser.takeScreenshot(); } },
in 3 milliseconds after step 1 the mocha timeout is triggered that triggers mocha's afterAll hook, that sends "suite:end" event (all this happens asynchronously) that triggers allure end suit logic. 4.As taking screenshot takes some time, allure's _endSuite had already ran before the browser (from WebDriver) asynchronously responded to a take screenshot command. And thus allure cannot attach a screenshot to an ongoing step as it considers all steps to be finished and fails on this check.

In general, this issue is quite similar to the https://github.com/webdriverio/webdriverio/issues/5545 but the fix seems to be not comprehensive enough.

It seems, that the most obvious solution to the issue would be to make TIME_BUFFER from shim.ts configurable through the wdio config file. Alternatively, one could try to properly synchronize all the hooks and callback executions for the timeout conditions, but this seems to be much more complicated endeavor.

What is your expected behavior?

Screenshot of webpage is created and added to the last step of an allure report

How to reproduce the bug.

Full code can be found here

config file:

const config = {
  specs: ["../specs/**/*.feature.js"],
  maxInstances: 1,  
  automationProtocol: "webdriver",
  capabilities: [
    {
      maxInstances: 1,
      browserName: "chrome",
      ["goog:chromeOptions"]: {
        args: ["--window-size=1920,1080", "--ignore-certificate-errors"],        
      },
    },
  ],
  logLevel: "warn", 
  waitforTimeout: 10000,
  mochaOpts: {
    ui: "bdd",
    timeout: 10000,
  },
  reporters: [
    "spec",
    [
      "allure",
      {
        outputDir: "tests/allure-results",
        disableWebdriverStepsReporting: true,
        disableWebdriverScreenshotsReporting: false,
      },
    ],
  ],
  /**
   * Function to be executed before a test (in Mocha/Jasmine) or a step (in Cucumber) starts.
   * @param {Object} test test details
   */
  beforeTest(test) {
    if (!browser.__headless) {
      console.log(`Running test: ${test.title}`);
    }
  },
  async afterTest(test, context, { passed }) {
    if (!passed) {
      await browser.takeScreenshot();
    }
  },
};

export { config };

test:

import * as chai from 'chai';

const { expect } = chai;

describe('Some tests', ()=> {
    before(async ()=> {
        await browser.url('https://webdriver.io');
    });
    it('can successfully open a page', async () => {
        const subtitle = await $('.hero__subtitle');
        expect(await subtitle.getText()).to.be.equal('Next-gen browser and mobile automation test framework for Node.js');
    });
    it('fails with timeout', async () => {
        await new Promise((resolve) => setTimeout(resolve, 300000));
    });
})

Relevant log output

> wdio-bug@0.1.0 test
> wdio tests/config/wdio.conf.js

Execution of 1 workers started at 2024-02-28T14:29:48.073Z

2024-02-28T14:29:48.386Z WARN webdriver: Chromedriver v120.0.6099.224 don't exist, trying to find known good version...
[0-0] RUNNING in chrome - file:///tests/specs/test.feature.js
[0-0] 2024-02-28T14:29:49.443Z WARN webdriver: Chromedriver v120.0.6099.224 don't exist, trying to find known good version...
[0-0] Running test: can successfully open a page
[0-0] Running test: fails with timeout
[0-0] Error in "Some tests.fails with timeout"
Error: Timeout of 10000ms exceeded. The execution in the test "Some tests fails with timeout" took too long. Try to reduce the run time or increase your timeout for test specs (https://webdriver.io/docs/timeouts). (/workspace/testReport/wdioBug/wdio-bug/tests/specs/test.feature.js)
    at createTimeoutError (/workspace/testReport/wdioBug/wdio-bug/node_modules/mocha/lib/errors.js:498:15)
    at Runnable._timeoutError (/workspace/testReport/wdioBug/wdio-bug/node_modules/mocha/lib/runnable.js:431:10)
    at Timeout.<anonymous> (/workspace/testReport/wdioBug/wdio-bug/node_modules/mocha/lib/runnable.js:246:24)
    at listOnTimeout (node:internal/timers:573:17)
    at process.processTimers (node:internal/timers:514:7)
[0-0] 2024-02-28T14:30:01.927Z ERROR @wdio/utils:shim: Error: There isn't any active test!
[0-0]     at AllureReporter.attachFile (file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/allure-reporter/build/reporter.js:58:19)
[0-0]     at AllureReporter.attachScreenshot (file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/allure-reporter/build/reporter.js:71:14)
[0-0]     at AllureReporter.onAfterCommand (file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/allure-reporter/build/reporter.js:356:18)
[0-0]     at AllureReporter.emit (node:events:526:35)
[0-0]     at AllureReporter.emit (node:domain:488:12)
[0-0]     at file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/runner/build/reporter.js:47:56
[0-0]     at Array.forEach (<anonymous>)
[0-0]     at BaseReporter.emit (file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/runner/build/reporter.js:47:25)
[0-0]     at EventEmitter.<anonymous> (file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/runner/build/index.js:224:58)
[0-0]     at EventEmitter.emit (node:events:514:28)
[0-0]     at EventEmitter.emit (node:domain:488:12)
[0-0]     at WebDriver.prototype.<computed> [as emit] (file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/utils/build/monad.js:191:35)
[0-0]     at file:///workspace/testReport/wdioBug/wdio-bug/node_modules/webdriver/build/command.js:106:18
[0-0]     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
[0-0]     at async Browser.wrapCommandFn (file:///workspace/testReport/wdioBug/wdio-bug/node_modules/@wdio/utils/build/shim.js:88:29)
[0-0]     at async Object.afterTest (file:///workspace/testReport/wdioBug/wdio-bug/tests/config/wdio.conf.js:46:7)
[0-0] Error in "AfterTest Hook"
There isn't any active test!
[0-0] FAILED in chrome - file:///tests/specs/test.feature.js

 "spec" Reporter:
------------------------------------------------------------------
[chrome 120.0.6099.224 linux #0-0] Running: chrome (v120.0.6099.224) on linux
[chrome 120.0.6099.224 linux #0-0] Session ID: 536d1a64f13c91ea9505e3c75e4c971d
[chrome 120.0.6099.224 linux #0-0]
[chrome 120.0.6099.224 linux #0-0] » /tests/specs/test.feature.js
[chrome 120.0.6099.224 linux #0-0] Some tests
[chrome 120.0.6099.224 linux #0-0]    ✓ can successfully open a page
[chrome 120.0.6099.224 linux #0-0]    ✖ fails with timeout
[chrome 120.0.6099.224 linux #0-0]
[chrome 120.0.6099.224 linux #0-0] 1 passing (11.8s)
[chrome 120.0.6099.224 linux #0-0] 1 failing
[chrome 120.0.6099.224 linux #0-0]
[chrome 120.0.6099.224 linux #0-0] 1) Some tests fails with timeout
[chrome 120.0.6099.224 linux #0-0] Timeout of 10000ms exceeded. The execution in the test "Some tests fails with timeout" took too long. Try to reduce the run time or increase your timeout for test specs (https://webdriver.io/docs/timeouts). (/workspace/testReport/wdioBug/wdio-bug/tests/specs/test.feature.js)
[chrome 120.0.6099.224 linux #0-0] Error: Timeout of 10000ms exceeded. The execution in the test "Some tests fails with timeout" took too long. Try to reduce the run time or increase your timeout for test specs (https://webdriver.io/docs/timeouts). (/workspace/testReport/wdioBug/wdio-bug/tests/specs/test.feature.js)
[chrome 120.0.6099.224 linux #0-0]     at createTimeoutError (/workspace/testReport/wdioBug/wdio-bug/node_modules/mocha/lib/errors.js:498:15)
[chrome 120.0.6099.224 linux #0-0]     at Runnable._timeoutError (/workspace/testReport/wdioBug/wdio-bug/node_modules/mocha/lib/runnable.js:431:10)
[chrome 120.0.6099.224 linux #0-0]     at Timeout.<anonymous> (/workspace/testReport/wdioBug/wdio-bug/node_modules/mocha/lib/runnable.js:246:24)
[chrome 120.0.6099.224 linux #0-0]     at listOnTimeout (node:internal/timers:573:17)
[chrome 120.0.6099.224 linux #0-0]     at process.processTimers (node:internal/timers:514:7)

Spec Files:      0 passed, 1 failed, 1 total (100% completed) in 00:00:13

Code of Conduct

[X] I agree to follow this project's Code of Conduct

Is there an existing issue for this?

[X] I have searched the existing issues

wdio-bot commented 6 months ago

Thanks for reporting!

We greatly appreciate any contributions that help resolve the bug. While we understand that active contributors have their own priorities, we kindly request your assistance if you rely on this bug being fixed. We encourage you to take a look at our contribution guidelines or join our friendly Discord development server, where you can ask any questions you may have. Thank you for your support, and cheers!

silvaj8 commented 5 months ago

I am also facing this issue in my project and I have some information to add. I found out that this started happening with version 8.5.0, with the migration to allure-js-commons v2 (https://github.com/webdriverio/webdriverio/pull/9704). So, as a workaround, I'm using the version 8.4.0 of @wdio/allure-reporter.

I hope this helps who's facing this issue too and investigating the source of the bug.

silvaj8 commented 3 weeks ago

@christian-bromann Could you please try to prioritize this issue, as this is a blocker for bumping the @wdio/allure-reporter package? The feature of taking a screenshot on the afterTest is really important to help debugging why a test failed.

christian-bromann commented 3 weeks ago

@silvaj8 let me set the expectations clear: if you are blocked on an error, please get involved and help resolve this. We expense contributions to the project too.

silvaj8 commented 3 weeks ago

I understand that, and I already tried to resolve the issue, but to no avail. I don't think I'm the right person to tackle this issue, given the knowledge I have about this package and the free time I have right now, but I will still give it a try (not officially though, so if anyone wants to come forward go ahead 😅), and if in the meantime I find something relevant I will share here.

I was hoping that you would know about some contributor that could be more indicated to solve this issue, and you could tag them, for example, the author of the PR I identified above (https://github.com/webdriverio/webdriverio/pull/9704). But I understand that may not be the way things work here, thank you for setting the expectations 👍

webdriverio / webdriverio