node icon indicating copy to clipboard operation
node copied to clipboard

`node:child_process.fork` does not generate cpu-prof when process is killed

Open AriPerkkio opened this issue 1 year ago • 3 comments

Version

v20.17.0

Platform

Darwin Aris-MacBook-Air.local 23.6.0 Darwin Kernel Version 23.6.0: Mon Jul 29 21:16:46 PDT 2024; root:xnu-10063.141.2~1/RELEASE_ARM64_T8112 arm64

Subsystem

No response

What steps will reproduce the bug?

// repro.mjs
import { fork } from "node:child_process";
import { Worker } from "node:worker_threads";
import { existsSync, writeFileSync } from "node:fs";
import assert from "node:assert";

writeFileSync( "./example.mjs", `
console.log("Hello world");

// Keep alive
setInterval(() => {}, 1_000);
`, "utf8");

const subprocess = fork("./example.mjs", { execArgv: ["--cpu-prof", "--cpu-prof-dir=forks-profile"] });
const onExit = new Promise((r) => subprocess.on("exit", r));

await new Promise((r) => setTimeout(r, 1000));
subprocess.kill();
await onExit;

const thread = new Worker("./example.mjs", { execArgv: ["--cpu-prof", "--cpu-prof-dir=threads-profile"] });

await new Promise((r) => setTimeout(r, 1000));
await thread.terminate();

assert(existsSync("./threads-profile"), "Threads profile missing");
assert(existsSync("./forks-profile"), "Forks profile missing");
 $ node repro.mjs 
Hello world
Hello world
node:internal/modules/run_main:129
    triggerUncaughtException(
    ^

AssertionError [ERR_ASSERTION]: Forks profile missing
    at file:///x/repros/scripts/repro.mjs:26:1
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5) {
  generatedMessage: false,
  code: 'ERR_ASSERTION',
  actual: false,
  expected: true,
  operator: '=='
}

Node.js v20.17.0

How often does it reproduce? Is there a required condition?

Always

What is the expected behavior? Why is that the expected behavior?

When a child process is killed with .kill(), it does not generate the CPU profile that --cpu-prof argument instructs it to do. I would expect profile to be generated.

This is inconsistent with node:worker_threads where terminating a Worker with .terminate() does still generate the profile. It also makes it difficult to debug slow child processes as you cannot get profile info without waiting for graceful exit.

What do you see instead?

Child process is killed and CPU profile is not written.

Additional information

No response

AriPerkkio avatar Sep 24 '24 07:09 AriPerkkio

I think because the child process will exit directly when you call subprocess.kill, it has no chance to dump the profile. If you add this code process.on('SIGTERM', () => { process.exit(); }) to child process, it can dump the profile.

theanarkh avatar Sep 24 '24 11:09 theanarkh

This seems to tie into another topic of whether subprocess.kill()/SIGTERM should just terminate the process with only the essential cleanups (it's debatable whether dumping cpu profiles should be considered essential), or maybe we should just invent a new method/signal/way for the subprocess to finish with also less-essential cleanups.

joyeecheung avatar Sep 24 '24 18:09 joyeecheung

If you add this code process.on('SIGTERM', () => { process.exit(); }) to child process, it can dump the profile.

Thanks for the work-around, this seems like good solution for now. I think I'll add this handler when we detect --cpu-prof or equivalent flags in process.execArgv.

This seems to tie into another topic of whether subprocess.kill()/SIGTERM should just terminate the process with only the essential cleanups (it's debatable whether dumping cpu profiles should be considered essential)

I see, this is not a simple decision to make. And especially when comparing to node:worker_threads I'm not sure these two were meant to be equivalent. In the documentation of .terminate() it's stated that execution doesn't stop immediatelly like node:child_process does:

Stop all JavaScript execution in the worker thread as soon as possible

But still I would like node:child_process to write CPU (and other) profiles before it finishes. This will make debugging slow or stuck-like processes much easier.

AriPerkkio avatar Sep 25 '24 13:09 AriPerkkio