feat(integ-runner): add option to show deployment output (aws#21466)

Currently no further output is emitted from the workers which makes it difficult to diagnose any issues.
This change addresses the problem by turning the existing `verbose` flag into a count, that can indicate the requested level of debug output.

`-v` - the current level of verbosity
`-vv` - print the deployment output
`-vvv` - verbose deployment output
`-vvvv` - additional debug output from deployment

----

### All Submissions:

* [x] Have you followed the guidelines in our [Contributing guide?](https://github.com/aws/aws-cdk/blob/main/CONTRIBUTING.md)

### Adding new Unconventional Dependencies:

* [ ] This PR adds new unconventional dependencies following the process described [here](https://github.com/aws/aws-cdk/blob/main/CONTRIBUTING.md/#adding-new-unconventional-dependencies)

### New Features

* [ ] Have you added the new feature to an [integration test](https://github.com/aws/aws-cdk/blob/main/INTEGRATION_TESTS.md)?
	* [ ] Did you use `yarn integ` to deploy the infrastructure and generate the snapshot (i.e. `yarn integ` without `--dry-run`)?

*By submitting this pull request, I confirm that my contribution is made under the terms of the Apache-2.0 license*

packages/@aws-cdk/integ-runner/README.md

@@ -52,6 +52,7 @@ to be a self contained CDK app. The runner will execute the following for each f
   Destroy stacks after deploy (use `--no-clean` for debugging)
 - `--verbose` (default=`false`)
   verbose logging, including integration test metrics
+  (specify multiple times to increase verbosity)
 - `--parallel-regions` (default=`us-east-1`,`us-east-2`, `us-west-2`)
   List of regions to run tests in. If this is provided then all tests will
   be run in parallel across these regions

packages/@aws-cdk/integ-runner/lib/cli.ts

@@ -18,7 +18,7 @@ async function main() {
     .usage('Usage: integ-runner [TEST...]')
     .option('list', { type: 'boolean', default: false, desc: 'List tests instead of running them' })
     .option('clean', { type: 'boolean', default: true, desc: 'Skips stack clean up after test is completed (use --no-clean to negate)' })
-    .option('verbose', { type: 'boolean', default: false, alias: 'v', desc: 'Verbose logs and metrics on integration tests durations' })
+    .option('verbose', { type: 'boolean', default: false, alias: 'v', count: true, desc: 'Verbose logs and metrics on integration tests durations (specify multiple times to increase verbosity)' })
     .option('dry-run', { type: 'boolean', default: false, desc: 'do not actually deploy the stack. just update the snapshot (not recommended!)' })
     .option('update-on-failed', { type: 'boolean', default: false, desc: 'rerun integration tests and update snapshots for failed tests.' })
     .option('force', { type: 'boolean', default: false, desc: 'Rerun all integration tests even if tests are passing' })
@@ -75,7 +75,7 @@ async function main() {
     // failed snapshot tests
     failedSnapshots = await runSnapshotTests(pool, testsFromArgs, {
       retain: argv['inspect-failures'],
-      verbose: argv.verbose,
+      verbose: Boolean(argv.verbose),
     });
     for (const failure of failedSnapshots) {
       destructiveChanges.push(...failure.destructiveChanges ?? []);
@@ -97,7 +97,7 @@ async function main() {
         profiles,
         clean: argv.clean,
         dryRun: argv['dry-run'],
-        verbose: argv.verbose,
+        verbosity: argv.verbose,
         updateWorkflow: !argv['disable-update-workflow'],
       });
       testsSucceeded = success;
@@ -107,7 +107,7 @@ async function main() {
         logger.warning('Not cleaning up stacks since "--no-clean" was used');
       }
 
-      if (argv.verbose) {
+      if (Boolean(argv.verbose)) {
         printMetrics(metrics);
       }
 

packages/@aws-cdk/integ-runner/lib/runner/integ-test-runner.ts

@@ -48,6 +48,13 @@ export interface RunOptions {
    * @default true
    */
   readonly updateWorkflow?: boolean;
+
+  /**
+   * The level of verbosity for logging.
+   *
+   * @default 0
+   */
+  readonly verbosity?: number;
 }
 
 /**
@@ -148,13 +155,20 @@ export class IntegTestRunner extends IntegRunner {
     const clean = options.clean ?? true;
     const updateWorkflowEnabled = (options.updateWorkflow ?? true)
       && (actualTestCase.stackUpdateWorkflow ?? true);
+    const enableForVerbosityLevel = (needed = 1) => {
+      const verbosity = options.verbosity ?? 0;
+      return (verbosity >= needed) ? true : undefined;
+    };
+
     try {
       if (!options.dryRun && (actualTestCase.cdkCommandOptions?.deploy?.enabled ?? true)) {
         assertionResults = this.deploy(
           {
             ...this.defaultArgs,
             profile: this.profile,
             requireApproval: RequireApproval.NEVER,
+            verbose: enableForVerbosityLevel(3),
+            debug: enableForVerbosityLevel(4),
           },
           updateWorkflowEnabled,
           options.testCaseName,
@@ -189,6 +203,8 @@ export class IntegTestRunner extends IntegRunner {
             output: path.relative(this.directory, this.cdkOutDir),
             ...actualTestCase.cdkCommandOptions?.destroy?.args,
             context: this.getContext(actualTestCase.cdkCommandOptions?.destroy?.args?.context),
+            verbose: enableForVerbosityLevel(3),
+            debug: enableForVerbosityLevel(4),
           });
         }
       }

packages/@aws-cdk/integ-runner/lib/runner/runner-base.ts

@@ -48,6 +48,13 @@ export interface IntegRunnerOptions {
    * @default - CdkCliWrapper
    */
   readonly cdk?: ICdk;
+
+  /**
+   * Show output from running integration tests
+   *
+   * @default false
+   */
+  readonly showOutput?: boolean;
 }
 
 /**
@@ -137,6 +144,7 @@ export abstract class IntegRunner {
 
     this.cdk = options.cdk ?? new CdkCliWrapper({
       directory: this.directory,
+      showOutput: options.showOutput,
       env: {
         ...options.env,
       },

packages/@aws-cdk/integ-runner/lib/workers/common.ts

@@ -149,11 +149,12 @@ export interface IntegTestOptions {
   readonly dryRun?: boolean;
 
   /**
-   * Whether to enable verbose logging
+   * The level of verbosity for logging.
+   * Higher number means more output.
    *
-   * @default false
+   * @default 0
    */
-  readonly verbose?: boolean;
+  readonly verbosity?: number;
 
   /**
    * If this is set to true then the stack update workflow will be disabled

packages/@aws-cdk/integ-runner/lib/workers/extract/extract_worker.ts

@@ -14,6 +14,8 @@ import { IntegTestBatchRequest } from '../integ-test-worker';
  */
 export function integTestWorker(request: IntegTestBatchRequest): IntegTestWorkerConfig[] {
   const failures: IntegTestInfo[] = [];
+  const verbosity = request.verbosity ?? 0;
+
   for (const testInfo of request.tests) {
     const test = new IntegTest(testInfo); // Hydrate from data
     const start = Date.now();
@@ -25,6 +27,7 @@ export function integTestWorker(request: IntegTestBatchRequest): IntegTestWorker
         env: {
           AWS_REGION: request.region,
         },
+        showOutput: verbosity >= 2,
       }, testInfo.destructiveChanges);
 
       const tests = runner.actualTests();
@@ -39,6 +42,7 @@ export function integTestWorker(request: IntegTestBatchRequest): IntegTestWorker
             clean: request.clean,
             dryRun: request.dryRun,
             updateWorkflow: request.updateWorkflow,
+            verbosity,
           });
           if (results) {
             failures.push(testInfo);

packages/@aws-cdk/integ-runner/lib/workers/integ-test-worker.ts

@@ -133,7 +133,7 @@ export async function runIntegrationTestsInParallel(
         tests: [test],
         clean: options.clean,
         dryRun: options.dryRun,
-        verbose: options.verbose,
+        verbosity: options.verbosity,
         updateWorkflow: options.updateWorkflow,
       }], {
         on: printResults,

packages/@aws-cdk/integ-runner/test/runner/integ-test-runner.test.ts

@@ -496,4 +496,41 @@ describe('IntegTest runIntegTests', () => {
       ],
     ]);
   });
+
+
+  test.each`
+    verbosity | verbose      | debug
+    ${0}      | ${undefined} | ${undefined}
+    ${1}      | ${undefined} | ${undefined}
+    ${2}      | ${undefined} | ${undefined}
+    ${3}      | ${true}      | ${undefined}
+    ${4}      | ${true}      | ${true}
+`('with verbosity set to $verbosity', ({ verbosity, verbose, debug }) => {
+    // WHEN
+    const integTest = new IntegTestRunner({
+      cdk: cdkMock.cdk,
+      test: new IntegTest({
+        fileName: 'test/test-data/xxxxx.test-with-snapshot.js',
+        discoveryRoot: 'test/test-data',
+      }),
+    });
+    integTest.runIntegTestCase({
+      testCaseName: 'xxxxx.test-with-snapshot',
+      verbosity: verbosity,
+    });
+
+    // THEN
+    expect(deployMock).toHaveBeenCalledWith(expect.objectContaining({
+      verbose,
+      debug,
+    }));
+    expect(deployMock).toHaveBeenCalledWith(expect.objectContaining({
+      verbose,
+      debug,
+    }));
+    expect(destroyMock).toHaveBeenCalledWith(expect.objectContaining({
+      verbose,
+      debug,
+    }));
+  });
 });

packages/cdk-cli-wrapper/lib/cdk-wrapper.ts

@@ -61,7 +61,7 @@ export interface SynthFastOptions {
   readonly context?: Record<string, string>,
 
   /**
-   * Additiional environment variables to set in the
+   * Additional environment variables to set in the
    * execution environment
    *
    * @default - no additional env
@@ -94,20 +94,29 @@ export interface CdkCliWrapperOptions {
    * @default 'aws-cdk/bin/cdk'
    */
   readonly cdkExecutable?: string;
+
+  /**
+   * Show the output from running the CDK CLI
+   *
+   * @default false
+   */
+  readonly showOutput?: boolean;
 }
 
 /**
- * Provides a programattic interface for interacting with the CDK CLI by
+ * Provides a programmatic interface for interacting with the CDK CLI by
  * wrapping the CLI with exec
  */
 export class CdkCliWrapper implements ICdk {
   private readonly directory: string;
   private readonly env?: { [key: string]: string };
   private readonly cdk: string;
+  private readonly showOutput: boolean;
 
   constructor(options: CdkCliWrapperOptions) {
     this.directory = options.directory;
     this.env = options.env;
+    this.showOutput = options.showOutput ?? false;
     try {
       this.cdk = options.cdkExecutable ?? 'cdk';
     } catch (e) {
@@ -129,7 +138,7 @@ export class CdkCliWrapper implements ICdk {
 
     return exec([this.cdk, 'ls', ...listCommandArgs], {
       cwd: this.directory,
-      verbose: options.verbose,
+      verbose: this.showOutput,
       env: this.env,
     });
   }
@@ -157,7 +166,7 @@ export class CdkCliWrapper implements ICdk {
 
     exec([this.cdk, 'deploy', ...deployCommandArgs], {
       cwd: this.directory,
-      verbose: options.verbose,
+      verbose: this.showOutput,
       env: this.env,
     });
   }
@@ -174,7 +183,7 @@ export class CdkCliWrapper implements ICdk {
 
     exec([this.cdk, 'destroy', ...destroyCommandArgs], {
       cwd: this.directory,
-      verbose: options.verbose,
+      verbose: this.showOutput,
       env: this.env,
     });
   }
@@ -192,7 +201,7 @@ export class CdkCliWrapper implements ICdk {
 
     exec([this.cdk, 'synth', ...synthCommandArgs], {
       cwd: this.directory,
-      verbose: options.verbose,
+      verbose: this.showOutput,
       env: this.env,
     });
   }
@@ -206,6 +215,7 @@ export class CdkCliWrapper implements ICdk {
   public synthFast(options: SynthFastOptions): void {
     exec(options.execCmd, {
       cwd: this.directory,
+      verbose: this.showOutput,
       env: {
         CDK_CONTEXT_JSON: JSON.stringify(options.context),
         CDK_OUTDIR: options.output,

packages/cdk-cli-wrapper/test/cdk-wrapper.test.ts

@@ -126,7 +126,7 @@ test('deploy with all arguments', () => {
     ]),
     expect.objectContaining({
       env: expect.anything(),
-      stdio: ['ignore', 'pipe', 'inherit'],
+      stdio: ['ignore', 'pipe', 'pipe'],
       cwd: '/project',
     }),
   );
@@ -462,3 +462,25 @@ test('can synth fast', () => {
     }),
   );
 });
+
+test('can show output', () => {
+  // WHEN
+  const cdk = new CdkCliWrapper({
+    directory: '/project',
+    showOutput: true,
+  });
+  cdk.synthFast({
+    execCmd: ['node', 'bin/my-app.js'],
+  });
+
+  // THEN
+  expect(spawnSyncMock).toHaveBeenCalledWith(
+    'node',
+    ['bin/my-app.js'],
+    expect.objectContaining({
+      env: expect.anything(),
+      stdio: ['ignore', 'pipe', 'inherit'],
+      cwd: '/project',
+    }),
+  );
+});