Skip to content

Kill gulp-karma process on Ctrl-C#3129

Merged
esanzgar merged 1 commit intomasterfrom
kill-karma
Apr 16, 2021
Merged

Kill gulp-karma process on Ctrl-C#3129
esanzgar merged 1 commit intomasterfrom
kill-karma

Conversation

@esanzgar
Copy link
Contributor

@esanzgar esanzgar commented Mar 9, 2021

The only way to kill yarn test --watch is sending a SIGINT via a
Ctrl+C keyboard shorcut. Killing karma process in
this way sometimes leaves the parent gulp process orphan. That's because
when karma is killed by SIGINT sometimes doesn't run the done in the
callback, hence leaving the gulp process waiting for the done signal.

On more rare occasions, I have seen orphan karma process too.

The solution presented here registers a listener for SIGINT and call the
done function. It doesn't unregister the event.

@codecov
Copy link

codecov bot commented Mar 9, 2021

Codecov Report

Merging #3129 (d496235) into master (2874ac0) will not change coverage.
The diff coverage is n/a.

Impacted file tree graph

@@           Coverage Diff           @@
##           master    #3129   +/-   ##
=======================================
  Coverage   97.95%   97.95%           
=======================================
  Files         207      207           
  Lines        7667     7667           
  Branches     1728     1728           
=======================================
  Hits         7510     7510           
  Misses        157      157           

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 2874ac0...d496235. Read the comment docs.

@LMS007
Copy link
Contributor

LMS007 commented Mar 9, 2021

Yes, I think this has not worked right for some time. Prior to this change I see this in the console when I quit.

Chrome Headless 90.0.4427.0 (Mac OS 11.1.0) ERROR
  Disconnected Client disconnected from CONNECTED state (transport close)
Chrome Headless 90.0.4427.0 (Mac OS 11.1.0): Executed 2759 of 2759 SUCCESS (11.665 secs / 6.242 secs)
Chrome Headless 90.0.4427.0 (Mac OS 11.1.0) ERROR
  Disconnected Client disconnected from CONNECTED state (transport close)
Chrome Headless 90.0.4427.0 (Mac OS 11.1.0) ERROR
  Disconnected Client disconnected from CONNECTED state (transport close)
[12:29:00] Finished '<anonymous>' after 42 s
[12:29:00] Finished 'test' after 44 s

Now I see this.

[12:29:55] The following tasks did not complete: test, <anonymous>
[12:29:55] Did you forget to signal async completion?

Which still seems slightly broken?

@robertknight
Copy link
Contributor

. Killing karma in this way sometimes leaves an orphan process in the background.

To recap, when running yarn test --watch there are at least three processes running, typically more because Chromium has several processes:

  1. A node process running yarn
  2. A node process running gulp + the server-side part of Karma
  3. Multiple Chromium processes created by puppeteer running the client-side part of Karma
[I]  ~/h/client (yarn)> ps -j
USER     PID  PPID  PGID   SESS JOBC STAT   TT       TIME COMMAND
robert  5712  5385  5712      0    1 T    s003    0:00.42 node /usr/local/Cellar/yarn/1.22.10/libexec/bin/yarn.js test
robert  5713  5712  5712      0    1 T    s003    0:39.24 gulp test --watch
robert  5726  5713  5712      0    1 T    s003    0:00.43 /Users/robert/hypothesis/client/node_modules/puppeteer/.local
robert  5729  5726  5712      0    1 T    s003    0:00.27 /Users/robert/hypothesis/client/node_modules/puppeteer/.local
robert  5730  5726  5712      0    1 T    s003    0:00.72 /Users/robert/hypothesis/client/node_modules/puppeteer/.local
robert  5731  5726  5712      0    1 T    s003    0:02.55 /Users/robert/hypothesis/client/node_modules/puppeteer/.local

Since all of these processes belong to the same process group (PGID 5712 here) pressing Ctrl+C will send SIGINT to all of them. Are you saying that the node process running gulp is not responding to SIGINT, or a different process?

@esanzgar
Copy link
Contributor Author

esanzgar commented Mar 18, 2021

I don't experience orphan process when I use gulp test. It must be something related to the node/yarn parent process:

yarn test process parents and children:

-+= 00001 root /sbin/launchd
 \-+= 35037 esanzgar /Applications/Visual Studio Code - Insiders.app/Contents/MacOS/Electron
   \-+- 35462 esanzgar /Applications/Visual Studio Code - Insiders.app/Contents/Frameworks/Code - Insiders H
     \-+- 35466 esanzgar /Applications/Visual Studio Code - Insiders.app/Contents/Frameworks/Code - Insiders
       \-+= 42617 esanzgar /bin/zsh -l
-->     \-+= 38417 esanzgar node /usr/local/Cellar/yarn/1.22.10/libexec/bin/yarn.js test --grep NotebookM -
           \-+- 38418 esanzgar gulp test --grep NotebookM --watch
             \-+- 38434 esanzgar /Users/esanzgar/Development/hypothesis/client/node_modules/puppeteer/.local
               |--- 38437 esanzgar /Users/esanzgar/Development/hypothesis/client/node_modules/puppeteer/.loc
               |--- 38438 esanzgar /Users/esanzgar/Development/hypothesis/client/node_modules/puppeteer/.loc
               \--- 38439 esanzgar /Users/esanzgar/Development/hypothesis/client/node_modules/puppeteer/.lo

After the yarn process is killed with Ctrl+C:

-+= 00001 root /sbin/launchd
 \--- 38418 esanzgar gulp test --grep NotebookM --watch

Based on this, it seems that the gulp process handles the SIGINT.

@esanzgar
Copy link
Contributor Author

esanzgar commented Mar 18, 2021

gulp test handles the SIGINT and in some circumstances only kills subprocess on double Ctrl+C. Thus, what happens is that on Ctrl+C, yarn sends the SIGINT to gulp process, who ignores the first SIGINT and waits for the second Ctrl+C but the process is orphan at that point.

The way to test this is to make create a syntax error (by removing a bracket or parenthesis) while running gulp test --watch [--grep X]

@esanzgar esanzgar force-pushed the kill-karma branch 2 times, most recently from 545b8bf to 0517409 Compare March 18, 2021 18:58
@esanzgar
Copy link
Contributor Author

I present a modified solution that doesn't leave:

[12:29:55] The following tasks did not complete: test, <anonymous>
[12:29:55] Did you forget to signal async completion?

@LMS007
Copy link
Contributor

LMS007 commented Mar 19, 2021

This works for me, and I would give this my approval, but please check with Rob too.
Thanks for staying on this Eduardo.

@robertknight
Copy link
Contributor

Eduardo's comments above provide some understanding of what is going on but I didn't feel we'd gotten to the bottom of it. With some further experimentation I have a minimal reproduction.

  1. Make the following change to gulpfile.js:
diff --git a/gulpfile.js b/gulpfile.js
index c16ab5292..66fea7833 100644
--- a/gulpfile.js
+++ b/gulpfile.js
@@ -354,6 +354,16 @@ function runKarma(done) {
   ).start();
 }
 
+gulp.task('longtask', done => {
+  setTimeout(() => {
+    done();
+  }, 20000);
+});
+
+process.on('SIGINT', () => {
+  console.log('gulp process received sigint');
+});
+
 // Unit and integration testing tasks.
 // Some (eg. a11y) tests rely on CSS bundles, so build these first.
 gulp.task(
  1. Then run gulp longtask and wait until gulp prints that it has started the longtask task.
  2. Press Ctrl+C - at this point you can see that gulp does exit automatically. If you remove the SIGINT handler it does.
  3. Run yarn gulp longtask and wait until it prints "Starting longtask" then press Ctrl+C. The task will appear to exit immediately but if you run ps you can see that gulp is still running.

So it looks like what is happening here is that if a process does not register a SIGINT handler, the default one kills the gulp process. If it does register a SIGINT handler, then the handler has to do that itself.

My guess then as to what happens with Karma is that Karma is installing a SIGINT handler of its own, and sure enough this is what is happening.

Experimenting locally with interrupting Karma at different points I found that:

  • The done callback passed to the Karma constructor was always invoked shortly after Ctrl+C was pressed
  • If Karma had got to the point of actually running the tests, then everything stopped and exited fairly quickly
  • If Ctrl+C was pressed after the underlined START: text from Karma appeared but before any tests had run, then Karma would call the done callback very quickly, but the gulp process would continue to run and later further output from Karma would appear.

So it seems that depending on when Karma's SIGINT handler receives the signal, it will always call the done callback, but it may or may not properly stop all Karma-related activity that is happening. When it fails to do so, the gulp process remains running. When gulp is run via Yarn, yarn will always exit immediately even if gulp continues to run.

On that basis, what I think we want to do here is to give Karma a small amount of time to finish running and cleanup when SIGINT is pressed, but enforce that the process stops after some delay. So maybe something like:

process.on('SIGINT', () => {
  // Give Karma a chance to handle SIGINT and cleanup, but forcibly
  // exit if it takes too long.
  setTimeout(() => process.exit(1), 5000);
});

Thoughts?

@esanzgar
Copy link
Contributor Author

esanzgar commented Mar 22, 2021

I tried Robert's suggestion:

process.on('SIGINT', () => {
  // Give Karma a chance to handle SIGINT and cleanup, but forcibly
  // exit if it takes too long.
  setTimeout(() => process.exit(1), 5000);
});

but I got an orphaned karma process in this scenario:

  1. create a syntax error in sidebar-test.js
  2. started a gulp test --grep sidebar-test --watch
  3. kill the gulp process right after Starting browser ChromeHeadless
esanzgar@snowflake client % ./node_modules/.bin/gulp test --grep sidebar-test --watch
[14:45:25] Using gulpfile ~/Development/hypothesis/client/gulpfile.js
[14:45:25] Starting 'test'...
[14:45:25] Starting 'build-css'...
[14:45:27] Finished 'build-css' after 2.19 s
[14:45:27] Starting '<anonymous>'...
Running tests matching pattern "sidebar-test":  [
  'annotator/test/pdf-sidebar-test.js',
  'annotator/test/sidebar-test.js'
]
22 03 2021 14:45:28.176:INFO [framework.browserify]: registering rebuild (autoWatch=true)
^C[14:45:28] Finished '<anonymous>' after 894 ms
[14:45:28] Finished 'test' after 3.09 s
^C22 03 2021 14:45:30.506:ERROR [framework.browserify]: bundle error
22 03 2021 14:45:30.507:ERROR [framework.browserify]: SyntaxError: /Users/esanzgar/Development/hypothesis/client/src/annotator/test/sidebar-test.js: Unexpected token (876:0)

  874 |     });
  875 |   });
> 876 | );
      | ^
  877 | while parsing file: /Users/esanzgar/Development/hypothesis/client/src/annotator/test/sidebar-test.js
22 03 2021 14:45:30.684:WARN [karma]: No captured browser, open http://localhost:9876/
22 03 2021 14:45:30.700:INFO [karma-server]: Karma v6.2.0 server started at http://localhost:9876/
22 03 2021 14:45:30.703:INFO [launcher]: Launching browsers ChromeHeadless_Custom with concurrency unlimited
22 03 2021 14:45:30.755:INFO [launcher]: Starting browser ChromeHeadless


esanzgar@snowflake client % ps -a | grep karma
18277 ttys006    0:00.29 /Users/esanzgar/Development/hypothesis/client/node_modules/puppeteer/.local-chromium/mac-856583/chrome-mac/Chromium.app/Contents/MacOS/Chromium --user-data-dir=/var/folders/w2/6l_zlgwn1zx6whm0hzym363w0000gn/T/karma-31306801 --enable-automation --no-default-browser-check --no-first-run --disable-default-apps --disable-popup-blocking --disable-translate --disable-background-timer-throttling --disable-renderer-backgrounding --disable-device-discovery-notifications http://localhost:9876/?id=31306801 --headless --disable-gpu --disable-dev-shm-usage --remote-debugging-port=9222

If the setTimeout is removed then I got no orphaned process.

Based on this empirical test, I would suggest we keep the patch proposed in this PR.

The only way to kill `yarn test --watch` is sending a SIGINT via a
<kbd>Ctrl</kbd>+<kbd>C</kbd> keyboard shorcut. Killing karma process in
this way sometimes leaves the parent gulp process orphan. That's because
when karma is killed by SIGINT sometimes doesn't run the `done` in the
callback, hence leaving the gulp process waiting for the `done` signal.

On more rare occasions, I have seen orphan karma process too.

The solution presented here registers a listener for SIGINT and call the
`done` function. It doesn't unregister the event.
@esanzgar
Copy link
Contributor Author

@robertknight your solution works, so I am pushing your solution.

@esanzgar esanzgar requested a review from robertknight April 15, 2021 14:47
Copy link
Contributor

@robertknight robertknight left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm happy to get this merged to fix the problem when running tests through yarn test specifically, as opposed to gulp test. However it would be good to not have to copy this code into each project where we are using a combination of yarn + gulp + Karma. Perhaps for example we could fix this issue upstream in Karma itself.

@esanzgar esanzgar merged commit 4db28b7 into master Apr 16, 2021
@esanzgar esanzgar deleted the kill-karma branch April 16, 2021 10:42
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants