feat: support speed measure

packages/build-scripts/src/commands/build.ts

@@ -75,6 +75,7 @@ export = async function({
 
   let compiler: webpack.MultiCompiler;
   try {
+    context.timeMeasure.addTimeEvent('webpack', 'start');
     compiler = webpackInstance(webpackConfig);
   } catch (err) {
     log.error('CONFIG', chalk.red('Failed to load webpack config.'));
@@ -85,6 +86,7 @@ export = async function({
   const result = await new Promise((resolve, reject): void => {
     // typeof(stats) is webpack.compilation.MultiStats
     compiler.run((err, stats) => {
+      context.timeMeasure.addTimeEvent('webpack', 'end');
       if (err) {
         log.error('WEBPACK', (err.stack || err.toString()));
         reject(err);
@@ -97,6 +99,8 @@ export = async function({
       if (isSuccessful) {
         resolve({
           stats,
+          time: context.timeMeasure.getTimeMeasure(),
+          timeOutput: context.timeMeasure.getOutput(),
         });
       } else {
         reject(new Error('webpack compile error'));

packages/build-scripts/src/commands/start.ts

@@ -81,6 +81,7 @@ export = async function({
 
   let compiler;
   try {
+    context.timeMeasure.addTimeEvent('webpack', 'start');
     compiler = webpack(webpackConfig);
   } catch (err) {
     log.error('CONFIG', chalk.red('Failed to load webpack config.'));
@@ -94,6 +95,7 @@ export = async function({
   let isFirstCompile = true;
   // typeof(stats) is webpack.compilation.MultiStats
   compiler.hooks.done.tap('compileHook', async (stats) => {
+    context.timeMeasure.addTimeEvent('webpack', 'end');
     const isSuccessful = webpackStats({
       urls,
       stats,
@@ -107,6 +109,8 @@ export = async function({
       urls,
       isFirstCompile,
       stats,
+      time: context.timeMeasure.getTimeMeasure(),
+      timeOutput: context.timeMeasure.getOutput(),
     });
   });
   // require webpack-dev-server after context setup

packages/build-scripts/src/core/Context.ts

@@ -3,6 +3,7 @@ import { GlobalConfig } from '@jest/types/build/Config';
 import { Logger } from 'npmlog';
 import { IHash, Json, JsonValue, MaybeArray, MaybePromise, JsonArray } from '../types';
 import hijackWebpackResolve from '../utils/hijackWebpack';
+import TimeMeasure from '../utils/TimeMeasure';
 
 import path = require('path')
 import assert = require('assert')
@@ -69,7 +70,7 @@ export interface IOnHookCallback {
 }
 
 export interface IOnHook {
-  (eventName: string, callback: IOnHookCallback): void;
+  (eventName: string, callback: IOnHookCallback, pluginName?: string): void;
 }
 
 export interface IPluginConfigWebpack {
@@ -223,7 +224,7 @@ class Context {
   private modifyJestConfig: IJestConfigFunction[]
 
   private eventHooks: {
-    [name: string]: IOnHookCallback[];
+    [name: string]: [IOnHookCallback, string?][];
   }
 
   private internalValue: IHash<any>
@@ -236,6 +237,10 @@ class Context {
 
   private cancelTaskNames: string[]
 
+  private customPluginIndex: number
+
+  public timeMeasure: TimeMeasure
+
   public pkg: Json
 
   public userConfig: IUserConfig
@@ -249,6 +254,8 @@ class Context {
     plugins = [],
     getBuiltInPlugins = () => [],
   }: IContextOptions) {
+    this.timeMeasure = new TimeMeasure();
+    this.customPluginIndex = 0;
     this.command = command;
     this.commandArgs = args;
     this.rootDir = rootDir;
@@ -269,7 +276,10 @@ class Context {
     this.cliOptionRegistration = {};
     this.methodRegistration = {};
     this.cancelTaskNames = [];
+    this.timeMeasure.wrapEvent(this.init ,'init')({ plugins, getBuiltInPlugins });
+  }
 
+  private init(config: IContextOptions) {
     this.pkg = this.getProjectFile(PKG_FILE);
     this.userConfig = this.getUserConfig();
     // custom webpack
@@ -280,7 +290,7 @@ class Context {
     }
     // register buildin options
     this.registerCliOption(BUILTIN_CLI_OPTIONS);
-    const builtInPlugins: IPluginList = [...plugins, ...getBuiltInPlugins(this.userConfig)];
+    const builtInPlugins: IPluginList = [...config.plugins, ...config.getBuiltInPlugins(this.userConfig)];
     this.checkPluginValue(builtInPlugins); // check plugins property
     this.plugins = this.resolvePlugins(builtInPlugins);
   }
@@ -390,8 +400,10 @@ class Context {
     const userPlugins = [...builtInPlugins, ...(this.userConfig.plugins || [])].map((pluginInfo): IPluginInfo => {
       let fn;
       if (_.isFunction(pluginInfo)) {
+        const pluginName = `customPlugin_${this.customPluginIndex++}`;
         return {
-          fn: pluginInfo,
+          name: pluginName,
+          fn: this.timeMeasure.wrapPlugin(pluginInfo, pluginName),
           options: {},
         };
       }
@@ -411,7 +423,7 @@ class Context {
       return {
         name: plugins[0],
         pluginPath,
-        fn: fn.default || fn || ((): void => {}),
+        fn: this.timeMeasure.wrapPlugin(fn.default || fn || ((): void => {}), plugins[0]),
         options,
       };
     });
@@ -510,19 +522,20 @@ class Context {
     return result;
   }
 
-  public onHook: IOnHook = (key, fn) => {
+  public onHook: IOnHook = (key, fn, pluginName) => {
     if (!Array.isArray(this.eventHooks[key])) {
       this.eventHooks[key] = [];
     }
-    this.eventHooks[key].push(fn);
+    this.eventHooks[key].push([fn, pluginName]);
   }
 
   public applyHook = async (key: string, opts = {}): Promise<void> => {
     const hooks = this.eventHooks[key] || [];
 
-    for (const fn of hooks) {
+    for (const [fn, pluginName] of hooks) {
+      const hookFn = this.timeMeasure.wrapHook(fn, key, pluginName);
       // eslint-disable-next-line no-await-in-loop
-      await fn(opts);
+      await hookFn(opts);
     }
   }
 
@@ -546,10 +559,12 @@ class Context {
 
   private runPlugins = async (): Promise<void> => {
     for (const pluginInfo of this.plugins) {
-      const { fn, options } = pluginInfo;
+      const { fn, options, name } = pluginInfo;
 
       const pluginContext = _.pick(this, PLUGIN_CONTEXT_KEY);
-
+      const proxyOnHook: IOnHook = (eventName, callback, pluginName) => {
+        this.onHook(eventName, callback, pluginName || name);
+      };
       const pluginAPI = {
         log,
         context: pluginContext,
@@ -559,7 +574,7 @@ class Context {
         cancelTask: this.cancelTask,
         onGetWebpackConfig: this.onGetWebpackConfig,
         onGetJestConfig: this.onGetJestConfig,
-        onHook: this.onHook,
+        onHook: proxyOnHook,
         setValue: this.setValue,
         getValue: this.getValue,
         registerUserConfig: this.registerUserConfig,
@@ -670,10 +685,10 @@ class Context {
   }
 
   public setUp = async (): Promise<ITaskConfig[]> => {
-    await this.runPlugins();
-    await this.runUserConfig();
-    await this.runWebpackFunctions();
-    await this.runCliOption();
+    await this.timeMeasure.wrapEvent(this.runPlugins, 'runPlugins')();
+    await this.timeMeasure.wrapEvent(this.runUserConfig, 'runUserConfig')();
+    await this.timeMeasure.wrapEvent(this.runWebpackFunctions, 'runWebpackFunctions')();
+    await this.timeMeasure.wrapEvent(this.runCliOption, 'runCliOption')();
     // filter webpack config by cancelTaskNames
     this.configArr = this.configArr.filter((config) => !this.cancelTaskNames.includes(config.name));
     return this.configArr;

packages/build-scripts/src/utils/TimeMeasure.ts

@@ -0,0 +1,130 @@
+import { IPlugin, IPluginAPI, IPluginOptions, IOnHookCallback } from '../core/Context';
+import { tagBg, textWithColor, humanTime } from './output';
+
+interface IMeasure {
+  start?: number;
+  end?: number;
+  name?: string;
+}
+
+interface IMeasureData {
+  [key: string]: IMeasure;
+}
+
+interface IHooksTimeMeasure {
+  [key: string]: IMeasure[];
+}
+
+const getCurTime = (): number => new Date().getTime();
+const getOutputTime = (start: number, end: number): string => {
+  return textWithColor(humanTime(start, end), end - start);
+};
+class TimeMeasure {
+  private startTime: number;
+
+  private pluginTimeMeasure: IMeasureData;
+
+  private hooksTimeMeasure: IHooksTimeMeasure;
+
+  private firstPluginExcuteTime: number;
+
+  private timeEvent: IMeasureData;
+
+  constructor() {
+    this.startTime = getCurTime();
+    this.hooksTimeMeasure = {};
+    this.pluginTimeMeasure = {};
+    this.firstPluginExcuteTime = 0;
+    this.timeEvent = {};
+  }
+
+  public wrapPlugin(plugin: IPlugin, name: string): IPlugin {
+    if (!name) return plugin;
+    this.pluginTimeMeasure[name] = {};
+    return async (api: IPluginAPI, options?: IPluginOptions) => {
+      const curTime = getCurTime();
+      this.pluginTimeMeasure[name].start = curTime;
+      if (!this.firstPluginExcuteTime) {
+        this.firstPluginExcuteTime = curTime;
+      }
+      await plugin(api, options);
+      this.pluginTimeMeasure[name].end = getCurTime();
+    };
+  }
+
+  public wrapHook(hookFn: IOnHookCallback, hookName: string, name: string): IOnHookCallback {
+    if (!name) return hookFn;
+    this.hooksTimeMeasure[name] = [];
+    return async (opts = {}) => {
+      const hooksTime: IMeasure = {
+        name: hookName,
+      };
+      hooksTime.start = getCurTime();
+      await hookFn(opts);
+      hooksTime.end = getCurTime();
+      this.hooksTimeMeasure[name].push(hooksTime);
+    };
+  }
+
+  public wrapEvent(eventFn: Function, eventName: string): Function {
+    return async (...args: any) => {
+      this.addTimeEvent(eventName, 'start');
+      eventFn(...args);
+      this.addTimeEvent(eventName, 'end');
+    };
+  }
+
+  public getTimeMeasure() {
+    return {
+      start: this.startTime,
+      firstPlugin: this.firstPluginExcuteTime,
+      plugins: this.pluginTimeMeasure,
+      hooks: this.hooksTimeMeasure,
+      timeEvent: this.timeEvent,
+    };
+  }
+
+  public addTimeEvent(event: string, eventType: 'start' | 'end'): void {
+    if (!this.timeEvent[event]) {
+      this.timeEvent[event] = {};
+    }
+    this.timeEvent[event][eventType] = getCurTime();
+  }
+
+  public getOutput(): string {
+    const curTime = getCurTime();
+    let output = `\n\n${tagBg('[Speed Measure]')} ⏱  \n`;
+
+    // start time
+    output += `General start time took ${getOutputTime(this.startTime, curTime)}\n`;
+
+    // resolve time before run plugin
+    output += `Resolve plugins time took ${getOutputTime(this.startTime, this.firstPluginExcuteTime)}\n`;
+
+    // plugin time
+    Object.keys(this.pluginTimeMeasure).forEach((pluginName) => {
+      const pluginTime = this.pluginTimeMeasure[pluginName];
+      output += `  Plugin ${pluginName} execution time took ${getOutputTime(pluginTime.start, pluginTime.end)}\n`;
+    });
+
+    // hooks time
+    Object.keys(this.hooksTimeMeasure).forEach((pluginName) => {
+      const hooksTime = this.hooksTimeMeasure[pluginName];
+      output += `  Hooks in ${pluginName} execution:\n`;
+      hooksTime.forEach((measureInfo) => {
+        output += `    Hook ${measureInfo.name} time took ${getOutputTime(measureInfo.start, measureInfo.end)}\n`;
+      });
+    });
+
+    output += `Time event\n`;
+
+    Object.keys(this.timeEvent).forEach((eventName) => {
+      const eventTime = this.timeEvent[eventName];
+      output += `  Event ${eventName} time took ${getOutputTime(eventTime.start, eventTime.end)}\n`;
+    });
+
+    return output;
+  }
+}
+
+export default TimeMeasure;

packages/build-scripts/src/utils/output.ts

@@ -0,0 +1,48 @@
+import chalk from 'chalk';
+
+const MS_IN_MINUTE = 60000;
+const MS_IN_SECOND = 1000;
+
+const tagBg = (text: string) => chalk.bgBlack.green.bold(text);
+const textWithColor = (text: string, time: number) => {
+  let textModifier = chalk.bold;
+  if (time > 10000) {
+    textModifier = textModifier.red;
+  } else if (time > 2000) {
+    textModifier = textModifier.yellow;
+  } else {
+    textModifier = textModifier.green;
+  }
+
+  return textModifier(text);
+};
+
+// inspired by https://github.com/stephencookdev/speed-measure-webpack-plugin/blob/master/output.js#L8
+const humanTime = (start: number, end: number) => {
+  const ms = end - start;
+  const minutes = Math.floor(ms / MS_IN_MINUTE);
+  const secondsRaw = (ms - minutes * MS_IN_MINUTE) / MS_IN_SECOND;
+  const secondsWhole = Math.floor(secondsRaw);
+  const remainderPrecision = secondsWhole > 0 ? 2 : 3;
+  const secondsRemainder = Math.min(secondsRaw - secondsWhole, 0.99);
+  const seconds =
+    secondsWhole +
+    secondsRemainder
+      .toPrecision(remainderPrecision)
+      .replace(/^0/, '')
+      .replace(/0+$/, '')
+      .replace(/^\.$/, '');
+
+  let time = '';
+
+  if (minutes > 0) time += `${minutes  } min${  minutes > 1 ? 's' : ''  }, `;
+  time += `${seconds  } secs`;
+
+  return time;
+};
+
+export {
+  tagBg,
+  textWithColor,
+  humanTime,
+};