From a3202f8e2bf6c2f296400ff8b3e49b61a6caa685 Mon Sep 17 00:00:00 2001 From: Joyee Cheung Date: Thu, 25 Aug 2022 18:08:53 +0800 Subject: [PATCH] test: deflake child process exec timeout tests On Windows it might take too long for the parent to start the communication with a child process, so by the time the parent starts its own timer, the child process might have already completed running, and the parent in those tests won't have a chance to terminate these child processes after the timeout. To address this issue, raise the time for which the child is supposed to run to make sure that the parent starts its own timer before the child terminates in the tests. Also, split the test into smaller ones to reduce the overhead. PR-URL: https://github.com/nodejs/node/pull/44390 Refs: https://github.com/nodejs/reliability/issues/356 Reviewed-By: James M Snell Reviewed-By: Stephen Belanger --- test/common/child_process.js | 45 ++++++++++++ .../test-child-process-exec-timeout-expire.js | 50 +++++++++++++ .../test-child-process-exec-timeout-kill.js | 39 ++++++++++ ...-child-process-exec-timeout-not-expired.js | 34 +++++++++ .../test-child-process-exec-timeout.js | 73 ------------------- 5 files changed, 168 insertions(+), 73 deletions(-) create mode 100644 test/common/child_process.js create mode 100644 test/parallel/test-child-process-exec-timeout-expire.js create mode 100644 test/parallel/test-child-process-exec-timeout-kill.js create mode 100644 test/parallel/test-child-process-exec-timeout-not-expired.js delete mode 100644 test/parallel/test-child-process-exec-timeout.js diff --git a/test/common/child_process.js b/test/common/child_process.js new file mode 100644 index 00000000000000..30669821bf4165 --- /dev/null +++ b/test/common/child_process.js @@ -0,0 +1,45 @@ +'use strict'; + +const assert = require('assert'); +const common = require('./'); + +// Workaround for Windows Server 2008R2 +// When CMD is used to launch a process and CMD is killed too quickly, the +// process can stay behind running in suspended state, never completing. +function cleanupStaleProcess(filename) { + if (!common.isWindows) { + return; + } + process.once('beforeExit', () => { + const basename = filename.replace(/.*[/\\]/g, ''); + require('child_process') + .execFileSync(`${process.env.SystemRoot}\\System32\\wbem\\WMIC.exe`, [ + 'process', + 'where', + `commandline like '%${basename}%child'`, + 'delete', + '/nointeractive', + ]); + }); +} + +// This should keep the child process running long enough to expire +// the timeout. +const kExpiringChildRunTime = common.platformTimeout(20 * 1000); +const kExpiringParentTimer = 1; +assert(kExpiringChildRunTime > kExpiringParentTimer); + +function logAfterTime(time) { + setTimeout(() => { + // The following console statements are part of the test. + console.log('child stdout'); + console.error('child stderr'); + }, time); +} + +module.exports = { + cleanupStaleProcess, + logAfterTime, + kExpiringChildRunTime, + kExpiringParentTimer +}; diff --git a/test/parallel/test-child-process-exec-timeout-expire.js b/test/parallel/test-child-process-exec-timeout-expire.js new file mode 100644 index 00000000000000..08e54544836d98 --- /dev/null +++ b/test/parallel/test-child-process-exec-timeout-expire.js @@ -0,0 +1,50 @@ +'use strict'; + +// Test exec() with a timeout that expires. + +const common = require('../common'); +const assert = require('assert'); +const cp = require('child_process'); + +const { + cleanupStaleProcess, + logAfterTime, + kExpiringChildRunTime, + kExpiringParentTimer +} = require('../common/child_process'); + +if (process.argv[2] === 'child') { + logAfterTime(kExpiringChildRunTime); + return; +} + +const cmd = `"${process.execPath}" "${__filename}" child`; + +cp.exec(cmd, { + timeout: kExpiringParentTimer, +}, common.mustCall((err, stdout, stderr) => { + console.log('[stdout]', stdout.trim()); + console.log('[stderr]', stderr.trim()); + + let sigterm = 'SIGTERM'; + assert.strictEqual(err.killed, true); + // TODO OpenBSD returns a null signal and 143 for code + if (common.isOpenBSD) { + assert.strictEqual(err.code, 143); + sigterm = null; + } else { + assert.strictEqual(err.code, null); + } + // At least starting with Darwin Kernel Version 16.4.0, sending a SIGTERM to a + // process that is still starting up kills it with SIGKILL instead of SIGTERM. + // See: https://github.com/libuv/libuv/issues/1226 + if (common.isOSX) + assert.ok(err.signal === 'SIGTERM' || err.signal === 'SIGKILL'); + else + assert.strictEqual(err.signal, sigterm); + assert.strictEqual(err.cmd, cmd); + assert.strictEqual(stdout.trim(), ''); + assert.strictEqual(stderr.trim(), ''); +})); + +cleanupStaleProcess(__filename); diff --git a/test/parallel/test-child-process-exec-timeout-kill.js b/test/parallel/test-child-process-exec-timeout-kill.js new file mode 100644 index 00000000000000..0be04e8607f3d0 --- /dev/null +++ b/test/parallel/test-child-process-exec-timeout-kill.js @@ -0,0 +1,39 @@ +'use strict'; + +// Test exec() with both a timeout and a killSignal. + +const common = require('../common'); +const assert = require('assert'); +const cp = require('child_process'); + +const { + cleanupStaleProcess, + logInTimeout, + kExpiringChildRunTime, + kExpiringParentTimer, +} = require('../common/child_process'); + +if (process.argv[2] === 'child') { + logInTimeout(kExpiringChildRunTime); + return; +} + +const cmd = `"${process.execPath}" "${__filename}" child`; + +// Test with a different kill signal. +cp.exec(cmd, { + timeout: kExpiringParentTimer, + killSignal: 'SIGKILL' +}, common.mustCall((err, stdout, stderr) => { + console.log('[stdout]', stdout.trim()); + console.log('[stderr]', stderr.trim()); + + assert.strictEqual(err.killed, true); + assert.strictEqual(err.code, null); + assert.strictEqual(err.signal, 'SIGKILL'); + assert.strictEqual(err.cmd, cmd); + assert.strictEqual(stdout.trim(), ''); + assert.strictEqual(stderr.trim(), ''); +})); + +cleanupStaleProcess(__filename); diff --git a/test/parallel/test-child-process-exec-timeout-not-expired.js b/test/parallel/test-child-process-exec-timeout-not-expired.js new file mode 100644 index 00000000000000..fb0af5fa8f59d5 --- /dev/null +++ b/test/parallel/test-child-process-exec-timeout-not-expired.js @@ -0,0 +1,34 @@ +'use strict'; + +// Test exec() when a timeout is set, but not expired. + +const common = require('../common'); +const assert = require('assert'); +const cp = require('child_process'); + +const { + cleanupStaleProcess, + logAfterTime +} = require('../common/child_process'); + +const kTimeoutNotSupposedToExpire = 2 ** 30; +const childRunTime = common.platformTimeout(100); + +// The time spent in the child should be smaller than the timeout below. +assert(childRunTime < kTimeoutNotSupposedToExpire); + +if (process.argv[2] === 'child') { + logAfterTime(childRunTime); + return; +} + +const cmd = `"${process.execPath}" "${__filename}" child`; + +cp.exec(cmd, { + timeout: kTimeoutNotSupposedToExpire +}, common.mustSucceed((stdout, stderr) => { + assert.strictEqual(stdout.trim(), 'child stdout'); + assert.strictEqual(stderr.trim(), 'child stderr'); +})); + +cleanupStaleProcess(__filename); diff --git a/test/parallel/test-child-process-exec-timeout.js b/test/parallel/test-child-process-exec-timeout.js deleted file mode 100644 index 64648d62bb3284..00000000000000 --- a/test/parallel/test-child-process-exec-timeout.js +++ /dev/null @@ -1,73 +0,0 @@ -'use strict'; -const common = require('../common'); -const assert = require('assert'); -const cp = require('child_process'); - -if (process.argv[2] === 'child') { - setTimeout(() => { - // The following console statements are part of the test. - console.log('child stdout'); - console.error('child stderr'); - }, common.platformTimeout(1000)); - return; -} - -const cmd = `"${process.execPath}" "${__filename}" child`; - -// Test the case where a timeout is set, and it expires. -cp.exec(cmd, { timeout: 1 }, common.mustCall((err, stdout, stderr) => { - let sigterm = 'SIGTERM'; - assert.strictEqual(err.killed, true); - // TODO OpenBSD returns a null signal and 143 for code - if (common.isOpenBSD) { - assert.strictEqual(err.code, 143); - sigterm = null; - } else { - assert.strictEqual(err.code, null); - } - // At least starting with Darwin Kernel Version 16.4.0, sending a SIGTERM to a - // process that is still starting up kills it with SIGKILL instead of SIGTERM. - // See: https://github.com/libuv/libuv/issues/1226 - if (common.isOSX) - assert.ok(err.signal === 'SIGTERM' || err.signal === 'SIGKILL'); - else - assert.strictEqual(err.signal, sigterm); - assert.strictEqual(err.cmd, cmd); - assert.strictEqual(stdout.trim(), ''); - assert.strictEqual(stderr.trim(), ''); -})); - -// Test with a different kill signal. -cp.exec(cmd, { - timeout: 1, - killSignal: 'SIGKILL' -}, common.mustCall((err, stdout, stderr) => { - assert.strictEqual(err.killed, true); - assert.strictEqual(err.code, null); - assert.strictEqual(err.signal, 'SIGKILL'); - assert.strictEqual(err.cmd, cmd); - assert.strictEqual(stdout.trim(), ''); - assert.strictEqual(stderr.trim(), ''); -})); - -// Test the case where a timeout is set, but not expired. -cp.exec(cmd, { timeout: 2 ** 30 }, common.mustSucceed((stdout, stderr) => { - assert.strictEqual(stdout.trim(), 'child stdout'); - assert.strictEqual(stderr.trim(), 'child stderr'); -})); - -// Workaround for Windows Server 2008R2 -// When CMD is used to launch a process and CMD is killed too quickly, the -// process can stay behind running in suspended state, never completing. -if (common.isWindows) { - process.once('beforeExit', () => { - const basename = __filename.replace(/.*[/\\]/g, ''); - cp.execFileSync(`${process.env.SystemRoot}\\System32\\wbem\\WMIC.exe`, [ - 'process', - 'where', - `commandline like '%${basename}%child'`, - 'delete', - '/nointeractive', - ]); - }); -}