chore(cli): log SDK calls when using -vvv

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

@@ -126,7 +126,7 @@ export class SdkProvider {
 
     const region = await AwsCliCompatible.region(options.profile);
     const requestHandler = AwsCliCompatible.requestHandlerBuilder(options.httpOptions);
-    return new SdkProvider(credentialProvider, region, requestHandler);
+    return new SdkProvider(credentialProvider, region, requestHandler, options.logger);
   }
 
   private readonly plugins = new CredentialPlugins();
@@ -138,6 +138,7 @@ export class SdkProvider {
      */
     public readonly defaultRegion: string,
     private readonly requestHandler: NodeHttpHandlerOptions = {},
+    private readonly logger?: Logger,
   ) {}
 
   /**
@@ -169,7 +170,7 @@ export class SdkProvider {
 
       // Our current credentials must be valid and not expired. Confirm that before we get into doing
       // actual CloudFormation calls, which might take a long time to hang.
-      const sdk = new SDK(baseCreds.credentials, env.region, this.requestHandler);
+      const sdk = new SDK(baseCreds.credentials, env.region, this.requestHandler, this.logger);
       await sdk.validateCredentials();
       return { sdk, didAssumeRole: false };
     }
@@ -201,7 +202,7 @@ export class SdkProvider {
           `${fmtObtainedCredentials(baseCreds)} could not be used to assume '${options.assumeRoleArn}', but are for the right account. Proceeding anyway.`,
         );
         return {
-          sdk: new SDK(baseCreds.credentials, env.region, this.requestHandler),
+          sdk: new SDK(baseCreds.credentials, env.region, this.requestHandler, this.logger),
           didAssumeRole: false,
         };
       }
@@ -221,7 +222,7 @@ export class SdkProvider {
     if (baseCreds.source === 'none') {
       return undefined;
     }
-    return (await new SDK(baseCreds.credentials, env.region, this.requestHandler).currentAccount()).partition;
+    return (await new SDK(baseCreds.credentials, env.region, this.requestHandler, this.logger).currentAccount()).partition;
   }
 
   /**
@@ -273,7 +274,7 @@ export class SdkProvider {
           throw new Error('Unable to resolve AWS credentials (setup with "aws configure")');
         }
 
-        return await new SDK(credentials, this.defaultRegion, this.requestHandler).currentAccount();
+        return await new SDK(credentials, this.defaultRegion, this.requestHandler, this.logger).currentAccount();
       } catch (e: any) {
         // Treat 'ExpiredToken' specially. This is a common situation that people may find themselves in, and
         // they are complaining about if we fail 'cdk synth' on them. We loudly complain in order to show that
@@ -376,10 +377,12 @@ export class SdkProvider {
         clientConfig: {
           region,
           requestHandler: this.requestHandler,
+          customUserAgent: 'aws-cdk',
+          logger: this.logger,
         },
       })();
 
-      return new SDK(credentials, region, this.requestHandler);
+      return new SDK(credentials, region, this.requestHandler, this.logger);
     } catch (err: any) {
       if (err.name === 'ExpiredToken') {
         throw err;

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

@@ -1,3 +1,4 @@
+import { inspect } from 'util';
 import {
   AppSyncClient,
   FunctionConfiguration,
@@ -318,7 +319,7 @@ import { AccountAccessKeyCache } from './account-cache';
 import { cached } from './cached';
 import { Account } from './sdk-provider';
 import { defaultCliUserAgent } from './user-agent';
-import { debug } from '../../logging';
+import { debug, trace } from '../../logging';
 import { traceMethods } from '../../util/tracing';
 
 export interface S3ClientOptions {
@@ -545,13 +546,15 @@ export class SDK {
     private readonly _credentials: AwsCredentialIdentity,
     region: string,
     requestHandler: NodeHttpHandlerOptions,
+    logger?: Logger,
   ) {
     this.config = {
       region,
       credentials: _credentials,
       requestHandler,
       retryStrategy: new ConfiguredRetryStrategy(7, (attempt) => 300 * (2 ** attempt)),
       customUserAgent: defaultCliUserAgent(),
+      logger,
     };
     this.currentRegion = region;
   }
@@ -981,3 +984,90 @@ export class SDK {
 }
 
 const CURRENT_ACCOUNT_KEY = Symbol('current_account_key');
+
+export class SdkToCliLogger implements Logger {
+  public trace(...content: any[]) {
+    // This is too much detail for our logs
+    // trace('[SDK trace] %s', this.fmtContent(content));
+    Array.isArray(content);
+  }
+
+  public debug(...content: any[]) {
+    // This is too much detail for our logs
+    // trace('[SDK debug] %s', this.fmtContent(content));
+    Array.isArray(content);
+  }
+
+  /**
+   * Info is called mostly (exclusively?) for successful API calls
+   *
+   * Payload:
+   *
+   * (Note the input contains entire CFN templates, for example)
+   *
+   * ```
+   * {
+   *   clientName: 'S3Client',
+   *   commandName: 'GetBucketLocationCommand',
+   *   input: {
+   *     Bucket: '.....',
+   *     ExpectedBucketOwner: undefined
+   *   },
+   *   output: { LocationConstraint: 'eu-central-1' },
+   *   metadata: {
+   *     httpStatusCode: 200,
+   *     requestId: '....',
+   *     extendedRequestId: '...',
+   *     cfId: undefined,
+   *     attempts: 1,
+   *     totalRetryDelay: 0
+   *   }
+   * }
+   * ```
+   */
+  public info(...content: any[]) {
+    // This is called
+    trace('[SDK info] %s', this.fmtContent(content));
+  }
+
+  public warn(...content: any[]) {
+    trace('[SDK warn] %s', this.fmtContent(content));
+  }
+
+  /**
+   * Error is called mostly (exclusively?) for failing API calls
+   *
+   * Payload (input would be the entire API call arguments).
+   *
+   * ```
+   * {
+   *   clientName: 'STSClient',
+   *   commandName: 'GetCallerIdentityCommand',
+   *   input: {},
+   *   error: AggregateError [ECONNREFUSED]:
+   *       at internalConnectMultiple (node:net:1121:18)
+   *       at afterConnectMultiple (node:net:1688:7) {
+   *     code: 'ECONNREFUSED',
+   *     '$metadata': { attempts: 3, totalRetryDelay: 600 },
+   *     [errors]: [ [Error], [Error] ]
+   *   },
+   *   metadata: { attempts: 3, totalRetryDelay: 600 }
+   * }
+   * ```
+   */
+  public error(...content: any[]) {
+    trace('[SDK error] %s', this.fmtContent(content));
+  }
+
+  /**
+   * This can be anything.
+   *
+   * For debug, it seems to be mostly strings.
+   * For info, it seems to be objects.
+   *
+   * Stringify and join without separator.
+   */
+  private fmtContent(content: any[]) {
+    return content.map((x) => typeof x === 'string' ? x : inspect(x)).join('');
+  }
+}

packages/aws-cdk/lib/cli.ts

@@ -8,7 +8,7 @@ import { ILock } from './api/util/rwlock';
 import { parseCommandLineArguments } from './parse-command-line-arguments';
 import { checkForPlatformWarnings } from './platform-warnings';
 import { enableTracing } from './util/tracing';
-import { SdkProvider } from '../lib/api/aws-auth';
+import { SdkProvider, SdkToCliLogger } from '../lib/api/aws-auth';
 import { BootstrapSource, Bootstrapper } from '../lib/api/bootstrap';
 import { StackSelector } from '../lib/api/cxapp/cloud-assembly';
 import { CloudExecutable, Synthesizer } from '../lib/api/cxapp/cloud-executable';
@@ -89,6 +89,7 @@ export async function exec(args: string[], synthesizer?: Synthesizer): Promise<n
       proxyAddress: argv.proxy,
       caBundlePath: argv['ca-bundle-path'],
     },
+    logger: new SdkToCliLogger(),
   });
 
   let outDirLock: ILock | undefined;

packages/aws-cdk/lib/util/directories.ts

@@ -17,7 +17,12 @@
   const tmpDir = fs.realpathSync(os.tmpdir());
   let home;
   try {
-    home = path.join((os.userInfo().homedir ?? os.homedir()).trim(), '.cdk');
+    let userInfoHome: string | undefined = os.userInfo().homedir;
+    // Node returns this if the user doesn't have a home directory
+    if (userInfoHome == '/var/empty') {
+      userInfoHome = undefined;
+    }
+    home = path.join((userInfoHome ?? os.homedir()).trim(), '.cdk');
   } catch {}
   return process.env.CDK_HOME
     ? path.resolve(process.env.CDK_HOME)

packages/aws-cdk/lib/util/npm.ts

@@ -6,7 +6,7 @@ import { debug } from '../../lib/logging';
 const exec = promisify(_exec);
 
 export async function getLatestVersionFromNpm(): Promise<string> {
-  const { stdout, stderr } = await exec('npm view aws-cdk version');
+  const { stdout, stderr } = await exec('npm view aws-cdk version', { timeout: 3000 });
   if (stderr && stderr.trim().length > 0) {
     debug(`The 'npm view' command generated an error stream with content [${stderr.trim()}]`);
   }

packages/aws-cdk/test/trace-fs.ts

@@ -0,0 +1,14 @@
+import * as fs from 'fs';
+
+// eslint-disable-next-line no-console
+void(fs);
+
+const originalFs = Object.assign({}, fs);
+
+module.exports = () => {
+  (fs as any).writeFile = (file: any, data: any, options: any, callback: any) => {
+    // eslint-disable-next-line no-console
+    console.error(file);
+    return originalFs.writeFile(file, data, options, callback);
+  };
+};