sometimes junit-reported just doesn't generate reports

[jcompagner]

I am not sure if this plugin of karma is to blame or that this is a problem in karma itself. It is very annoying that our builds now and then break when we run it on Jenkins because our jobs are configured to fail/error the build when there are no karma reports found.

And now and then (sometimes it goed ok for quite a few builds, and then suddenly it can fail a few times after each other) this plugin doesn't generate the reports. I am running karma in full debug output that i paste below, there you see 2 runs you see everything is successful but in 1 of them 1 output line is missing: [INFO] 19 03 2021 14:05:36.674:DEBUG [reporter.junit]: JUnit results written to "/[fullpath]/target/TEST-browser-karma.xml".

how can this happen?

the one that is fine:

[INFO] Chrome Headless 89.0.4389.82 (Linux x86_64): Executed 198 of 225 (skipped 27) SUCCESS (7.294 secs / 5.876 secs) [INFO] 19 03 2021 14:05:36.432:DEBUG [launcher]: CAPTURED -> BEING_KILLED [INFO] 19 03 2021 14:05:36.432:DEBUG [launcher]: BEING_KILLED -> BEING_FORCE_KILLED [INFO] 19 03 2021 14:05:36.432:DEBUG [Chrome Headless 89.0.4389.82 (Linux x86_64)]: CONNECTED -> DISCONNECTED [INFO] TOTAL: 198 SUCCESS [INFO] TOTAL: 198 SUCCESS [INFO] 19 03 2021 14:05:36.579:DEBUG [karma-server]: Run complete, exiting. [INFO] 19 03 2021 14:05:36.580:DEBUG [launcher]: Disconnecting all browsers [INFO] 19 03 2021 14:05:36.580:DEBUG [launcher]: BEING_FORCE_KILLED -> BEING_FORCE_KILLED [INFO] 19 03 2021 14:05:36.587:DEBUG [proxy]: Destroying proxy agents [INFO] 19 03 2021 14:05:36.663:DEBUG [launcher]: Process ChromeHeadless exited with code null and signal SIGTERM [INFO] 19 03 2021 14:05:36.663:DEBUG [temp-dir]: Cleaning temp dir /tmp/karma-12630893 [INFO] 19 03 2021 14:05:36.674:DEBUG [reporter.junit]: JUnit results written to "[fullpath]/target/TEST-browser-karma.xml". [INFO] 19 03 2021 14:05:36.691:DEBUG [launcher]: Finished all browsers [INFO] 19 03 2021 14:05:36.692:DEBUG [launcher]: BEING_FORCE_KILLED -> FINISHED [INFO] 19 03 2021 14:05:36.692:DEBUG [launcher]: FINISHED -> FINISHED [INFO] 19 03 2021 14:05:36.698:DEBUG [karma-server]: Received stop event, exiting. [INFO] 19 03 2021 14:05:36.698:DEBUG [launcher]: Disconnecting all browsers [INFO] 19 03 2021 14:05:36.699:DEBUG [launcher]: FINISHED -> BEING_FORCE_KILLED [INFO] 19 03 2021 14:05:36.699:DEBUG [proxy]: Destroying proxy agents

the one that fails:

[INFO] 21 03 2021 22:37:56.802:DEBUG [Chrome Headless 89.0.4389.82 (Linux x86_64)]: EXECUTING -> CONNECTED [INFO] [INFO] 21 03 2021 22:37:56.816:DEBUG [launcher]: CAPTURED -> BEING_KILLED [INFO] 21 03 2021 22:37:56.816:DEBUG [launcher]: BEING_KILLED -> BEING_FORCE_KILLED [INFO] 21 03 2021 22:37:56.817:DEBUG [Chrome Headless 89.0.4389.82 (Linux x86_64)]: CONNECTED -> DISCONNECTED [INFO] TOTAL: 198 SUCCESS [INFO] TOTAL: 198 SUCCESS [INFO] 21 03 2021 22:37:57.078:DEBUG [karma-server]: Run complete, exiting. [INFO] 21 03 2021 22:37:57.090:DEBUG [launcher]: Disconnecting all browsers [INFO] 21 03 2021 22:37:57.090:DEBUG [launcher]: BEING_FORCE_KILLED -> BEING_FORCE_KILLED [INFO] 21 03 2021 22:37:57.102:DEBUG [proxy]: Destroying proxy agents [INFO] 21 03 2021 22:37:57.449:DEBUG [launcher]: Process ChromeHeadless exited with code null and signal SIGTERM [INFO] 21 03 2021 22:37:57.449:DEBUG [temp-dir]: Cleaning temp dir /tmp/karma-58044430 [INFO] 21 03 2021 22:37:57.610:DEBUG [launcher]: Finished all browsers [INFO] 21 03 2021 22:37:57.610:DEBUG [launcher]: BEING_FORCE_KILLED -> FINISHED [INFO] 21 03 2021 22:37:57.610:DEBUG [launcher]: FINISHED -> FINISHED [INFO] 21 03 2021 22:37:57.614:DEBUG [karma-server]: Received stop event, exiting. [INFO] 21 03 2021 22:37:57.615:DEBUG [launcher]: Disconnecting all browsers [INFO] 21 03 2021 22:37:57.615:DEBUG [launcher]: FINISHED -> BEING_FORCE_KILLED [INFO] 21 03 2021 22:37:57.615:DEBUG [proxy]: Destroying proxy agents

[jcompagner]

its even very weird, i can't just explain this. See the above log of builds. all the failed builds happen at "22:31". this is because there is an automatic job run at night that builds something that this job uses somewhere as an artifact (completely unrelated to the npm/karma stuff, is another java plugin that is build) The same mvn commands ("clean install") are used for all of them including the one that i then trigger in the morning to make the build correct again . Its not always the case that it only fails to generate reports for those triggered builds but it is a very common scenario.

[JayBur]

@jcompagner I seem to be running into this issue as well.

When run locally or triggering a jenkins build manually it will generally create the report. However, as part of scheduled jenkins builds the report now often isn't generated.

Have you found out anything else since then?

[jcompagner]

The thing is lately we don't have many problems anymore with that... Maybe it is because of updates on various npm packages.

we didn't change must also on karma.config i think this is really the only change that we did:

https://github.com/Servoy/servoy-eclipse/commit/5b9c3a67be75406ecb787d134bd755ef2be389f5#diff-2fdd2a7830de8c7d13672d8e85cd91f3fe6e74a941e0642110a2b3bffcd4da83R29 adding a coverage plugin..

[JayBur]

Thanks for getting back to me so soon. I think the only change we had since this started occuring were minor npm updates as well. So maybe getting to latest might fix things. If that doesn't work I think I'll start looking at using alternative formats to supply jenkins with the results.

[arobinson]

We are seeing this issue as well. I'm starting to wonder if this is a karma issue, as we had the same issue in a coverage reporter and had to revert to an older unsupported coverage reporter. Seems odd that two different reporters would have the same issue and be the reporter code versus a common bug in the karma plugin code that it isn't waiting for the promise to complete of the reporter before exiting the process.

The other issue I am referring to is from this project, but it is the karma-coverage reporter: https://github.com/karma-runner/karma-coverage/issues/434

Our "fix" was to uninstall karma-coverage and use the deprecated karma-coverage-istanbul-reporter instead. With that plugin we have been getting reliable creation of the coverage reports in Jenkins.

Or perhaps there is shared code in karma-runner between karma-junit-reporter and karma-coverage that could have an issue?

Looking at the source code for karma-coverage-istanbul-reporter, that code uses onRunComplete callback to generate the report. I see that both karma-coverage and karma-junit-reporer use onExit hook to produce the code. Is it possible that karma is not always waiting for the onExit hook to finish but onRunComplete is a more reliable hook?

FYI, that code can be seen here: https://github.com/mattlewis92/karma-coverage-istanbul-reporter/blob/b61dd3067a4c60270a71508fdce8d4f95ed1f4bc/src/reporter.js#L242

[arobinson]

I added some console.log statements and ran a job on our jenkins machine. It reproduced the issue. Here was the output:

------ onBrowserComplete
 TOTAL: 6848 SUCCESS

 Finished in 13 mins 20.84 secs / 9 mins 48.094 secs @ 19:38:33 GMT+0000 (Coordinated Universal Time)

 SUMMARY:
 ✔ 6848 tests completed
 ℹ 30 tests skipped
 TOTAL: 6848 SUCCESS
 ✔ Browser application bundle generation complete.
 ------ onExit called 1
 ------ onExit called 2
 07 09 2021 19:38:42.102:WARN [launcher]: Chrome was not killed in 2000 ms, sending SIGKILL.
 ✔ Browser application bundle generation complete.
 ------ onExit called 1
 ------ onExit called 2

Diff:

114a115
>       console.log('------ writeXmlForBrowser -> no output');
118a120
>     console.log('------ writeXmlForBrowser -> starting write');
126a129
>         console.log('------ pendingFileWritings', pendingFileWritings);
165a169
>     console.log('------ onBrowserComplete');
252a257
>     console.log('------ onExit called 1');
255a261
>       console.log('------ onExit called 2');

So, from the extra console logs, I can see that writeXmlForBrowser is never invoked, but onBrowserComplete was invoked. I'm assuming that this code executed and short-circuited the writing of the report:

    if (!suite || !result) {
      return // don't die if browser didn't start
    }

at the top of my job this was printed:

 07 09 2021 19:22:36.897:INFO [karma-server]: Karma v6.3.4 server started at http://localhost:9876/
 07 09 2021 19:22:36.897:INFO [launcher]: Launching browsers ChromeHeadless with concurrency unlimited
 07 09 2021 19:22:36.901:INFO [launcher]: Starting browser Chrome
 07 09 2021 19:25:04.887:WARN [launcher]: Chrome have not captured in 120000 ms, killing.
 07 09 2021 19:25:10.645:INFO [launcher]: Trying to start Chrome again (1/2).

Perhaps, since the browser was restarted, the reporter has the wrong value for the browser.id? If that is the case then this code in onBrowserComplete would not find anything:

var suite = suites[browser.id]

and it would therefore skip the creation of the report.

I can't reproduce this locally, but can ~75% of the time on Jenkins. I can try to get better information, but I cannot debug it, only can really use console logs. I'll keep trying, but let me know if you need more information

[arobinson]

After putting in more logging, I do not see initializeXmlForBrowser being called when the problem reproduces, so it would seem that karma did not call onRunStart nor onBrowserStart. I'm not sure how that is possible though

[arobinson]

Looks like this is a reproduction of this issue: https://github.com/karma-runner/karma/issues/945

[arobinson]

Work-around that seems to be functioning:

201c201,207
<       return
---
>       if (testsuite === undefined) {
>         initializeXmlForBrowser(browser)
>         testsuite = suites[browser.id]
>       }
>       if (!testsuite) {
>         return;
>       }

With context:

  this.specSuccess = this.specSkipped = this.specFailure = function (browser, result) {
    var testsuite = suites[browser.id]
    var validMilliTime
    var spec

    if (!testsuite) {
      if (testsuite === undefined) {
        initializeXmlForBrowser(browser)
        testsuite = suites[browser.id]
      }
      if (!testsuite) {
        return;
      }
    }

[ozkoidi]

Hello, I forked the project to test @arobinson's workaround and unfortunately I still get test executions without coverage reports sometimes. I'm running the tests for an Angular app in Azure DevOps pipeline and the test execution doesn't fail (I do have some NG0303 and NG0304 errors but I also have those when the reports are properly generated) but randomly the test coverage is not generated. In those cases the following logs are not present (which makes sense)

DEBUG [reporter:parallel-coverage]: relaying onRunComplete() on reporter:junit
DEBUG [reporter:parallel-coverage]: relaying onRunComplete() on reporter:coverage
DEBUG [reporter:parallel-coverage]: relaying done() on reporter:junit
DEBUG [reporter:parallel-coverage]: relaying done() on reporter:coverage
DEBUG [reporter.junit]: JUnit results written to samplePath/.../...report.xml
DEBUG [coverage]: Writing coverage to samplePath./.../Client/coverage

Any other ideas?

[jr01]

On our CI system the junit reporter sometimes (about 1 in 10 runs) doesn't write to disk. When that happens the 'progress' reporter also writes empty lines instead of something like Chrome Headless 96.0.4664.45 (Windows 10): Executed 1 of ....

Looking at the progress reporter code empty lines will be output if onBrowserStart isn't executed.

So my conclusion is the same as @arobinson - this is an issue in Karma core.