Workers hang after a failed step with some assertions (webdriverio)

[nikzupancic]

What are you trying to achieve?

I'm running codecept inside workers but noticed that some assertions will fail and then just hang the whole thread without ever continuing its execution. The problematic assertions are all see ones: see, dontSee, seeElement, dontSeeElement. What I'm expecting is a graceful fail that would then continue with other scenarios within suite (or terminate the connection with test browser/device if this is the only scenario).

What do you get instead?

There are a few lines showing an error. screenshotOnFail captures the image but after that it just hangs, the connection to browser/cloud device is never terminated.

Provide console output if related. Use --verbose mode for more details.

      I dont see element "#app"
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] Error | Error
    [1] <teardown> Stopping recording promises
 › <screenshotOnFail> Test failed, try to save a screenshot
 › Screenshot has been saved to ./screenshots/Testy_test.failed.png

Provide test source code if related

Using contradictory steps just to show that the test is expected to fail:

Feature('Testing scenario')

Scenario('Testy test', ({I}) => {
    I.amOnPage('https://codecept.io/')
    I.waitForVisible('#app')
    I.dontSeeElement('#app')
})

Details

• CodeceptJS version: 3.5.6
• NodeJS Version: 18.7.1
• Operating System: Ubuntu 20.04.6 LTS (Focal Fossa)
• webdriverio: 8.15.10
• Configuration file:

{
    tests: __dirname + 'test.js',
    output: './screenshots'
    bootstrap: () => {},
    teardown: () => {},
    mocha: {},
    plugins: {},
    helpers: {
        WebDriver: {
            restart: false,
            host: 'hub-cloud.browserstack.com',
            port: 4444,
            waitForTimeout: 5000,
            browser: 'Safari',
            platform: 'iOS',
            url: 'https://codecept.io',
            desiredCapabilities: {
                    build: 'testing-run',
                    'browserstack.user': 'X',
                    'browserstack.key': 'X',
                    os_version: '16',
                    device: 'iPhone 14',
                    platform: 'iOS',
            }
        }
    }
}

Note that config given above is using a Browserstack service but I suspect that the results would be the same if running this locally.

My thought was that something breaks in worker-parent communication but I couldn't figure out exactly what goes wrong. When looking at messages that are sent to parent thread I noticed that the last events sent to parent are test.failed and test.finish but nothing after that. Looking at other calls with "graceful failures" I can also see some other events following failed test: suite.after, test.skipped (there are multiple skipped tests in the same scenario), global.failures, global.after.

When it hangs these are the last 2 objects sent from worker to parent:

{"event":"test.failed","workerIndex":1,"data":{"opts":{},"tags":[],"uid":"ryiL1qBCssvxKFySxbhmlw","workerIndex":1,"retries":-1,"title”:””Testy test,”status":"failed","duration":7910,"err":{"message":"","actual":[true],"expected":true},"parent":{"title”:”Testing scenario”}}}
{"event":"test.finish","workerIndex":1,"data":{"opts":{},"tags":[],"uid":"ryiL1qBCssvxKFySxbhmlw","workerIndex":1,"retries":-1,"title”:”Testy test”,duration":7910,"err":null,"parent":{"title”:”Testing scenario”}}}

Other calls (waitForVisible, waitForInvisible etc.) still fail as expected but because the tests are time sensitive I want to verify that elements are visible/invisible at the exact moment which is why waitFor isn't useful for me. Any ideas what's happening? Or at least how to work around this issue?

[kobenguyent]

hey @nikzupancic may you happen to try with latest version of codeceptjs?

[nikzupancic]

@kobenguyent Using 3.5.12-beta.3 it still hangs but the output is a little different:

      I dont see element "#app"
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error | Error undefined...
    [1] <teardown> Stopping recording promises
 › <screenshotOnFail> Test failed, try to save a screenshot
 › Screenshot has been saved to ./screenshots/Testy_test.failed.png

[kobenguyent]

So I saw you reported with 3.5.6. may you help try with older version like 3.5.5 to see if that issue occurs https://codecept.io/changelog/#_3-5-5

[nikzupancic]

@kobenguyent Same result with 3.5.5. I did however manage to narrow this issue down to mocha-multi reporter. Here's my configuration:

mocha: {
    reporterOptions: {
        'codeceptjs-cli-reporter': {
            stdout: '-',
            options: {
                verbose: true,
                steps: true
            }
        },
        'mocha-junit-reporter': {
            stdout: '-',
            options: {
                mochaFile: path.join('output', 'result.[hash].xml')
            }
        }
    }
},

And this is how workers are configured:

const configFilePath = __dirname + '/codecept.conf.js'
const workerRunner = new Workers(null, { testConfig: configFilePath })
const verboseEnabled = true

const worker = workerRunner.spawn()

worker.addTestFiles([path.join(__dirname, 'webTest.js')])
worker.addConfig(config)
worker.addOptions({ config: configFilePath, verbose: verboseEnabled, reporter: 'mocha-multi' })
workerRunner.on(event.all.result, () => workerRunner.printResults())

workerRunner.run()

With this the failed step freezes the whole framework. If I don't pass mocha-multi option to the worker then the dontSeeElement fails as expected.

worker.addOptions({ config: configFilePath, verbose: verboseEnabled })

Also if I change the reporter to mocha-junit-reporter then it fails again without a proper teardown.

My mocha-junit-reporter is at version 2.2.0, mocha-multi is 1.1.7

[kobenguyent]

interesting! You are using the custom parallel execution + mocha-multi reporter. I mostly use allure/report portal for the reports, so my knowledge here is limited.

[kobenguyent]

@nikzupancic https://github.com/codeceptjs/CodeceptJS/pull/3971/files this touched mocha report, may you could learn from there if something wrong.

[kobenguyent]

As this is reported by using custom parallel workers so I think we can't help much there unless it happens with the core.

[nikzupancic]

I get that this may not necessarily be a CodeceptJS issue but just leaving what I found on this so far. It's not really a workers issue at all but based on how I was configuring workers' reporter.

After some more research I noticed that TruthAssertion contains actual and expected params. In my case for failing dontSeeElement the values are actual = [ true ] (array) and expected = true (boolean).

This then gets passed down to mocha-junit-reporter to mocha which calls diff.createPatch with expected and actual values it receives. As far as I can see createPatch expects string parameters (and I'm just getting this from the types package which may or may not be completely correct?) but in this case it's passed a boolean and boolean array which somehow breaks it.

I tried converting expected and actual values in TruthAssertion to strings and while it produces a weird error output it at least fails completely and terminates the whole framework in the end (and I know just forcing stuff to string isn't a solution but I was curious if this would help with the above issue).

Here's the output I get in this case (there's no values listed under expected or actual just empty line)

       Testing scenario:

      expected elements of #app not to be seen
      + expected - actual

@kobenguyent Thanks for the help so far but one more question since you're more familiar with this codebase: is there anyway I could somehow work around this in my case? Or maybe catch the usual error that's thrown by dontSeeElement and just throw my own to avoid this?

[kobenguyent]

hey @nikzupancic thanks for your time to debug the issue, I had a quick check on the codebase and yeah noticed that actually the error thrown by such methods don't bring much benefits for debugging. So I made some changes here #4144. Hope that helps.
Also there is a test build that you could try with https://www.npmjs.com/package/codeceptjs/v/3.5.12-beta.6
May you kindly give it a try once you got some time? Many thanks!

[nikzupancic]

Thanks @kobenguyent. I tried running the beta version and I can confirm that in this case it fails properly but there is still some weird output:

    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error (Non-Terminated) | Error: Element "#app" is still visible on page. | (err) => { step.status = 'failed'; step.endTime = ...
    [1] Error | Error: Element "#app" is still visible on page. undefined...

Not sure if (Non-Terminated) is expected or problematic in this case? Also in the last line you can see that something's still undefined. As far as I can tell so far though these are more cosmetic issues

[kobenguyent]

Thanks @nikzupancic for testing it out. Like you said I think it's just a cosmetic issue and it won't have any big impact. We could live with it in the meantime, I believe.