fix(@angular-devkit/build-angular): add debugging and timing information in JavaScript and CSS optimization plugins

alan-agius4 · dgp1130 · commit a54018d8f5f9 · 2022-05-20T11:40:39.000-07:00
This can be useful to debug slow builds. Example of output ``` LOG from build-angular.JavaScriptOptimizerPlugin <t> optimize asset: runtime.ad5c30339e926c89.js: 221.959564 ms <t> optimize asset: polyfills.ec3ffae5bac27204.js: 1071.080092 ms <t> optimize asset: main.aa8a15155ca2133f.js: 3391.588635 ms <t> optimize js assets: 3483.799739 ms LOG from build-angular.CssOptimizerPlugin <t> optimize asset: styles.d251c5bf54715558.css: 26.569907 ms <t> optimize css assets: 34.441737 ms ``` ``` LOG from build-angular.JavaScriptOptimizerPlugin <i> polyfills.ec3ffae5bac27204.js restored from cache. <i> runtime.ad5c30339e926c89.js restored from cache. <t> optimize asset: main.69fb55a243b46bfa.js: 2618.5191210000003 ms <t> optimize js assets: 2721.226144 ms LOG from build-angular.CssOptimizerPlugin <i> styles.d251c5bf54715558.css restored from cache. <t> optimize css assets: 12.149169 ms ``` (cherry picked from commit 6cbb941)
diff --git a/packages/angular_devkit/build_angular/src/webpack/plugins/css-optimizer-plugin.ts b/packages/angular_devkit/build_angular/src/webpack/plugins/css-optimizer-plugin.ts
@@ -40,6 +40,8 @@ export class CssOptimizerPlugin {
     const { OriginalSource, SourceMapSource } = compiler.webpack.sources;
 
     compiler.hooks.compilation.tap(PLUGIN_NAME, (compilation) => {
+      const logger = compilation.getLogger('build-angular.CssOptimizerPlugin');
+
       compilation.hooks.processAssets.tapPromise(
         {
           name: PLUGIN_NAME,
@@ -48,6 +50,7 @@ export class CssOptimizerPlugin {
         async (compilationAssets) => {
           const cache = compilation.options.cache && compilation.getCache(PLUGIN_NAME);
 
+          logger.time('optimize css assets');
           for (const assetName of Object.keys(compilationAssets)) {
             if (!/\.(?:css|scss|sass|less|styl)$/.test(assetName)) {
               continue;
@@ -70,6 +73,7 @@ export class CssOptimizerPlugin {
               >();
 
               if (cachedOutput) {
+                logger.debug(`${name} restored from cache`);
                 await this.addWarnings(compilation, cachedOutput.warnings);
                 compilation.updateAsset(name, cachedOutput.source, (assetInfo) => ({
                   ...assetInfo,
@@ -82,12 +86,15 @@ export class CssOptimizerPlugin {
             const { source, map: inputMap } = styleAssetSource.sourceAndMap();
             const input = typeof source === 'string' ? source : source.toString();
 
+            const optimizeAssetLabel = `optimize asset: ${asset.name}`;
+            logger.time(optimizeAssetLabel);
             const { code, warnings, map } = await this.optimize(
               input,
               asset.name,
               inputMap,
               this.targets,
             );
+            logger.timeEnd(optimizeAssetLabel);
 
             await this.addWarnings(compilation, warnings);
 
@@ -104,6 +111,7 @@ export class CssOptimizerPlugin {
               warnings,
             });
           }
+          logger.timeEnd('optimize css assets');
         },
       );
     });
diff --git a/packages/angular_devkit/build_angular/src/webpack/plugins/javascript-optimizer-plugin.ts b/packages/angular_devkit/build_angular/src/webpack/plugins/javascript-optimizer-plugin.ts
@@ -90,12 +90,15 @@ export class JavaScriptOptimizerPlugin {
     const { OriginalSource, SourceMapSource } = compiler.webpack.sources;
 
     compiler.hooks.compilation.tap(PLUGIN_NAME, (compilation) => {
+      const logger = compilation.getLogger('build-angular.JavaScriptOptimizerPlugin');
+
       compilation.hooks.processAssets.tapPromise(
         {
           name: PLUGIN_NAME,
           stage: compiler.webpack.Compilation.PROCESS_ASSETS_STAGE_OPTIMIZE_SIZE,
         },
         async (compilationAssets) => {
+          logger.time('optimize js assets');
           const scriptsToOptimize = [];
           const cache =
             compilation.options.cache && compilation.getCache('JavaScriptOptimizerPlugin');
@@ -123,6 +126,7 @@ export class JavaScriptOptimizerPlugin {
               >();
 
               if (cachedOutput) {
+                logger.debug(`${name} restored from cache`);
                 compilation.updateAsset(name, cachedOutput.source, (assetInfo) => ({
                   ...assetInfo,
                   minimized: true,
@@ -195,6 +199,8 @@ export class JavaScriptOptimizerPlugin {
           try {
             const tasks = [];
             for (const { name, code, map, cacheItem } of scriptsToOptimize) {
+              logger.time(`optimize asset: ${name}`);
+
               tasks.push(
                 workerPool
                   .run({
@@ -215,6 +221,8 @@ export class JavaScriptOptimizerPlugin {
                         minimized: true,
                       }));
 
+                      logger.timeEnd(`optimize asset: ${name}`);
+
                       return cacheItem?.storePromise({
                         source: optimizedAsset,
                       });
@@ -233,6 +241,8 @@ export class JavaScriptOptimizerPlugin {
           } finally {
             void workerPool.destroy();
           }
+
+          logger.timeEnd('optimize js assets');
         },
       );
     });
