karma-runner / karma

Spectacular Test Runner for JavaScript
http://karma-runner.github.io
MIT License
11.95k stars 1.71k forks source link

Karma becomes unresponsive instead of failing #3290

Open jslegers opened 5 years ago

jslegers commented 5 years ago

I'm starting my Karma like this (in Java) :

ArrayList<String> karmaTestCommand = new ArrayList<String>();
boolean isWindows = System.getProperty("os.name").startsWith("Windows");
if (isWindows) {
  karmaTestCommand.add("cmd"); //on Windows, NPM is not an executable, but a .cmd file
  karmaTestCommand.add("/c");
}
karmaTestCommand.add("npm");
karmaTestCommand.add("run");
karmaTestCommand.add("test");

ProcessBuilder karmaProcessBuilder = new ProcessBuilder(karmaTestCommand);
karmaProcessBuilder.inheritIO();
Map<String, String> karmaProcessEnv = karmaProcessBuilder.environment();
karmaProcessEnv.put("RIA_TESTSERVER_PORT", Integer.toString(testserverPort));
karmaProcessEnv.put("KARMA_SERVER_PORT", Integer.toString(karmaServerPort));
Process karmaProcess = karmaProcessBuilder.start();

boolean completed = new ProcessWatchDog(karmaProcess).waitFor(20, TimeUnit.MINUTES);
if (!completed) {
  System.err.println("Tests timed out after 20 minutes!");
  RIATestReport.writeTestTimeoutReport("target/junit_reports/test-results.xml", RunKarmaTests.class.getName());
}

This starts the following script :

"scripts": {
  "test": "karma start common/test/karma/karma.conf.js --singleRun=true || (exit 0)"
}

Due to some issue with Firefox on one of our Jenkins slaves, Karma behaves like this :

[java] 02 04 2019 14:06:25.834:WARN [launcher]: Firefox have not captured in 60000 ms, killing.
[java] 02 04 2019 14:06:25.891:DEBUG [launcher]: Process Firefox exited with code 0
[java] 02 04 2019 14:06:25.891:DEBUG [temp-dir]: Cleaning temp dir C:\Users\release\AppData\Local\Temp\karma-95416947
[java] 02 04 2019 14:06:25.897:INFO [launcher]: Trying to start Firefox again (1/2).
[java] 02 04 2019 14:06:25.897:DEBUG [launcher]: Restarting Firefox
[java] 02 04 2019 14:06:25.897:DEBUG [temp-dir]: Creating temp dir at C:\Users\release\AppData\Local\Temp\karma-95416947
[java] 02 04 2019 14:06:25.898:DEBUG [launcher]: C:\Program Files\Mozilla Firefox\firefox.exe http://localhost:51005/?id=95416947 -profile C:\Users\release\AppData\Local\Temp\karma-95416947 -no-remote
[java] 02 04 2019 14:07:25.898:WARN [launcher]: Firefox have not captured in 60000 ms, killing.
[java] 02 04 2019 14:07:25.961:DEBUG [launcher]: Process Firefox exited with code 0
[java] 02 04 2019 14:07:25.961:DEBUG [temp-dir]: Cleaning temp dir C:\Users\release\AppData\Local\Temp\karma-95416947
[java] 02 04 2019 14:07:25.967:INFO [launcher]: Trying to start Firefox again (2/2).
[java] 02 04 2019 14:07:25.967:DEBUG [launcher]: Restarting Firefox
[java] 02 04 2019 14:07:25.967:DEBUG [temp-dir]: Creating temp dir at C:\Users\release\AppData\Local\Temp\karma-95416947
[java] 02 04 2019 14:07:25.968:DEBUG [launcher]: C:\Program Files\Mozilla Firefox\firefox.exe http://localhost:51005/?id=95416947 -profile C:\Users\release\AppData\Local\Temp\karma-95416947 -no-remote
[java] 02 04 2019 14:08:25.968:WARN [launcher]: Firefox have not captured in 60000 ms, killing.
[java] 02 04 2019 14:08:26.038:DEBUG [launcher]: Process Firefox exited with code 0
[java] 02 04 2019 14:08:26.038:DEBUG [temp-dir]: Cleaning temp dir C:\Users\release\AppData\Local\Temp\karma-95416947
[java] 02 04 2019 14:08:26.045:ERROR [launcher]: Firefox failed 2 times (timeout). Giving up.

This causes Karma to become unresponsive and will result in the process reaching a timeout after 20 minutes.

Is there any was I can get this process to end immediately, so I don't block my Jenkins slave for nothing?

johnjbarton commented 5 years ago

The launcher is supposed to see browser_process_failure and exit. https://github.com/karma-runner/karma/blob/c311ac00cef4a957f889ed613238793c0ffa95a2/lib/launchers/base.js#L111

For some reason this does not happen in your case.

To solve this we need to add encapsulated management of the state of launcher and log its transitions. We did this for browser in #3202. Then --logLevel=DEBUG will guide us to the issue.

jslegers commented 5 years ago

To solve this we need to add encapsulated management of the state of launcher and log its transitions. We did this for browser in #3202.

I'm not entirely sure what you're saying here.

Anyway, do you need anything from me for this?

johnjbarton commented 5 years ago

If you want to try to debug your issue you can add logging to the copy of karma-runner base.js to see what values prevent the line above from being executed. Since there is no practical way for us to reproduce your issue, ultimately better logging is all we can do.

croes commented 5 years ago

I spent some time debugging this issue. You can easily reproduce it by setting an extremely low captureTimeout (like 2ms). When trying to run multiple browsers, you'll notice that Karma hangs after giving up on restarts.

Upon further investigation, I noticed that the browser_process_failure listener in https://github.com/karma-runner/karma/blob/13ed69522bb19a2d26b61fe72f1ce43b64ac30c3/lib/launcher.js#L77 is never invoked.

The event is emitted in https://github.com/karma-runner/karma/blob/13ed69522bb19a2d26b61fe72f1ce43b64ac30c3/lib/launchers/base.js#L121. Emitting the event on this (similar to the done event a few lines above it), fixes the issue:

if (this.error && this.state !== BEING_FORCE_KILLED && this.state !== RESTARTING) {
      emitter.emit('browser_process_failure', this) // trigger the server's event listener
      this.emit('browser_process_failure') // trigger the launcher's event listener
}

Not sure if this is the proper way to fix this, but at least now we know why it is hanging.