Closed cklogs closed 2 years ago
Thank you @devoto13, I tried your branches yesterday and the result was the same (no coverage generated half the time). With Karma's logLevel set to debug the logs are huge so I put here just the beginning and end of the two types of run.
I include the reduced and cleaned logs below but as far as I can see the differences are:
Coverage report generated | No coverage report generated |
---|---|
Logs show [coverage]: onBrowserComplete completed | No logs about onBrowserComplete being called |
In "[coverage]: onRunComplete called BrowserCollection" the Browser object's pendingDisconnect property is null |
In "[coverage]: onRunComplete called BrowserCollection" the Browser object's pendingDisconnect contains a Timeout object |
The launcher sends the SIGKILL | no SIGKILL is sent |
[coverage]: Writing coverage is present before onExit completed | no "Writing coverage" debug log before onExit completed |
[reporter.junit]: JUnit results written | no "JUnit results written" log |
With test coverage generated π
> ng test --no-watch --code-coverage
- Generating browser application bundles (phase: setup)...
[config]: Loading config /home/vsts/work/1/s/Client/karma.conf.js
[config]: autoWatch set to false, because of singleRun
.
.
.
INFO [coverage]: onBrowserComplete completed
DEBUG [launcher]: CAPTURED -> BEING_KILLED
DEBUG [launcher]: BEING_KILLED -> BEING_FORCE_KILLED
DEBUG [Chrome Headless 99.0.4844.51 (Linux x86_64)]: CONNECTED -> DISCONNECTED
TOTAL: 3231 SUCCESS
Chrome Headless 99.0.4844.51 (Linux x86_64): Executed 3231 of 3234 (skipped 3)[32m SUCCESS[39m (1 min 38.135 secs / 59.497 secs)
[32mTOTAL: 3231 SUCCESS[39m
10 03 2022 16:10:38.524:INFO [coverage]: onRunComplete called BrowserCollection {
browsers: [
Browser {
id: '25015465',
fullName: 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) HeadlessChrome/99.0.4844.51 Safari/537.36',
name: 'Chrome Headless 99.0.4844.51 (Linux x86_64)',
lastResult: [BrowserResult],
disconnectsCount: 0,
activeSockets: [Array],
noActivityTimeout: 210000,
singleRun: true,
clientConfig: [Object],
collection: [BrowserCollection],
emitter: [Server],
socket: [Socket],
timer: [Object],
disconnectDelay: 210000,
log: [Logger],
noActivityTimeoutId: Timeout {
\_idleTimeout: 210000,
\_idlePrev: [TimersList],
\_idleNext: [Timeout],
\_idleStart: 278390,
\_onTimeout: [Function (anonymous)],
\_timerArgs: undefined,
\_repeat: null,
\_destroyed: false,
[Symbol(refed)]: true,
[Symbol(kHasPrimitive)]: false,
[Symbol(asyncId)]: 680445,
[Symbol(triggerId)]: 680443
},
pendingDisconnect: null,
state: 'DISCONNECTED'
}
],
emitter: EventEmitter {
\_events: [Object: null prototype] {},
\_eventsCount: 0,
\_maxListeners: undefined,
[Symbol(kCapture)]: false
}
}
INFO [coverage]: onRunComplete completed
DEBUG [karma-server]: Run complete, exiting.
DEBUG [launcher]: Disconnecting all browsers
DEBUG [launcher]: BEING_FORCE_KILLED -> BEING_FORCE_KILLED
DEBUG [proxy]: Destroying proxy agents
INFO [coverage]: onExit called
=============================== Coverage summary ===============================
Statements : 91.97% ( 23967/26059 )
Branches : 79.05% ( 9673/12237 )
Functions : 88.99% ( 6694/7522 )
Lines : 92.2% ( 22669/24586 )
================================================================================
WARN [launcher]: ChromeHeadless was not killed in 2000 ms, sending SIGKILL.
DEBUG [coverage]: Writing coverage to /home/vsts/work/1/s/Client/coverage
DEBUG [launcher]: Process ChromeHeadless exited with code null and signal SIGTERM
DEBUG [temp-dir]: Cleaning temp dir /tmp/karma-25015465
DEBUG [coverage]: Writing coverage to /home/vsts/work/1/s/Client/coverage
DEBUG [coverage]: Writing coverage to /home/vsts/work/1/s/Client/coverage
INFO [coverage]: onExit completed
DEBUG [reporter.junit]: JUnit results written to "/home/vsts/work/1/s/Client/TESTS-Chrome*Headless_99.0.4844.51*(Linux_x86_64).xml".
DEBUG [launcher]: Finished all browsers
DEBUG [launcher]: BEING_FORCE_KILLED -> FINISHED
DEBUG [launcher]: FINISHED -> FINISHED
DEBUG [karma-server]: Received stop event, exiting.
DEBUG [launcher]: Disconnecting all browsers
DEBUG [launcher]: FINISHED -> BEING_FORCE_KILLED
DEBUG [proxy]: Destroying proxy agents
INFO [coverage]: onExit called
INFO [coverage]: onExit completed ##[section]Finishing: Test
Without test coverage π
> ng test --no-watch --code-coverage
- Generating browser application bundles (phase: setup)...
DEBUG [config]: Loading config /home/vsts/work/1/s/Client/karma.conf.js
DEBUG [config]: autoWatch set to false, because of singleRun
.
.
.
DEBUG [launcher]: CAPTURED -> BEING_KILLED
DEBUG [launcher]: BEING_KILLED -> BEING_FORCE_KILLED
DEBUG [Chrome Headless 99.0.4844.51 (Linux x86_64)]: CONNECTED -> DISCONNECTED
TOTAL: 3231 SUCCESS
Chrome Headless 99.0.4844.51 (Linux x86_64): Executed 3231 of 0 (skipped 3)[32m SUCCESS[39m (2 mins 15.127 secs / 59.651 secs)
[32mTOTAL: 3231 SUCCESS[39m
INFO [coverage]: onRunComplete called BrowserCollection {
browsers: [
Browser {
id: '13380493',
fullName: 'Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) HeadlessChrome/99.0.4844.51 Safari/537.36',
name: 'Chrome Headless 99.0.4844.51 (Linux x86_64)',
lastResult: [BrowserResult],
disconnectsCount: 0,
activeSockets: [Array],
noActivityTimeout: 210000,
singleRun: true,
clientConfig: [Object],
collection: [BrowserCollection],
emitter: [Server],
socket: [Socket],
timer: [Object],
disconnectDelay: 210000,
log: [Logger],
noActivityTimeoutId: Timeout {
\_idleTimeout: 210000,
\_idlePrev: [TimersList],
\_idleNext: [Timeout],
\_idleStart: 285367,
\_onTimeout: [Function (anonymous)],
\_timerArgs: undefined,
\_repeat: null,
\_destroyed: false,
[Symbol(refed)]: true,
[Symbol(kHasPrimitive)]: false,
[Symbol(asyncId)]: 681197,
[Symbol(triggerId)]: 681196
},
pendingDisconnect: Timeout {
\_idleTimeout: -1,
\_idlePrev: null,
\_idleNext: null,
\_idleStart: 187011,
\_onTimeout: null,
\_timerArgs: undefined,
\_repeat: null,
\_destroyed: true,
[Symbol(refed)]: true,
[Symbol(kHasPrimitive)]: false,
[Symbol(asyncId)]: 646232,
[Symbol(triggerId)]: 646172
},
state: 'DISCONNECTED'
}
],
emitter: EventEmitter {
\_events: [Object: null prototype] {},
\_eventsCount: 0,
\_maxListeners: undefined,
[Symbol(kCapture)]: false
}
}
INFO [coverage]: onRunComplete completed
DEBUG [karma-server]: Run complete, exiting.
DEBUG [launcher]: Disconnecting all browsers
DEBUG [launcher]: BEING_FORCE_KILLED -> BEING_FORCE_KILLED
DEBUG [proxy]: Destroying proxy agents
INFO [coverage]: onExit called
INFO [coverage]: onExit completed
DEBUG [launcher]: Process ChromeHeadless exited with code null and signal SIGTERM
DEBUG [temp-dir]: Cleaning temp dir /tmp/karma-13380493
DEBUG [launcher]: Finished all browsers
DEBUG [launcher]: BEING_FORCE_KILLED -> FINISHED
DEBUG [launcher]: FINISHED -> FINISHED
DEBUG [karma-server]: Received stop event, exiting.
DEBUG [launcher]: Disconnecting all browsers
DEBUG [launcher]: FINISHED -> BEING_FORCE_KILLED
DEBUG [proxy]: Destroying proxy agents
INFO [coverage]: onExit called
INFO [coverage]: onExit completed ##[section]Finishing: Test
Thanks for the details @ozkoidi! I don't think pendingDisconnect
is relevant, it probably happened sometime during the test execution and karma has recovered from it given that the timer is inactive (_idleTimeout: -1
).
Missing onBrowserComplete called
looks relevant though. junit reporter is affected by this as well. Unfortunately, I was not able to figure out how exactly could it happen from reading the code... There is a relatively sync chain of browser_complete -> browser_complete_with_no_more_retries -> run_complete -> Karma shut down, but I don't understand where it could race, so that browser_complete
event is not reaching plugins at all. Without the process.kill
the pending event listeners should prevent Node process from exiting and they should be called even if out of order π€
Can you please use the two below branches and share logs for the two cases to further investigate this problem?
$ npm i devoto13/karma#test-coverage-1
$ npm i devoto13/karma-coverate#test-coverage-1
If possible can you also attach unedited logs as files as timestamps may be useful in figuring out what is going on?
Hello again @devoto13, I tested your latest branches in the pipelines and I get the same behavior.
I attach here a zip file with the full unit tests log output (Karma's logLevel set to LOG_DEBUG
).
The zip contains 2 text files (coverage-devoto-1.txt and no-coverage-devoto-1.txt). For confidentiality reasons I had to rename the tests but I don't think that should be an impediment.
I hope you find these logs useful to find the problem, thanks for your time.
Thank you for the help debuggin it, @ozkoidi! Are you sure you were running the code from test-coverage-1
branches though? I don't see any of the logs added in https://github.com/devoto13/karma/commit/727469e873e8fc74e947eb3fddd8c77c121d4591 for example.
And specific test names are irrelevant, I was primarily interested to look into the timing of the newly added logs.
Yes, I even uninstalled and re-installed karma and karma-coverage again today to be sure. You can see it in this extract from my package-lock.json:
"karma": {
"version": "git+ssh://git@github.com/devoto13/karma.git#c411e999b433a1c135305953658f9662571312a4",
"dev": true,
"from": "karma@github:devoto13/karma#test-coverage-1",
...
"karma-coverage": {
"version": "git+ssh://git@github.com/devoto13/karma-coverage.git#a7f67f27edd9ea515bfcf39e6fef2259f89360c7",
"dev": true,
"from": "karma-coverage@github:devoto13/karma-coverage#test-coverage-1",
...
I run the pipeline several times and searched for the logs you added but indeed, they never show up on the output. If there is anything else I could do to help please let me know as this issue blocks our pipelines often.
Okey, thanks @ozkoidi! So it seems that the browser_complete
event is not coming from the browser over the socket.io connection, that's interesting. I'll look more into it and get back to you if I need more information.
Thanks again for your help in debugging this.
I had the very same issue and was trying for weeks now to solve it. I was able constantly solved it with adding to karma.config.js following 2 options
browserSocketTimeout: 8 * 60 * 40000,
pingTimeout: 8 * 60 * 40000,
so the resulted file is
// Karma configuration file, see link for more information
// https://karma-runner.github.io/1.0/config/configuration-file.html
const isDocker = require('is-docker');
module.exports = (config) => {
config.set({
basePath: '',
frameworks: ['jasmine', '@angular-devkit/build-angular'],
plugins: [
require('karma-jasmine'),
require('karma-chrome-launcher'),
require('karma-jasmine-html-reporter'),
require('karma-junit-reporter'),
require('karma-coverage'),
require('@angular-devkit/build-angular/plugins/karma'),
],
client: {
jasmine: {
random: false,
stopOnFailure: true,
failFast: true,
},
clearContext: false, // leave Jasmine Spec Runner output visible in browser
},
junitReporter: {
outputDir: './reports',
outputFile: 'karma.xml',
useBrowserName: false,
},
coverageReporter: {
dir: './reports/coverage',
subdir: '.',
includeAllSources: true,
reporters: [
{ type: 'cobertura' },
{ type: 'lcovonly' },
{ type: 'html' },
{ type: 'text' },
],
check: {
// thresholds for all files
global: {
statements: 76.25,
branches: 55.95,
functions: 71.4,
lines: 75.8,
}
},
},
reporters: ['progress', 'kjhtml', 'junit', 'coverage'],
port: 9876,
colors: true,
logLevel: config.LOG_INFO,
autoWatch: true,
// to avoid DISCONNECTED messages
browserDisconnectTimeout: 400000, // default 2000
browserDisconnectTolerance: 6, // default 0
browserNoActivityTimeout: 8 * 60 * 40000, //default 10000
captureTimeout: 8 * 60 * 40000, //default 60000
browserSocketTimeout: 8 * 60 * 40000,
pingTimeout: 8 * 60 * 40000,
browsers: ['ChromeCustom'],
singleRun: false,
customLaunchers: {
ChromeCustom: {
base: 'ChromeHeadless',
flags: isDocker() ? ['--disable-gpu', '--no-sandbox'] : [],
},
},
});
};
Thank you so much @danbilokha! After adding browserSocketTimeout
and pingTimeout
it hasn't failed a single time so far :tada:
I already had big values for browserDisconnectTimeout
, browserNoActivityTimeout
and played with browserDisconnectTolerance
in the past but didn't help. However adding the properties you mentioned made the coverage reports to always be generated π
Even though is not an actual fix, it does unblock our pipelines, so thanks again for your suggestion :)
had same issue while running unit tests through linux docker container with low cpu specs. using browserSocketTimeout and pingTimeout worked!!!
for anyone searching like me below are our app configs. angular v14 with nrwl nx v14 using karma
Hi there,
This library is now recommended for code coverage when using v11 of the angular-cli. We are currently using karma-coverage-istanbul-reporter because we have yet to get successful coverage reports with karma-coverage. Seeing, however, that there are deprecation warnings when using the istanbul reporter library with the v11 angular-cli, we would very much like to move off it.
Perhaps someone here can help discern what is wrong with our configuration or point us in the right direction.
I will include the karma.config, and test output debug logs for two different projects.
The first project (PROJECT-1) is a bare project that was initialized with
ng new
command. It was updated to Angular 11 using theng update
command from angular-cli. The point of including this project is to serve as a 'control' for the second project.The second project (PROJECT-2) comes from a relatively large production codebase. In this codebase is roughly 5000 unit tests.
Important points
PROJECT-1 tests are run with:
ng test
. PROJECT-2 tests are run with:node --max_old_space_size=8192 node_modules/@angular/cli/bin/ng test
.--max_old_space_size
configuration property mentioned about.Below is the karma config file shared by the two projects and the debug logs that are output when running tests.
Karma config
PROJECT-1-debug-output.txt PROJECT-2-debug-output.txt
In the PROJECT-2 output you will see only ~20 tests ran. This is because I used an
fdescribe
to run a single test file so as to reduce the noise a little. The same result--no coverage--happens with or without this change.The point of failure seems to be here:
Thanks in advance for your support.