[Asking for help] Process are blocking when throw error in scenario with Retry enabled #4358

Horsty80 · 2024-05-21T15:07:33Z

When i run to all test (~70) in 4 workers, at the end, i get stuck with this error message

✖ "after all" hook: codeceptjs.afterSuite in "Homepage feature" in 0ms

CodeceptJS version: 3.6.2
NodeJS Version: 20
playwright: 1.43.0
allure-codeceptjs: 2.15.1
Configuration file:

    Playwright: {
      url: testConfig.url,
      show: false,
      locale: "en-EN",
      browser: 'chromium',
      chromium: {
        args: ['--auth-server-whitelist=""'],
      },
      ignoreHTTPSErrors: true,
      fullPageScreenshots: true,
      windowSize: '1920x1080',
      waitForAction: 250,
      waitForTimeout: 10000, 
      waitForNavigation: 'load',
      restart: 'context',
      keepCookies: false,
      keepBrowserState: false
    },

I have allready open here #3640 an issue before, but no response and the probleme has gone, but it's here again :'(

Horsty80 · 2024-05-21T15:57:09Z

This issue, append in local too but it's not on each run, so it's seems to be random...

I don't know how to fix this

Horsty80 · 2024-05-23T21:22:40Z

I've worked on a reproductible repo, you can find here https://github.com/Horsty80/codeceptjs-debug

Working test

pnpm i
pnpm working

Throwing error in After/Before without try/catch

 pnpm error-1

Lead to error but the CI is not block

  4) Error 1 @error1
       "before each" hook: Before for "test something 6":
     Error: done() called multiple times in hook <Error 1 @error1 "before each" hook: Before for "test something 6"> of file /Users/cyril/Workspace/codeceptjs-debug/tests/error-1_test.ts
      at /Users/cyril/Workspace/codeceptjs-debug/node_modules/.pnpm/codeceptjs@3.6.2_@babel+core@7.24.5_@babel+preset-env@7.24.5_react@18.2.0_typescript@5.4.5/node_modules/codeceptjs/lib/scenario.js:156:55
      at runNextTicks (node:internal/process/task_queues:60:5)
      at processTimers (node:internal/timers:511:9)

  5) Error 1 @error1
       "before each" hook: Before for "test something 5":
     Uncaught Async error
      at Timeout._onTimeout (tests/error-1_test.ts:7:11)
      at listOnTimeout (node:internal/timers:573:17)
      at processTimers (node:internal/timers:514:7)

Throwing error in some random Scenario without try/catch

 pnpm error-2

Lead to mentioned error ✖ "after all" hook: codeceptjs.afterSuite in "Error 2 @error2" in 0ms
But the CI is block and it's impossible to take back control.

-- FAILURES:

  1) Error 2 @error2
       "before each" hook: Before for "test something 5":
     Uncaught Async error
      at Timeout._onTimeout (tests/error-2_test.ts:16:11)
      at listOnTimeout (node:internal/timers:573:17)
      at processTimers (node:internal/timers:514:7)
  
  Scenario Steps:
  - I.amOnPage("https://www.google.com") at Context.<anonymous> (./tests/error-2_test.ts:4:5)
  
  
  Scenario Steps:
  - I.amOnPage("https://www.google.com") at Context.<anonymous> (./tests/error-2_test.ts:4:5)
  

  2) Error 2 @error2
       "before each" hook: Before for "test something 5":
     Error: done() called multiple times in hook <Error 2 @error2 "before each" hook: Before for "test something 5"> of file /Users/cyril/Workspace/codeceptjs-debug/tests/error-2_test.ts
      at /Users/cyril/Workspace/codeceptjs-debug/node_modules/.pnpm/codeceptjs@3.6.2_@babel+core@7.24.5_@babel+preset-env@7.24.5_react@18.2.0_typescript@5.4.5/node_modules/codeceptjs/lib/scenario.js:156:55


  FAIL  | 1 passed, 2 failed   // 2s
    --- STARTED "before each" hook: Before for "test something 6" ---
    I am on page "https://www.google.com"
    › [Browser:Info] Autofocus processing was blocked because a document already has a focused element.
    › [Browser:Info] Autofocus processing was blocked because a document already has a focused element.
    › [Browser:Error] Permissions policy violation: unload is not allowed in this document.
    › [Browser:Error] Permissions policy violation: unload is not allowed in this document.
    --- ENDED "before each" hook: Before for "test something 6" ---
    I see element button#W0wltc
    I click button#W0wltc
    --- ENDED "before each" hook: Before for "test something 7" ---
    I see element button#W0wltc
    I click button#W0wltc
    I dont see element button#W0wltc
[03]   ✔ test something 6 in 59ms
  ✔ test something 6 in 168ms
  test something 9
    I dont see element button#W0wltc
[01]   ✔ test something 7 in 177ms
  ✔ OK in 177ms

  OK  | 3 passed   // 3s
    --- STARTED "before each" hook: Before for "test something 9" ---
    I am on page "https://www.google.com"
    › [Browser:Info] Autofocus processing was blocked because a document already has a focused element.
    › [Browser:Error] Permissions policy violation: unload is not allowed in this document.
    --- ENDED "before each" hook: Before for "test something 9" ---
    I see element button#W0wltc
    I click button#W0wltc
    I dont see element button#W0wltc
[03]   ✔ test something 9 in 168ms
  ✔ OK in 168ms


-- FAILURES:
  ✖ "after all" hook: codeceptjs.afterSuite in "Error 2 @error2" in 0ms

Throwing error in some random Scenario with try/catch

 pnpm error-3

Lead to the same error as pnpm error-2 the CI / terminal is block and impossible to take back the control

Throwing error in Before with try/catch

 pnpm error-4

Lead to the same error as pnpm error-1, test failed, but we take back the control.

Horsty80 · 2024-05-23T21:27:02Z

So my first conclusion are something in my test code throw an async error and it's not try/catch and Codecept can not handle it correctly.
But on my workflow of test (not the linked repository) I use codeceptJs method, and I have remove all throw that I can find on my custom helper.

Tomorrow I will work on adding some try/catch on stuff I presume can lead to unhandled error, but is it possible that some error inside codeceptJs code can lead to unhandled error ?

Horsty80 · 2024-05-23T21:37:52Z

🎉UPDATE

It's seems that if I remove retry: 3 in the codecept.conf.ts the "blocking" not happens anymore.
I will try some retry configuration to check this clue

Horsty80 · 2024-05-23T22:16:13Z

I invok @DavertMik 🙌 you have work on the global retry feature and maybe you can help me on it or how to find the root cause

Horsty80 · 2024-05-23T23:11:26Z

Last test and last conclusion ^^

For codeceptjs: 3.4.1 is working ✅
for 3.5.0 is not working ❌

With the same config

After checking changelog, I've found the line that cause the issue from the fix here #3667

https://github.com/codeceptjs/CodeceptJS/pull/3667/files#diff-9c88056d70f40caa621cb9519252872211ec64f80a84fa1c127c1f98880a93b8R47

I've try to replace this code block

    if (Number.isInteger(+retryConfig)) {
       if (test.retries() === -1) test.retries(retryConfig);
       return;
     }

By this:

    if (Number.isInteger(+retryConfig)) {
       if (isNotSet(test.retries())) test.retries(retryConfig);
       return;
     }

I don't really understand what is in cause, but clearly the test.retries() === -1 cause this issue

Investigation are explain on this issue codeceptjs#4358

Horsty80 · 2024-05-24T21:15:03Z

... Wrong fixed, that is not the root cause of the issue.
But strangely adding line of code here have impact on the blocking issue 🤔 even a console.log() inside the if achieve the same thing...

So I keep investigate ✌️

andonary · 2024-05-27T12:57:11Z

I think using a console.log inside of this force JavaScript to load this part of code. And thus import Suite from Mocha: https://github.com/Horsty80/CodeceptJS/blob/3c009e0759b3ddda7caa1984209fe248213553d2/lib/scenario.js#L175

test.retries is an inside method of Mocha:
https://github.com/mochajs/mocha/blob/master/lib/suite.js#L129

to me, test.retries should not be undefined. Not sure where should be the root cause

Horsty80 · 2024-05-27T13:21:41Z

to me, test.retries should not be undefined. Not sure where should be the root cause

Yes it's test.retries is defined, just a wrong idea of the root cause for me ( that for i delete my PR)
I'm keep investigate, but the code base of the lib and the project are difficult to understand

test.retries for Scenario and not Suite is defined here if i understand:
https://github.com/mochajs/mocha/blob/master/lib/test.js#L75

Horsty80 · 2024-05-28T14:09:11Z

Maybe link with #4197 ?

kobenguyent · 2024-05-29T06:15:00Z

We patched the retryTo issue in 3.5.11 > https://codecept.io/changelog/#_3-5-11 and the stale issue is found by you from 3.5.0. So the issue should be somewhere else, I think.

Horsty80 · 2024-05-29T07:28:15Z

Ok so the issue ara around the retry and how promise rejection are handled i presume ?

kobenguyent · 2024-05-29T07:49:21Z

adding more debug info

2024-05-29T07:46:29.650Z mocha:runner total number of failures: 2
  ✖ test something 3 in 81ms
    --- ENDED "after each" hook: After for "test something 3" ---
    --- STARTED "before each" hook: Before for "test something 3" ---
    I am on page "https://www.google.com"
2024-05-29T07:46:29.743Z mocha:runner uncaught(): got truthy exception Error: Async error
    at Timeout._onTimeout (/Users/t/Desktop/projects/codeceptjs-debug/tests/error-4_test.ts:8:13)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7)
  ✖ FAILED in 35ms
2024-05-29T07:46:29.743Z mocha:runner uncaught(): forcing Runnable to complete with Error
2024-05-29T07:46:29.743Z mocha:runner total number of failures: 3

       --- STARTED "after each" hook: After for "test something 3" ---
After hook
2024-05-29T07:46:29.834Z mocha:runner uncaught(): throwing after run has completed!
[03] Worker Error: Error: Async error
    at Timeout._onTimeout (/Users/t/Desktop/projects/codeceptjs-debug/tests/error-4_test.ts:8:13)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7)
2024-05-29T07:46:29.853Z mocha:runner uncaught(): throwing after run has completed!
[03] Worker Error: Error: Async error
    at Timeout._onTimeout (/Users/t/Desktop/projects/codeceptjs-debug/tests/error-4_test.ts:8:13)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7)
    › [Browser:Info] Autofocus processing was blocked because a document already has a focused element.
    › [Browser:Error] Permissions policy violation: unload is not allowed in this document.
    --- ENDED "after each" hook: After for "test something 3" ---
2024-05-29T07:46:30.429Z mocha:runner total number of failures: 4
  ✖ FAILED in 35ms

    --- ENDED "after each" hook: After for "test something 3" ---
2024-05-29T07:46:30.436Z mocha:runner _addEventListener(): adding for event error; 0 current listeners
2024-05-29T07:46:30.437Z mocha:runner runSuite(): running Working @working:

2024-05-29T07:46:30.437Z mocha:runner runSuite(): bailing
2024-05-29T07:46:30.437Z mocha:runner run(): root suite completed; emitting end
2024-05-29T07:46:30.442Z mocha:runner uncaught(): got truthy exception TypeError: Cannot read properties of undefined (reading 'stack')
    at /Users/t/Desktop/projects/codeceptjs-debug/node_modules/codeceptjs/lib/cli.js:189:25
    at Array.map (<anonymous>)
    at Cli.result (/Users/t/Desktop/projects/codeceptjs-debug/node_modules/codeceptjs/lib/cli.js:160:21)
    at Runner.emit (node:events:529:35)
    at Runner.emit (node:domain:489:12)
    at end (/Users/t/Desktop/projects/codeceptjs-debug/node_modules/mocha/lib/runner.js:1049:10)
    at /Users/t/Desktop/projects/codeceptjs-debug/node_modules/mocha/lib/runner.js:908:7
    at next (/Users/t/Desktop/projects/codeceptjs-debug/node_modules/mocha/lib/runner.js:485:14)
    at Immediate.<anonymous> (/Users/t/Desktop/projects/codeceptjs-debug/node_modules/mocha/lib/runner.js:570:5)
    at processImmediate (node:internal/timers:476:21)
2024-05-29T07:46:30.442Z mocha:runner uncaught(): forcing Runnable to complete with Error
2024-05-29T07:46:30.443Z mocha:runner total number of failures: 5
-- FAILURES:
  ✖ "after all" hook: codeceptjs.afterSuite in "Error 4 @error4" in 1ms
2024-05-29T07:46:30.569Z mocha:runner uncaught(): got truthy exception Error: Async error
    at Timeout._onTimeout (/Users/t/Desktop/projects/codeceptjs-debug/tests/error-4_test.ts:19:11)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7)
2024-05-29T07:46:30.569Z mocha:runner uncaught(): Runnable has already failed
2024-05-29T07:46:30.714Z mocha:runner uncaught(): got truthy exception Error: Async error
    at Timeout._onTimeout (/Users/t/Desktop/projects/codeceptjs-debug/tests/error-4_test.ts:8:13)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7)
2024-05-29T07:46:30.715Z mocha:runner uncaught(): Runnable has already failed
2024-05-29T07:46:30.748Z mocha:runner uncaught(): got truthy exception Error: Async error
    at Timeout._onTimeout (/Users/tDesktop/projects/codeceptjs-debug/tests/error-4_test.ts:19:11)
    at listOnTimeout (node:internal/timers:569:17)
    at processTimers (node:internal/timers:512:7)
2024-05-29T07:46:30.748Z mocha:runner uncaught(): Runnable has already failed

Horsty80 · 2024-05-29T12:33:44Z

Using the version 3.6.3-beta.2 doesn't change the behavior, i still have the blocked issue

-- FAILURES:
  ✖ "after all" hook: codeceptjs.afterSuite in "My custom test" in 1ms

Maybe that can help you, but i get a lot of allure report error like this mention that something wrong append from
codeceptjs/lib/actor.js:146:11

       Something went wrong Error: Something went wrong
    at AllureReporter.debug (/e2e/node_modules/.pnpm/allure-codeceptjs@2.15.1/node_modules/allure-codeceptjs/src/index.ts:316:19)
    at AllureReporter.allureStepByCodeceptStep (/e2e/node_modules/.pnpm/allure-codeceptjs@2.15.1/node_modules/allure-codeceptjs/src/index.ts:127:12)
    at AllureReporter.stepFinished (/e2e/node_modules/.pnpm/allure-codeceptjs@2.15.1/node_modules/allure-codeceptjs/src/index.ts:289:29)
    at EventEmitter.emit (node:events:526:35)
    at EventEmitter.emit (node:domain:488:12)
    at Object.emit (/e2e/node_modules/.pnpm/codeceptjs@3.6.3-beta.2_typescript@5.4.2/node_modules/codeceptjs/lib/event.js:149:28)
    at /e2e/node_modules/.pnpm/codeceptjs@3.6.3-beta.2_typescript@5.4.2/node_modules/codeceptjs/lib/actor.js:146:11

kobenguyent · 2024-05-29T12:37:22Z

hey @Horsty80 which allure report are you using? the legacy one or the one from allure team? Also if you disable the allure plugin, does your CI still stale?

Horsty80 · 2024-05-29T12:40:59Z

I use this one : https://www.npmjs.com/package/allure-codeceptjs
I get:

allure-codeceptjs: 2.15.0
allure-commandline: 2.27.0

Before this new beta version, I have already try to remove allure but there are no impact on the issue.
I can retry with the beta to be sure.

I pointing on this allure's error only because the stacktrace begin inside codeceptjs lib so maybe that can help to debug

kobenguyent · 2024-05-29T12:43:35Z

well if that's possible, adding the DEBUG=* would provide us more info and perhaps we could learn something from there.

Horsty80 · 2024-05-29T13:04:37Z

So i've retry without allure, and i get the same behavior.
I have start another test with DEBUG=* i hope i can have something that can help

Horsty80 · 2024-05-29T22:45:53Z

well if that's possible, adding the DEBUG=* would provide us more info and perhaps we could learn something from there.

With debug, I have a tons of log to explore, but I see nothing strange or something can be useful
Maybe you have something in mind that can help me to find the right log ?

Just to recap, I play 70 tests with run-worker command (with 4 or 6 workers), and I use plugin autoLogin and Retry + the Allure reporter

My CI is blocked each time, and even remove the retry didn't have the expected solution.

I don't know where to search but I can test what you propose, let me know

kobenguyent · 2024-05-30T05:29:27Z

Out of curiosity, are you using the After/AfterSuite in your Scenario files?

I recall recently I got the issue (the process hangs) when using the hook like Before/After stuff like that. So the solution is moving the code from those hooks to a function and call that function in the scenario. Not a clean solution but at least it helped.

Before(() => {...}) -> preconditions() {...}

After(() => {...}) -> postconditions() {...}

Scenario('test', () => {
preconditions();
...
postconditions();
})

Horsty80 · 2024-05-30T07:48:49Z

Out of curiosity, are you using the After/AfterSuite in your Scenario files?

I recall recently I got the issue (the process hangs) when using the hook like Before/After stuff like that. So the solution is moving the code from those hooks to a function and call that function in the scenario. Not a clean solution but at least it helped.

Before(() => {...}) -> preconditions() {...}

After(() => {...}) -> postconditions() {...}

Scenario('test', () => { preconditions(); ... postconditions(); })

Yes i have that before, but i have remove all before/after from scenario files
And has you can see in my code that i share here https://github.com/Horsty80/codeceptjs-debug
https://github.com/Horsty80/codeceptjs-debug/blob/main/tests/error-2_test.ts the Before is only a I.amOnPage

kobenguyent · 2024-05-30T08:44:56Z

https://github.com/Horsty80/codeceptjs-debug/blob/main/tests/error-2_test.ts#L3

maybe redundant async cause some side effects?

Horsty80 · 2024-05-30T09:29:53Z

I will update with a new test file without the befare and test that but i think i get the same behavior

Horsty80 · 2024-06-03T12:51:00Z

@kobenguyent i still have the stale process issue with the 3.6.3-beta.2

The debug show me some much logs that can not exploit them

kobenguyent · 2024-06-03T14:53:04Z

Did you spot any unusual with your After block?

Horsty80 added a commit to Horsty80/CodeceptJS that referenced this issue May 23, 2024

fix: add check on test can be undefined

3c009e0

Investigation are explain on this issue codeceptjs#4358

Horsty80 mentioned this issue May 23, 2024

fix: add check on test can be undefined #4359

Closed

7 tasks

Horsty80 changed the title ~~Block in Github action~~ [Asking for help] Process are blocking when throw error in scenario with Retry enabled May 24, 2024

Horsty80 mentioned this issue May 25, 2024

Tests don't fail gracefully when encountering errors after test execution and stall the CI #4211

Closed

kobenguyent mentioned this issue May 29, 2024

fix(cli): stale process #4367

Merged

5 tasks

This was referenced Jun 4, 2024

fix: handle throw error inside retryTo promise #4377

Merged

Ensure scenario termination #4378

Merged

kobenguyent closed this as completed in #4367 Jun 10, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[Asking for help] Process are blocking when throw error in scenario with Retry enabled #4358

[Asking for help] Process are blocking when throw error in scenario with Retry enabled #4358

Horsty80 commented May 21, 2024 •

edited

Loading

Horsty80 commented May 21, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 24, 2024

andonary commented May 27, 2024

Horsty80 commented May 27, 2024 •

edited

Loading

Horsty80 commented May 28, 2024

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024 •

edited

Loading

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024

Horsty80 commented May 29, 2024

kobenguyent commented May 30, 2024

Horsty80 commented May 30, 2024

kobenguyent commented May 30, 2024

Horsty80 commented May 30, 2024

Horsty80 commented Jun 3, 2024

kobenguyent commented Jun 3, 2024

[Asking for help] Process are blocking when throw error in scenario with Retry enabled #4358

[Asking for help] Process are blocking when throw error in scenario with Retry enabled #4358

Comments

Horsty80 commented May 21, 2024 • edited Loading

Horsty80 commented May 21, 2024

Horsty80 commented May 23, 2024

Working test

Throwing error in After/Before without try/catch

Throwing error in some random Scenario without try/catch

Throwing error in some random Scenario with try/catch

Throwing error in Before with try/catch

Horsty80 commented May 23, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 23, 2024

Horsty80 commented May 24, 2024

andonary commented May 27, 2024

Horsty80 commented May 27, 2024 • edited Loading

Horsty80 commented May 28, 2024

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024 • edited Loading

kobenguyent commented May 29, 2024

Horsty80 commented May 29, 2024

Horsty80 commented May 29, 2024

kobenguyent commented May 30, 2024

Horsty80 commented May 30, 2024

kobenguyent commented May 30, 2024

Horsty80 commented May 30, 2024

Horsty80 commented Jun 3, 2024

kobenguyent commented Jun 3, 2024

Horsty80 commented May 21, 2024 •

edited

Loading

Horsty80 commented May 27, 2024 •

edited

Loading

Horsty80 commented May 29, 2024 •

edited

Loading