Merge branch 'main' into mrgrain/chore/toolkit/emit-more-times

packages/@aws-cdk/toolkit/lib/api/io/private/logger.ts

@@ -79,6 +79,28 @@ function stripEmojis(msg: string): string {
   return msg.replace(/\p{Emoji_Presentation}/gu, '');
 }
 
+/**
+ * An IoHost wrapper that trims whitespace at the beginning and end of messages.
+ * This is required, since after removing emojis and ANSI colors,
+ * we might end up with floating whitespace at either end.
+ */
+export function withTrimmedWhitespace(ioHost: IIoHost): IIoHost {
+  return {
+    notify: async <T>(msg: IoMessage<T>) => {
+      await ioHost.notify({
+        ...msg,
+        message: msg.message.trim(),
+      });
+    },
+    requestResponse: async <T, U>(msg: IoRequest<T, U>) => {
+      return ioHost.requestResponse({
+        ...msg,
+        message: msg.message.trim(),
+      });
+    },
+  };
+}
+
 // @todo these cannot be awaited WTF
 export function asSdkLogger(ioHost: IIoHost, action: ToolkitAction): Logger {
   return new class implements Logger {

packages/@aws-cdk/toolkit/lib/toolkit/toolkit.ts

@@ -19,7 +19,7 @@ import { CachedCloudAssemblySource, IdentityCloudAssemblySource, StackAssembly,
 import { ALL_STACKS, CloudAssemblySourceBuilder } from '../api/cloud-assembly/private';
 import { ToolkitError } from '../api/errors';
 import { IIoHost, IoMessageCode, IoMessageLevel } from '../api/io';
-import { asSdkLogger, withAction, Timer, confirm, error, highlight, info, success, warn, ActionAwareIoHost, debug, result, withoutEmojis, withoutColor } from '../api/io/private';
+import { asSdkLogger, withAction, Timer, confirm, error, highlight, info, success, warn, ActionAwareIoHost, debug, result, withoutEmojis, withoutColor, withTrimmedWhitespace } from '../api/io/private';
 
 /**
  * The current action being performed by the CLI. 'none' represents the absence of an action.
@@ -115,7 +115,9 @@ export class Toolkit extends CloudAssemblySourceBuilder implements AsyncDisposab
     if (props.color === false) {
       ioHost = withoutColor(ioHost);
     }
-    this.ioHost = ioHost;
+    // After removing emojis and color, we might end up with floating whitespace at either end of the message
+    // This also removes newlines that we currently emit for CLI backwards compatibility.
+    this.ioHost = withTrimmedWhitespace(ioHost);
   }
 
   public async dispose(): Promise<void> {

packages/@aws-cdk/toolkit/test/toolkit/toolkit.test.ts

@@ -9,42 +9,64 @@ import * as chalk from 'chalk';
 import { Toolkit } from '../../lib';
 import { TestIoHost } from '../_helpers';
 
-test('emojis can be stripped from message', async () => {
-  const ioHost = new TestIoHost();
-  const toolkit = new Toolkit({ ioHost, emojis: false });
-
-  await toolkit.ioHost.notify({
-    message: '💯Smile123😀',
-    action: 'deploy',
-    level: 'info',
-    code: 'CDK_TOOLKIT_I0000',
-    time: new Date(),
+describe('message formatting', () => {
+  test('emojis can be stripped from message', async () => {
+    const ioHost = new TestIoHost();
+    const toolkit = new Toolkit({ ioHost, emojis: false });
+
+    await toolkit.ioHost.notify({
+      message: '💯Smile123😀',
+      action: 'deploy',
+      level: 'info',
+      code: 'CDK_TOOLKIT_I0000',
+      time: new Date(),
+    });
+
+    expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
+      action: 'deploy',
+      level: 'info',
+      code: 'CDK_TOOLKIT_I0000',
+      message: 'Smile123',
+    }));
   });
 
-  expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
-    action: 'deploy',
-    level: 'info',
-    code: 'CDK_TOOLKIT_I0000',
-    message: 'Smile123',
-  }));
-});
+  test('color can be stripped from message', async () => {
+    const ioHost = new TestIoHost();
+    const toolkit = new Toolkit({ ioHost, color: false });
 
-test('color can be stripped from message', async () => {
-  const ioHost = new TestIoHost();
-  const toolkit = new Toolkit({ ioHost, color: false });
+    await toolkit.ioHost.notify({
+      message: chalk.red('RED') + chalk.bold('BOLD') + chalk.blue('BLUE'),
+      action: 'deploy',
+      level: 'info',
+      code: 'CDK_TOOLKIT_I0000',
+      time: new Date(),
+    });
 
-  await toolkit.ioHost.notify({
-    message: chalk.red('RED') + chalk.bold('BOLD') + chalk.blue('BLUE'),
-    action: 'deploy',
-    level: 'info',
-    code: 'CDK_TOOLKIT_I0000',
-    time: new Date(),
+    expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
+      action: 'deploy',
+      level: 'info',
+      code: 'CDK_TOOLKIT_I0000',
+      message: 'REDBOLDBLUE',
+    }));
   });
 
-  expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
-    action: 'deploy',
-    level: 'info',
-    code: 'CDK_TOOLKIT_I0000',
-    message: 'REDBOLDBLUE',
-  }));
+  test('whitespace is always trimmed from a message', async () => {
+    const ioHost = new TestIoHost();
+    const toolkit = new Toolkit({ ioHost, color: false });
+
+    await toolkit.ioHost.notify({
+      message: '   test message\n\n',
+      action: 'deploy',
+      level: 'info',
+      code: 'CDK_TOOLKIT_I0000',
+      time: new Date(),
+    });
+
+    expect(ioHost.notifySpy).toHaveBeenCalledWith(expect.objectContaining({
+      action: 'deploy',
+      level: 'info',
+      code: 'CDK_TOOLKIT_I0000',
+      message: 'test message',
+    }));
+  });
 });

packages/aws-cdk-lib/aws-ec2/lib/client-vpn-endpoint.ts

@@ -265,7 +265,7 @@ export interface ClientVpnEndpointAttributes {
 }
 
 /**
- * A client VPN connnection
+ * A client VPN connection
  */
 export class ClientVpnEndpoint extends Resource implements IClientVpnEndpoint {
   /**

packages/aws-cdk/lib/api/aws-auth/sdk-logger.ts

@@ -1,17 +1,33 @@
-import { inspect } from 'util';
+import { inspect, format } from 'util';
 import { Logger } from '@smithy/types';
-import { trace } from '../../logging';
 import { replacerBufferWithInfo } from '../../serialize';
+import type { IIoHost } from '../../toolkit/cli-io-host';
 
 export class SdkToCliLogger implements Logger {
+  private readonly ioHost: IIoHost;
+
+  public constructor(ioHost: IIoHost) {
+    this.ioHost = ioHost;
+  }
+
+  private notify(level: 'debug' | 'info' | 'warn' | 'error', ...content: any[]) {
+    void this.ioHost.notify({
+      time: new Date(),
+      level,
+      action: 'none' as any,
+      code: 'CDK_SDK_I0000',
+      message: format('[SDK %s] %s', level, formatSdkLoggerContent(content)),
+    });
+  }
+
   public trace(..._content: any[]) {
     // This is too much detail for our logs
-    // trace('[SDK trace] %s', fmtContent(content));
+    // this.notify('trace', ...content);
   }
 
   public debug(..._content: any[]) {
     // This is too much detail for our logs
-    // trace('[SDK debug] %s', fmtContent(content));
+    // this.notify('debug', ...content);
   }
 
   /**
@@ -42,11 +58,11 @@ export class SdkToCliLogger implements Logger {
    * ```
    */
   public info(...content: any[]) {
-    trace('[sdk info] %s', formatSdkLoggerContent(content));
+    this.notify('info', ...content);
   }
 
   public warn(...content: any[]) {
-    trace('[sdk warn] %s', formatSdkLoggerContent(content));
+    this.notify('warn', ...content);
   }
 
   /**
@@ -71,7 +87,7 @@ export class SdkToCliLogger implements Logger {
    * ```
    */
   public error(...content: any[]) {
-    trace('[sdk error] %s', formatSdkLoggerContent(content));
+    this.notify('info', ...content);
   }
 }
 

packages/aws-cdk/lib/api/aws-auth/sdk-provider.ts

@@ -10,10 +10,10 @@ import { cached } from './cached';
 import { CredentialPlugins } from './credential-plugins';
 import { makeCachingProvider } from './provider-caching';
 import { SDK } from './sdk';
+import { callTrace, traceMemberMethods } from './tracing';
 import { debug, warning } from '../../logging';
 import { AuthenticationError } from '../../toolkit/error';
 import { formatErrorMessage } from '../../util/error';
-import { traceMethods } from '../../util/tracing';
 import { Mode } from '../plugin/mode';
 
 export type AssumeRoleAdditionalOptions = Partial<Omit<AssumeRoleCommandInput, 'ExternalId' | 'RoleArn'>>;
@@ -111,7 +111,7 @@ export interface SdkForEnvironment {
  *     - Seeded terminal with `ReadOnly` credentials in order to do `cdk diff`--the `ReadOnly`
  *       role doesn't have `sts:AssumeRole` and will fail for no real good reason.
  */
-@traceMethods
+@traceMemberMethods
 export class SdkProvider {
   /**
    * Create a new SdkProvider which gets its defaults in a way that behaves like the AWS CLI does
@@ -120,6 +120,7 @@ export class SdkProvider {
    * class `AwsCliCompatible` for the details.
    */
   public static async withAwsCliCompatibleDefaults(options: SdkProviderOptions = {}) {
+    callTrace(SdkProvider.withAwsCliCompatibleDefaults.name, SdkProvider.constructor.name, options.logger);
     const credentialProvider = await AwsCliCompatible.credentialChainBuilder({
       profile: options.profile,
       httpOptions: options.httpOptions,

packages/aws-cdk/lib/api/aws-auth/sdk.ts

@@ -317,11 +317,11 @@ import { WaiterResult } from '@smithy/util-waiter';
 import { AccountAccessKeyCache } from './account-cache';
 import { cachedAsync } from './cached';
 import { Account } from './sdk-provider';
+import { traceMemberMethods } from './tracing';
 import { defaultCliUserAgent } from './user-agent';
 import { debug } from '../../logging';
 import { AuthenticationError } from '../../toolkit/error';
 import { formatErrorMessage } from '../../util/error';
-import { traceMethods } from '../../util/tracing';
 
 export interface S3ClientOptions {
   /**
@@ -521,14 +521,16 @@ export interface IStepFunctionsClient {
 /**
  * Base functionality of SDK without credential fetching
  */
-@traceMethods
+@traceMemberMethods
 export class SDK {
   private static readonly accountCache = new AccountAccessKeyCache();
 
   public readonly currentRegion: string;
 
   public readonly config: ConfigurationOptions;
 
+  protected readonly logger?: Logger;
+
   /**
    * STS is used to check credential validity, don't do too many retries.
    */
@@ -557,6 +559,7 @@ export class SDK {
       customUserAgent: defaultCliUserAgent(),
       logger,
     };
+    this.logger = logger;
     this.currentRegion = region;
   }
 

packages/aws-cdk/lib/api/aws-auth/tracing.ts

@@ -0,0 +1,59 @@
+import type { Logger } from '@smithy/types';
+
+let ENABLED = false;
+let INDENT = 0;
+
+export function setSdkTracing(enabled: boolean) {
+  ENABLED = enabled;
+}
+
+/**
+ * Method decorator to trace a single static or member method, any time it's called
+ */
+export function callTrace(fn: string, className?: string, logger?: Logger) {
+  if (!ENABLED || !logger) {
+    return;
+  }
+
+  logger.info(`[trace] ${' '.repeat(INDENT)}${className || '(anonymous)'}#${fn}()`);
+}
+
+/**
+ * Method decorator to trace a single member method any time it's called
+ */
+function traceCall(receiver: object, _propertyKey: string, descriptor: PropertyDescriptor, parentClassName?: string) {
+  const fn = descriptor.value;
+  const className = typeof receiver === 'function' ? receiver.name : parentClassName;
+
+  descriptor.value = function (...args: any[]) {
+    const logger = (this as any).logger;
+    if (!ENABLED || typeof logger?.info !== 'function') { return fn.apply(this, args); }
+
+    logger.info.apply(logger, [`[trace] ${' '.repeat(INDENT)}${className || this.constructor.name || '(anonymous)'}#${fn.name}()`]);
+    INDENT += 2;
+
+    const ret = fn.apply(this, args);
+    if (ret instanceof Promise) {
+      return ret.finally(() => {
+        INDENT -= 2;
+      });
+    } else {
+      INDENT -= 2;
+      return ret;
+    }
+  };
+  return descriptor;
+}
+
+/**
+ * Class decorator, enable tracing for all member methods on this class
+ * @deprecated this doesn't work well with localized logging instances, don't use
+ */
+export function traceMemberMethods(constructor: Function) {
+  // Instance members
+  for (const [name, descriptor] of Object.entries(Object.getOwnPropertyDescriptors(constructor.prototype))) {
+    if (typeof descriptor.value !== 'function') { continue; }
+    const newDescriptor = traceCall(constructor.prototype, name, descriptor, constructor.name) ?? descriptor;
+    Object.defineProperty(constructor.prototype, name, newDescriptor);
+  }
+}

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

@@ -8,6 +8,7 @@ import { checkForPlatformWarnings } from './platform-warnings';
 import * as version from './version';
 import { SdkProvider } from '../api/aws-auth';
 import { SdkToCliLogger } from '../api/aws-auth/sdk-logger';
+import { setSdkTracing } from '../api/aws-auth/tracing';
 import { BootstrapSource, Bootstrapper } from '../api/bootstrap';
 import { StackSelector } from '../api/cxapp/cloud-assembly';
 import { CloudExecutable, Synthesizer } from '../api/cxapp/cloud-executable';
@@ -28,7 +29,6 @@ import { Notices } from '../notices';
 import { Command, Configuration } from './user-configuration';
 import { IoMessageLevel, CliIoHost } from '../toolkit/cli-io-host';
 import { ToolkitError } from '../toolkit/error';
-import { enableTracing } from '../util/tracing';
 
 /* eslint-disable max-len */
 /* eslint-disable @typescript-eslint/no-shadow */ // yargs
@@ -66,7 +66,10 @@ export async function exec(args: string[], synthesizer?: Synthesizer): Promise<n
 
   // Debug should always imply tracing
   if (argv.debug || argv.verbose > 2) {
-    enableTracing(true);
+    setSdkTracing(true);
+  } else {
+    // cli-lib-alpha needs to explicitly set in case it was enabled before
+    setSdkTracing(false);
   }
 
   try {
@@ -104,7 +107,7 @@ export async function exec(args: string[], synthesizer?: Synthesizer): Promise<n
       proxyAddress: argv.proxy,
       caBundlePath: argv['ca-bundle-path'],
     },
-    logger: new SdkToCliLogger(),
+    logger: new SdkToCliLogger(ioHost),
   });
 
   let outDirLock: ILock | undefined;

packages/aws-cdk/lib/legacy-exports-source.ts

@@ -19,7 +19,7 @@ export { execProgram } from './api/cxapp/exec';
 export { RequireApproval } from './diff';
 export { leftPad } from './api/util/string-manipulation';
 export { formatAsBanner } from './cli/util/console-formatters';
-export { enableTracing } from './util/tracing';
+export { setSdkTracing as enableTracing } from './api/aws-auth/tracing';
 export { aliases, command, describe } from './commands/docs';
 export { lowerCaseFirstCharacter } from './api/hotswap/common';
 export { deepMerge } from './util/objects';