feat: Add --profile option to lerna exec and lerna run

commands/exec/README.md

@@ -79,3 +79,27 @@ Pass `--no-bail` to disable this behavior, executing in _all_ packages regardles
 
 Disable package name prefixing when output is streaming (`--stream` _or_ `--parallel`).
 This option can be useful when piping results to other processes, such as editor plugins.
+
+### `--profile`
+
+Profiles the command executions and produces a performance profile which can be analyzed using DevTools in a
+Chromium-based browser (direct url: `devtools://devtools/bundled/devtools_app.html`). The profile shows a timeline of
+the command executions where each execution is assigned to an open slot. The number of slots is determined by the
+`--concurrency` option and the number of open slots is determined by `--concurrency` minus the number of ongoing
+operations. The end result is a visualization of the parallel execution of your commands.
+
+The default location of the performance profiles is at the root of your project.
+
+```sh
+$ lerna run exec --profile
+```
+
+> **Note:** Lerna will only profile when topological sorting is enabled (i.e. without `--parallel` and `--no-sort`).
+
+### `--profile-location <location>`
+
+You can provide a custom location for the performance profiles. The location is relative to the root of your project.
+
+```sh
+$ lerna run build --profile --profile-location=logs/profile/
+```

commands/exec/command.js

@@ -57,6 +57,16 @@ exports.builder = yargs => {
         hidden: true,
         type: "boolean",
       },
+      profile: {
+        group: "Command Options:",
+        describe: "Profile command executions and output performance profile to default location.",
+        type: "boolean",
+      },
+      "profile-location": {
+        group: "Command Options:",
+        describe: "Output performance profile to custom location (relative to the project root).",
+        type: "string",
+      },
     });
 
   return filterable(yargs);

commands/exec/index.js

@@ -4,6 +4,7 @@ const pMap = require("p-map");
 
 const ChildProcessUtilities = require("@lerna/child-process");
 const Command = require("@lerna/command");
+const Profiler = require("@lerna/profiler");
 const runTopologically = require("@lerna/run-topologically");
 const ValidationError = require("@lerna/validation-error");
 const { getFilteredPackages } = require("@lerna/filter-options");
@@ -120,14 +121,33 @@ class ExecCommand extends Command {
   }
 
   runCommandInPackagesTopological() {
+    let profiler;
+    let runnerWithProfiler;
     const runner = this.options.stream
       ? pkg => this.runCommandInPackageStreaming(pkg)
       : pkg => this.runCommandInPackageCapturing(pkg);
 
-    return runTopologically(this.filteredPackages, runner, {
+    if (this.options.profile) {
+      profiler = new Profiler({
+        concurrency: this.concurrency,
+        log: this.logger,
+        profile: this.options.profile,
+        profileLocation: this.options.profileLocation,
+        rootPath: this.project.rootPath,
+      });
+      runnerWithProfiler = pkg => profiler.run(() => runner(pkg), pkg.name);
+    }
+
+    let chain = runTopologically(this.filteredPackages, profiler ? runnerWithProfiler : runner, {
       concurrency: this.concurrency,
       rejectCycles: this.options.rejectCycles,
     });
+
+    if (profiler) {
+      chain = chain.then(results => profiler.output().then(() => results));
+    }
+
+    return chain;
   }
 
   runCommandInPackagesParallel() {

commands/exec/package.json

@@ -35,6 +35,7 @@
     "@lerna/child-process": "file:../../core/child-process",
     "@lerna/command": "file:../../core/command",
     "@lerna/filter-options": "file:../../core/filter-options",
+    "@lerna/profiler": "file:../../utils/profiler",
     "@lerna/run-topologically": "file:../../utils/run-topologically",
     "@lerna/validation-error": "file:../../core/validation-error",
     "p-map": "^2.1.0"

commands/run/README.md

@@ -82,3 +82,27 @@ Pass `--no-bail` to disable this behavior, running the script in _all_ packages
 
 Disable package name prefixing when output is streaming (`--stream` _or_ `--parallel`).
 This option can be useful when piping results to other processes, such as editor plugins.
+
+### `--profile`
+
+Profiles the script executions and produces a performance profile which can be analyzed using DevTools in a
+Chromium-based browser (direct url: `devtools://devtools/bundled/devtools_app.html`). The profile shows a timeline of
+the script executions where each execution is assigned to an open slot. The number of slots is determined by the
+`--concurrency` option and the number of open slots is determined by `--concurrency` minus the number of ongoing
+operations. The end result is a visualization of the parallel execution of your scripts.
+
+The default location of the performance profiles is at the root of your project.
+
+```sh
+$ lerna run build --profile
+```
+
+> **Note:** Lerna will only profile when topological sorting is enabled (i.e. without `--parallel` and `--no-sort`).
+
+### `--profile-location <location>`
+
+You can provide a custom location for the performance profiles. The location is relative to the root of your project.
+
+```sh
+$ lerna run build --profile --profile-location=logs/profile/
+```

commands/run/command.js

@@ -59,6 +59,16 @@ exports.builder = yargs => {
         hidden: true,
         type: "boolean",
       },
+      profile: {
+        group: "Command Options:",
+        describe: "Profile script executions and output performance profile to default location.",
+        type: "boolean",
+      },
+      "profile-location": {
+        group: "Command Options:",
+        describe: "Output performance profile to custom location (relative to the project root).",
+        type: "string",
+      },
     });
 
   return filterable(yargs);

commands/run/index.js

@@ -5,6 +5,7 @@ const pMap = require("p-map");
 const Command = require("@lerna/command");
 const npmRunScript = require("@lerna/npm-run-script");
 const output = require("@lerna/output");
+const Profiler = require("@lerna/profiler");
 const timer = require("@lerna/timer");
 const runTopologically = require("@lerna/run-topologically");
 const ValidationError = require("@lerna/validation-error");
@@ -128,14 +129,33 @@ class RunCommand extends Command {
   }
 
   runScriptInPackagesTopological() {
+    let profiler;
+    let runnerWithProfiler;
     const runner = this.options.stream
       ? pkg => this.runScriptInPackageStreaming(pkg)
       : pkg => this.runScriptInPackageCapturing(pkg);
 
-    return runTopologically(this.packagesWithScript, runner, {
+    if (this.options.profile) {
+      profiler = new Profiler({
+        concurrency: this.concurrency,
+        log: this.logger,
+        profile: this.options.profile,
+        profileLocation: this.options.profileLocation,
+        rootPath: this.project.rootPath,
+      });
+      runnerWithProfiler = pkg => profiler.run(() => runner(pkg), pkg.name);
+    }
+
+    let chain = runTopologically(this.packagesWithScript, runnerWithProfiler || runner, {
       concurrency: this.concurrency,
       rejectCycles: this.options.rejectCycles,
     });
+
+    if (profiler) {
+      chain = chain.then(results => profiler.output().then(() => results));
+    }
+
+    return chain;
   }
 
   runScriptInPackagesParallel() {

commands/run/package.json

@@ -36,6 +36,7 @@
     "@lerna/filter-options": "file:../../core/filter-options",
     "@lerna/npm-run-script": "file:../../utils/npm-run-script",
     "@lerna/output": "file:../../utils/output",
+    "@lerna/profiler": "file:../../utils/profiler",
     "@lerna/run-topologically": "file:../../utils/run-topologically",
     "@lerna/timer": "file:../../utils/timer",
     "@lerna/validation-error": "file:../../core/validation-error",

utils/profiler/README.md

@@ -0,0 +1,9 @@
+# `@lerna/profiler`
+
+> An internal Lerna tool
+
+## Usage
+
+You probably shouldn't, at least directly.
+
+Install [lerna](https://www.npmjs.com/package/lerna) for access to the `lerna` CLI.

utils/profiler/package.json

@@ -0,0 +1,39 @@
+{
+  "name": "@lerna/profiler",
+  "version": "3.18.5",
+  "description": "An internal Lerna tool",
+  "keywords": [
+    "lerna",
+    "utils"
+  ],
+  "homepage": "https://github.com/lerna/lerna/tree/master/utils/profiler#readme",
+  "license": "MIT",
+  "author": {
+    "name": "Benjamin Weggersen",
+    "url": "https://github.com/bweggersen"
+  },
+  "files": [
+    "profiler.js"
+  ],
+  "main": "profiler.js",
+  "engines": {
+    "node": ">= 6.9.0"
+  },
+  "publishConfig": {
+    "access": "public"
+  },
+  "repository": {
+    "type": "git",
+    "url": "git+https://github.com/lerna/lerna.git",
+    "directory": "utils/profiler"
+  },
+  "scripts": {
+    "test": "echo \"Run tests from root\" && exit 1"
+  },
+  "dependencies": {
+    "figgy-pudding": "^3.5.1",
+    "fs-extra": "^8.1.0",
+    "npmlog": "^4.1.2",
+    "upath": "^1.2.0"
+  }
+}

utils/profiler/profiler.js

@@ -0,0 +1,98 @@
+"use strict";
+
+const figgyPudding = require("figgy-pudding");
+const fs = require("fs-extra");
+const npmlog = require("npmlog");
+const upath = require("upath");
+
+const hrtimeToMicroseconds = hrtime => {
+  return (hrtime[0] * 1e9 + hrtime[1]) / 1000;
+};
+
+const range = len => {
+  return Array(len)
+    .fill()
+    .map((_, idx) => idx);
+};
+
+const getTimeBasedFilename = () => {
+  const now = new Date(); // 2011-10-05T14:48:00.000Z
+  const datetime = now.toISOString().split(".")[0]; // 2011-10-05T14:48:00
+  const datetimeNormalized = datetime.replace(/-|:/g, ""); // 20111005T144800
+  return `Lerna-Profile-${datetimeNormalized}.json`;
+};
+
+const getOutputPath = (rootPath, profileLocation) => {
+  const outputFolder = profileLocation ? upath.join(rootPath, profileLocation) : rootPath;
+  return upath.join(outputFolder, getTimeBasedFilename());
+};
+
+const ProfilerConfig = figgyPudding({
+  concurrency: {},
+  log: { default: npmlog },
+  profile: "enabled",
+  enabled: {},
+  profileLocation: {},
+  rootPath: {},
+});
+
+class Profiler {
+  constructor(opts) {
+    const { concurrency, enabled, log, profileLocation, rootPath } = ProfilerConfig(opts);
+
+    this.enabled = enabled;
+    this.events = [];
+    this.log = log;
+    this.outputPath = getOutputPath(rootPath, profileLocation);
+    this.threads = range(concurrency);
+  }
+
+  run(fn, name) {
+    if (!this.enabled) {
+      return fn();
+    }
+
+    let startTime;
+    let threadId;
+
+    return Promise.resolve()
+      .then(() => {
+        startTime = process.hrtime();
+        threadId = this.threads.shift();
+      })
+      .then(() => fn())
+      .then(value => {
+        const duration = process.hrtime(startTime);
+
+        // Trace Event Format documentation:
+        // https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
+        const event = {
+          name,
+          ph: "X",
+          ts: hrtimeToMicroseconds(startTime),
+          pid: 1,
+          tid: threadId,
+          dur: hrtimeToMicroseconds(duration),
+        };
+
+        this.events.push(event);
+
+        this.threads.unshift(threadId);
+        this.threads.sort();
+
+        return value;
+      });
+  }
+
+  output() {
+    if (!this.enabled) {
+      return;
+    }
+
+    return fs
+      .outputJson(this.outputPath, this.events)
+      .then(() => this.log.info("profiler", `Performance profile saved to ${this.outputPath}`));
+  }
+}
+
+module.exports = Profiler;