Block in Github action
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 https://github.com/codeceptjs/CodeceptJS/issues/3640 an issue before, but no response and the probleme has gone, but it's here again :'(
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
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/[email protected]_@[email protected]_@[email protected][email protected][email protected]/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/[email protected]_@[email protected]_@[email protected][email protected][email protected]/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.
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 ?
🎉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
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
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
... 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 ✌️
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
to me,
test.retriesshould 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
Maybe link with #4197 ?
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.
Ok so the issue ara around the retry and how promise rejection are handled i presume ?
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
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/[email protected]/node_modules/allure-codeceptjs/src/index.ts:316:19)
at AllureReporter.allureStepByCodeceptStep (/e2e/node_modules/.pnpm/[email protected]/node_modules/allure-codeceptjs/src/index.ts:127:12)
at AllureReporter.stepFinished (/e2e/node_modules/.pnpm/[email protected]/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/[email protected][email protected]/node_modules/codeceptjs/lib/event.js:149:28)
at /e2e/node_modules/.pnpm/[email protected][email protected]/node_modules/codeceptjs/lib/actor.js:146:11
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?
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
well if that's possible, adding the DEBUG=* would provide us more info and perhaps we could learn something from there.
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
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
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(); })
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
https://github.com/Horsty80/codeceptjs-debug/blob/main/tests/error-2_test.ts#L3
maybe redundant async cause some side effects?
I will update with a new test file without the befare and test that but i think i get the same behavior
@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
Did you spot any unusual with your After block?