[kbn/optimizer] log about high-level optimizer progress (#103354)

* [kbn/optimizer] log about high-level optimizer progress

* restore logOptimizerProgress helper to fix tests

* fix lint error

Co-authored-by: spalger <spalger@users.noreply.github.com>
Co-authored-by: Kibana Machine <42973632+kibanamachine@users.noreply.github.com>

packages/kbn-cli-dev-mode/src/optimizer.test.ts

@@ -18,9 +18,11 @@ import { Optimizer, Options } from './optimizer';
 
 jest.mock('@kbn/optimizer');
 const realOptimizer = jest.requireActual('@kbn/optimizer');
-const { runOptimizer, OptimizerConfig, logOptimizerState } = jest.requireMock('@kbn/optimizer');
+const { runOptimizer, OptimizerConfig, logOptimizerState, logOptimizerProgress } =
+  jest.requireMock('@kbn/optimizer');
 
 logOptimizerState.mockImplementation(realOptimizer.logOptimizerState);
+logOptimizerProgress.mockImplementation(realOptimizer.logOptimizerProgress);
 
 class MockOptimizerConfig {}
 

packages/kbn-cli-dev-mode/src/optimizer.ts

@@ -18,7 +18,13 @@ import {
 } from '@kbn/dev-utils';
 import * as Rx from 'rxjs';
 import { ignoreElements } from 'rxjs/operators';
-import { runOptimizer, OptimizerConfig, logOptimizerState, OptimizerUpdate } from '@kbn/optimizer';
+import {
+  runOptimizer,
+  OptimizerConfig,
+  logOptimizerState,
+  logOptimizerProgress,
+  OptimizerUpdate,
+} from '@kbn/optimizer';
 
 export interface Options {
   enabled: boolean;
@@ -111,6 +117,7 @@ export class Optimizer {
       subscriber.add(
         runOptimizer(config)
           .pipe(
+            logOptimizerProgress(log),
             logOptimizerState(log, config),
             tap(({ state }) => {
               this.phase$.next(state.phase);

packages/kbn-optimizer/src/cli.ts

@@ -13,6 +13,7 @@ import { lastValueFrom } from '@kbn/std';
 import { run, createFlagError, Flags } from '@kbn/dev-utils';
 
 import { logOptimizerState } from './log_optimizer_state';
+import { logOptimizerProgress } from './log_optimizer_progress';
 import { OptimizerConfig } from './optimizer';
 import { runOptimizer } from './run_optimizer';
 import { validateLimitsForAllBundles, updateBundleLimits } from './limits';
@@ -97,6 +98,11 @@ export function runKbnOptimizerCli(options: { defaultLimitsPath: string }) {
         throw createFlagError('expected --report-stats to have no value');
       }
 
+      const logProgress = flags.progress ?? false;
+      if (typeof logProgress !== 'boolean') {
+        throw createFlagError('expected --progress to have no value');
+      }
+
       const filter = typeof flags.filter === 'string' ? [flags.filter] : flags.filter;
       if (!Array.isArray(filter) || !filter.every((f) => typeof f === 'string')) {
         throw createFlagError('expected --filter to be one or more strings');
@@ -144,7 +150,11 @@ export function runKbnOptimizerCli(options: { defaultLimitsPath: string }) {
       const update$ = runOptimizer(config);
 
       await lastValueFrom(
-        update$.pipe(logOptimizerState(log, config), reportOptimizerTimings(log, config))
+        update$.pipe(
+          logProgress ? logOptimizerProgress(log) : (x) => x,
+          logOptimizerState(log, config),
+          reportOptimizerTimings(log, config)
+        )
       );
 
       if (updateLimits) {
@@ -169,6 +179,7 @@ export function runKbnOptimizerCli(options: { defaultLimitsPath: string }) {
           'inspect-workers',
           'validate-limits',
           'update-limits',
+          'progress',
         ],
         string: ['workers', 'scan-dir', 'filter', 'limits'],
         default: {
@@ -176,12 +187,14 @@ export function runKbnOptimizerCli(options: { defaultLimitsPath: string }) {
           examples: true,
           cache: true,
           'inspect-workers': true,
+          progress: true,
           filter: [],
           focus: [],
         },
         help: `
           --watch            run the optimizer in watch mode
           --workers          max number of workers to use
+          --no-progress      disable logging of progress information
           --oss              only build oss plugins
           --profile          profile the webpack builds and write stats.json files to build outputs
           --no-core          disable generating the core bundle

packages/kbn-optimizer/src/index.ts

@@ -9,6 +9,7 @@
 export { OptimizerConfig } from './optimizer';
 export * from './run_optimizer';
 export * from './log_optimizer_state';
+export * from './log_optimizer_progress';
 export * from './node';
 export * from './limits';
 export * from './cli';

packages/kbn-optimizer/src/log_optimizer_progress.ts

@@ -0,0 +1,62 @@
+/*
+ * Copyright Elasticsearch B.V. and/or licensed to Elasticsearch B.V. under one
+ * or more contributor license agreements. Licensed under the Elastic License
+ * 2.0 and the Server Side Public License, v 1; you may not use this file except
+ * in compliance with, at your election, the Elastic License 2.0 or the Server
+ * Side Public License, v 1.
+ */
+
+import { ToolingLog } from '@kbn/dev-utils';
+import * as Rx from 'rxjs';
+import { tap } from 'rxjs/operators';
+
+import { OptimizerUpdate } from './run_optimizer';
+
+const PROGRESS_REPORT_INTERVAL = 10_000;
+
+export function logOptimizerProgress(
+  log: ToolingLog
+): Rx.MonoTypeOperatorFunction<OptimizerUpdate> {
+  return (update$) =>
+    new Rx.Observable((subscriber) => {
+      const allBundleIds = new Set();
+      const completeBundles = new Set();
+      let loggedCompletion = new Set();
+
+      // catalog bundle ids and which have completed at least once, forward
+      // updates to next subscriber
+      subscriber.add(
+        update$
+          .pipe(
+            tap(({ state }) => {
+              for (const { bundleId, type } of state.compilerStates) {
+                allBundleIds.add(bundleId);
+                if (type !== 'running') {
+                  completeBundles.add(bundleId);
+                }
+              }
+            }),
+            tap(subscriber)
+          )
+          .subscribe()
+      );
+
+      // on interval check to see if at least 3 new bundles have completed at
+      // least one build and log about our progress if so
+      subscriber.add(
+        Rx.interval(PROGRESS_REPORT_INTERVAL).subscribe(
+          () => {
+            if (completeBundles.size - loggedCompletion.size < 3) {
+              return;
+            }
+
+            log.info(
+              `[${completeBundles.size}/${allBundleIds.size}] initial bundle builds complete`
+            );
+            loggedCompletion = new Set(completeBundles);
+          },
+          (error) => subscriber.error(error)
+        )
+      );
+    });
+}

packages/kbn-optimizer/src/log_optimizer_state.ts

@@ -82,14 +82,11 @@ export function logOptimizerState(log: ToolingLog, config: OptimizerConfig) {
             continue;
           }
 
+          bundleStates.set(id, type);
+
           if (type === 'running') {
             bundlesThatWereBuilt.add(id);
           }
-
-          bundleStates.set(id, type);
-          log.debug(
-            `[${id}] state = "${type}"${type !== 'running' ? ` after ${state.durSec} sec` : ''}`
-          );
         }
 
         if (state.phase === 'running' || state.phase === 'initializing') {