fix(child-process): Prevent duplicate logs when any package-oriented execution fails

Previously, avoiding duplicate logging required special handling per use-case and only covered non-streaming variants.

Author: evocateur

commands/exec/__tests__/exec-command.test.js

@@ -89,9 +89,14 @@ describe("ExecCommand", () => {
       expect(ChildProcessUtilities.spawn).toHaveBeenCalledTimes(1);
       expect(ChildProcessUtilities.spawn).lastCalledWith("ls", [], {
         cwd: path.join(testDir, "packages/package-2"),
+        pkg: expect.objectContaining({
+          name: "package-2",
+        }),
         env: expect.objectContaining({
           LERNA_PACKAGE_NAME: "package-2",
+          LERNA_ROOT_PATH: testDir,
         }),
+        extendEnv: false,
         reject: true,
         shell: true,
       });
@@ -120,9 +125,13 @@ describe("ExecCommand", () => {
       expect(ChildProcessUtilities.spawn).toHaveBeenCalledTimes(1);
       expect(ChildProcessUtilities.spawn).lastCalledWith("ls", [], {
         cwd: path.join(testDir, "packages/package-1"),
+        pkg: expect.objectContaining({
+          name: "package-1",
+        }),
         env: expect.objectContaining({
           LERNA_PACKAGE_NAME: "package-1",
         }),
+        extendEnv: false,
         reject: true,
         shell: true,
       });

commands/exec/index.js

@@ -27,50 +27,46 @@ class ExecCommand extends Command {
 
   initialize() {
     const dashedArgs = this.options["--"] || [];
-    const { cmd, args } = this.options;
 
-    this.command = cmd || dashedArgs.shift();
-    this.args = (args || []).concat(dashedArgs);
+    this.command = this.options.cmd || dashedArgs.shift();
+    this.args = (this.options.args || []).concat(dashedArgs);
 
     if (!this.command) {
       throw new ValidationError("ENOCOMMAND", "A command to execute is required");
     }
 
-    const { filteredPackages } = this;
+    // accessing properties of process.env can be expensive,
+    // so cache it here to reduce churn during tighter loops
+    this.env = Object.assign({}, process.env);
 
     this.batchedPackages = this.toposort
-      ? batchPackages(filteredPackages, this.options.rejectCycles)
-      : [filteredPackages];
+      ? batchPackages(this.filteredPackages, this.options.rejectCycles)
+      : [this.filteredPackages];
   }
 
   execute() {
     if (this.options.parallel) {
       return this.runCommandInPackagesParallel();
     }
 
-    return runParallelBatches(this.batchedPackages, this.concurrency, pkg =>
-      this.runCommandInPackage(pkg).catch(err => {
-        this.logger.error("exec", `'${err.cmd}' errored in '${pkg.name}'`);
+    const runner = this.options.stream
+      ? pkg => this.runCommandInPackageStreaming(pkg)
+      : pkg => this.runCommandInPackageCapturing(pkg);
 
-        if (err.code) {
-          // log non-lerna error cleanly
-          err.pkg = pkg;
-        }
-
-        throw err;
-      })
-    );
+    return runParallelBatches(this.batchedPackages, this.concurrency, runner);
   }
 
   getOpts(pkg) {
     return {
       cwd: pkg.location,
       shell: true,
-      env: Object.assign({}, process.env, {
+      extendEnv: false,
+      env: Object.assign({}, this.env, {
         LERNA_PACKAGE_NAME: pkg.name,
         LERNA_ROOT_PATH: this.project.rootPath,
       }),
       reject: this.options.bail,
+      pkg,
     };
   }
 
@@ -82,28 +78,19 @@ class ExecCommand extends Command {
       [this.command].concat(this.args).join(" ")
     );
 
-    return Promise.all(
-      this.filteredPackages.map(pkg =>
-        ChildProcessUtilities.spawnStreaming(
-          this.command,
-          this.args,
-          this.getOpts(pkg),
-          this.options.prefix && pkg.name
-        )
-      )
-    );
+    return Promise.all(this.filteredPackages.map(pkg => this.runCommandInPackageStreaming(pkg)));
   }
 
-  runCommandInPackage(pkg) {
-    if (this.options.stream) {
-      return ChildProcessUtilities.spawnStreaming(
-        this.command,
-        this.args,
-        this.getOpts(pkg),
-        this.options.prefix && pkg.name
-      );
-    }
+  runCommandInPackageStreaming(pkg) {
+    return ChildProcessUtilities.spawnStreaming(
+      this.command,
+      this.args,
+      this.getOpts(pkg),
+      this.options.prefix && pkg.name
+    );
+  }
 
+  runCommandInPackageCapturing(pkg) {
     return ChildProcessUtilities.spawn(this.command, this.args, this.getOpts(pkg));
   }
 }

commands/run/index.js

@@ -88,7 +88,7 @@ class RunCommand extends Command {
       ? pkg => this.runScriptInPackageStreaming(pkg)
       : pkg => this.runScriptInPackageCapturing(pkg);
 
-    return runParallelBatches(this.batchedPackages, this.concurrency, pkg => runner(pkg));
+    return runParallelBatches(this.batchedPackages, this.concurrency, runner);
   }
 
   runScriptInPackagesParallel() {
@@ -107,20 +107,9 @@ class RunCommand extends Command {
   }
 
   runScriptInPackageCapturing(pkg) {
-    return npmRunScript(this.script, this.getOpts(pkg))
-      .then(result => {
-        output(result.stdout);
-      })
-      .catch(err => {
-        this.logger.error("run", `'${this.script}' errored in '${pkg.name}'`);
-
-        if (err.code) {
-          // log non-lerna error cleanly
-          err.pkg = pkg;
-        }
-
-        throw err;
-      });
+    return npmRunScript(this.script, this.getOpts(pkg)).then(result => {
+      output(result.stdout);
+    });
   }
 }
 

core/child-process/__tests__/child-process.test.js

@@ -42,6 +42,19 @@ describe("ChildProcessUtilities", () => {
       expect(one.stdout).toBe("one");
       expect(two.stdout).toBe("two");
     });
+
+    it("decorates opts.pkg on error if caught", async () => {
+      try {
+        await ChildProcessUtilities.exec(
+          "theVeneratedVirginianVeteranWhoseMenAreAll",
+          ["liningUpToPutMeUpOnAPedestal"],
+          { pkg: { name: "hamilton" } }
+        );
+      } catch (err) {
+        expect(err.code).toBe("ENOENT");
+        expect(err.pkg).toEqual({ name: "hamilton" });
+      }
+    });
   });
 
   describe(".spawn()", () => {

core/child-process/index.js

@@ -13,19 +13,20 @@ const NUM_COLORS = colorWheel.length;
 
 function exec(command, args, opts) {
   const options = Object.assign({ stdio: "pipe" }, opts);
+  const spawned = spawnProcess(command, args, options);
 
-  return _spawn(command, args, options);
+  return wrapError(spawned);
 }
 
 function execSync(command, args, opts) {
   return execa.sync(command, args, opts).stdout;
 }
 
 function spawn(command, args, opts) {
-  const options = Object.assign({}, opts);
-  options.stdio = "inherit";
+  const options = Object.assign({}, opts, { stdio: "inherit" });
+  const spawned = spawnProcess(command, args, options);
 
-  return _spawn(command, args, options);
+  return wrapError(spawned);
 }
 
 // istanbul ignore next
@@ -35,7 +36,7 @@ function spawnStreaming(command, args, opts, prefix) {
 
   const colorName = colorWheel[children % NUM_COLORS];
   const color = chalk[colorName];
-  const spawned = _spawn(command, args, options);
+  const spawned = spawnProcess(command, args, options);
 
   const stdoutOpts = {};
   const stderrOpts = {}; // mergeMultiline causes escaped newlines :P
@@ -54,15 +55,14 @@ function spawnStreaming(command, args, opts, prefix) {
   spawned.stdout.pipe(logTransformer(stdoutOpts)).pipe(process.stdout);
   spawned.stderr.pipe(logTransformer(stderrOpts)).pipe(process.stderr);
 
-  return spawned;
+  return wrapError(spawned);
 }
 
 function getChildProcessCount() {
   return children;
 }
 
-// eslint-disable-next-line no-underscore-dangle
-function _spawn(command, args, opts) {
+function spawnProcess(command, args, opts) {
   children += 1;
 
   const child = execa(command, args, opts);
@@ -78,9 +78,29 @@ function _spawn(command, args, opts) {
   child.once("exit", drain);
   child.once("error", drain);
 
+  if (opts.pkg) {
+    child.pkg = opts.pkg;
+  }
+
   return child;
 }
 
+function wrapError(spawned) {
+  if (spawned.pkg) {
+    return spawned.catch(err => {
+      // istanbul ignore else
+      if (err.code) {
+        // log non-lerna error cleanly
+        err.pkg = spawned.pkg;
+      }
+
+      throw err;
+    });
+  }
+
+  return spawned;
+}
+
 exports.exec = exec;
 exports.execSync = execSync;
 exports.spawn = spawn;

integration/lerna-run.test.js

@@ -15,7 +15,7 @@ describe("lerna run", () => {
     try {
       await cliRunner(cwd)(...args);
     } catch (err) {
-      expect(err.message).toMatch("run 'fail' errored in 'package-3'");
+      expect(err.message).toMatch("npm run fail --silent exited 1 in 'package-3'");
     }
   });
 

utils/get-npm-exec-opts/get-npm-exec-opts.js

@@ -7,6 +7,7 @@ module.exports = getExecOpts;
 function getExecOpts(pkg, registry) {
   const opts = {
     cwd: pkg.location,
+    pkg,
   };
 
   if (registry) {

utils/npm-dist-tag/__tests__/npm-dist-tag.test.js

@@ -27,6 +27,7 @@ describe("dist-tag", () => {
 
       expect(ChildProcessUtilities.exec).lastCalledWith("npm", ["dist-tag", "add", "[email protected]", tag], {
         cwd: pkg.location,
+        pkg,
       });
     });
 
@@ -39,6 +40,7 @@ describe("dist-tag", () => {
           npm_config_registry: registry,
         }),
         extendEnv: false,
+        pkg,
       });
     });
   });
@@ -56,6 +58,7 @@ describe("dist-tag", () => {
 
       expect(ChildProcessUtilities.exec).lastCalledWith("npm", ["dist-tag", "rm", pkg.name, tag], {
         cwd: pkg.location,
+        pkg,
       });
     });
 
@@ -68,6 +71,7 @@ describe("dist-tag", () => {
           npm_config_registry: registry,
         }),
         extendEnv: false,
+        pkg,
       });
     });
   });
@@ -88,6 +92,7 @@ describe("dist-tag", () => {
 
       expect(ChildProcessUtilities.execSync).lastCalledWith("npm", ["dist-tag", "ls", pkg.name], {
         cwd: pkg.location,
+        pkg,
       });
     });
 
@@ -102,6 +107,7 @@ describe("dist-tag", () => {
           npm_config_registry: registry,
         }),
         extendEnv: false,
+        pkg,
       });
     });
   });