fix(cli): hangs on retrieving notices (#19967)

In an environment where DNS resolution works but network packets may be
dropped, the CLI can hang for up to 15 minutes trying to refresh
notices. We tried to set a timeout of 3 seconds on this, but did it in a
way that didn't work.

Turns out that the `request.on('timeout')` event in NodeJS doesn't actually stop
the request: it just notifies the listener that it's been a long time
since we saw network bytes, leaving the listener to do with that
what they want (potentially show a dialog box to a waiting user or
whatever). In our case, we had to do an additional `request.destroy()`
to actually stop the request.

Without doing this, the Promise would resolve correctly and the CLI
would continue, but the actual HTTP request would still be going on
in the background, preventing Node from shutting down.

This PR also changes the behavior of reporting a download failure: it
used to be that we would successfully resolve to a `[]` response if
the HTTP request failed (which would then be cached). Instead, after
this change we reject the Promise if anything goes wrong, so that the
next invocation will try again.

Fixes #19542.


----

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

Author: rix0rrr

packages/aws-cdk/lib/cli.ts

@@ -282,8 +282,7 @@ async function initCommandLine() {
 
   if (shouldDisplayNotices()) {
     void refreshNotices()
-      .then(_ => debug('Notices refreshed'))
-      .catch(e => debug(`Notices refresh failed: ${e}`));
+      .catch(e => debug(`Could not refresh notices: ${e}`));
   }
 
   const sdkProvider = await SdkProvider.withAwsCliCompatibleDefaults({

packages/aws-cdk/lib/notices.ts

@@ -107,9 +107,7 @@ export interface NoticeDataSource {
 export class WebsiteNoticeDataSource implements NoticeDataSource {
   fetch(): Promise<Notice[]> {
     const timeout = 3000;
-
-    return new Promise((resolve) => {
-      setTimeout(() => resolve([]), timeout);
+    return new Promise((resolve, reject) => {
       try {
         const req = https.get('https://cli.cdk.dev-tools.aws.dev/notices.json',
           { timeout },
@@ -123,29 +121,39 @@ export class WebsiteNoticeDataSource implements NoticeDataSource {
               res.on('end', () => {
                 try {
                   const data = JSON.parse(rawData).notices as Notice[];
+                  if (!data) {
+                    throw new Error("'notices' key is missing");
+                  }
+                  debug('Notices refreshed');
                   resolve(data ?? []);
                 } catch (e) {
-                  debug(`Failed to parse notices: ${e}`);
-                  resolve([]);
+                  reject(new Error(`Failed to parse notices: ${e.message}`));
                 }
               });
               res.on('error', e => {
-                debug(`Failed to fetch notices: ${e}`);
-                resolve([]);
+                reject(new Error(`Failed to fetch notices: ${e.message}`));
               });
             } else {
-              debug(`Failed to fetch notices. Status code: ${res.statusCode}`);
-              resolve([]);
+              reject(new Error(`Failed to fetch notices. Status code: ${res.statusCode}`));
             }
           });
-        req.on('error', e => {
-          debug(`Error on request: ${e}`);
-          resolve([]);
+        req.on('error', reject);
+        req.on('timeout', () => {
+          // The 'timeout' event doesn't stop anything by itself, it just
+          // notifies that it has been long time since we saw bytes.
+          // In our case, we want to give up.
+          req.destroy(new Error('Request timed out'));
         });
-        req.on('timeout', _ => resolve([]));
+
+        // It's not like I don't *trust* the 'timeout' event... but I don't trust it.
+        // Add a backup timer that will destroy the request after all.
+        // (This is at least necessary to make the tests pass, but that's probably because of 'nock'.
+        // It's not clear whether users will hit this).
+        setTimeout(() => {
+          req.destroy(new Error('Request timed out. You should never see this message; if you do, please let us know at https://github.com/aws/aws-cdk/issues'));
+        }, timeout + 200);
       } catch (e) {
-        debug(`HTTPS 'get' call threw an error: ${e}`);
-        resolve([]);
+        reject(new Error(`HTTPS 'get' call threw an error: ${e.message}`));
       }
     });
   }
@@ -156,7 +164,8 @@ interface CachedNotices {
   notices: Notice[],
 }
 
-const TIME_TO_LIVE = 60 * 60 * 1000; // 1 hour
+const TIME_TO_LIVE_SUCCESS = 60 * 60 * 1000; // 1 hour
+const TIME_TO_LIVE_ERROR = 1 * 60 * 1000; // 1 minute
 
 export class CachedDataSource implements NoticeDataSource {
   constructor(
@@ -171,17 +180,30 @@ export class CachedDataSource implements NoticeDataSource {
     const expiration = cachedData.expiration ?? 0;
 
     if (Date.now() > expiration || this.skipCache) {
-      const freshData = {
-        expiration: Date.now() + TIME_TO_LIVE,
-        notices: await this.dataSource.fetch(),
-      };
+      const freshData = await this.fetchInner();
       await this.save(freshData);
       return freshData.notices;
     } else {
+      debug(`Reading cached notices from ${this.fileName}`);
       return data;
     }
   }
 
+  private async fetchInner(): Promise<CachedNotices> {
+    try {
+      return {
+        expiration: Date.now() + TIME_TO_LIVE_SUCCESS,
+        notices: await this.dataSource.fetch(),
+      };
+    } catch (e) {
+      debug(`Could not refresh notices: ${e}`);
+      return {
+        expiration: Date.now() + TIME_TO_LIVE_ERROR,
+        notices: [],
+      };
+    }
+  }
+
   private async load(): Promise<CachedNotices> {
     const defaultValue = {
       expiration: 0,

packages/aws-cdk/test/notices.test.ts

@@ -191,60 +191,60 @@ describe('cli notices', () => {
       expect(result).toEqual([BASIC_NOTICE, MULTIPLE_AFFECTED_VERSIONS_NOTICE]);
     });
 
-    test('returns empty array when the server returns an unexpected status code', async () => {
-      const result = await mockCall(500, {
+    test('returns appropriate error when the server returns an unexpected status code', async () => {
+      const result = mockCall(500, {
         notices: [BASIC_NOTICE, MULTIPLE_AFFECTED_VERSIONS_NOTICE],
       });
 
-      expect(result).toEqual([]);
+      await expect(result).rejects.toThrow(/500/);
     });
 
-    test('returns empty array when the server returns an unexpected structure', async () => {
-      const result = await mockCall(200, {
+    test('returns appropriate error when the server returns an unexpected structure', async () => {
+      const result = mockCall(200, {
         foo: [BASIC_NOTICE, MULTIPLE_AFFECTED_VERSIONS_NOTICE],
       });
 
-      expect(result).toEqual([]);
+      await expect(result).rejects.toThrow(/key is missing/);
     });
 
-    test('returns empty array when the server returns invalid json', async () => {
-      const result = await mockCall(200, '-09aiskjkj838');
+    test('returns appropriate error when the server returns invalid json', async () => {
+      const result = mockCall(200, '-09aiskjkj838');
 
-      expect(result).toEqual([]);
+      await expect(result).rejects.toThrow(/Failed to parse/);
     });
 
-    test('returns empty array when HTTPS call throws', async () => {
+    test('returns appropriate error when HTTPS call throws', async () => {
       const mockGet = jest.spyOn(https, 'get')
         .mockImplementation(() => { throw new Error('No connection'); });
 
-      const result = await dataSource.fetch();
+      const result = dataSource.fetch();
 
-      expect(result).toEqual([]);
+      await expect(result).rejects.toThrow(/No connection/);
 
       mockGet.mockRestore();
     });
 
-    test('returns empty array when the request has an error', async () => {
+    test('returns appropriate error when the request has an error', async () => {
       nock('https://cli.cdk.dev-tools.aws.dev')
         .get('/notices.json')
         .replyWithError('DNS resolution failed');
 
-      const result = await dataSource.fetch();
+      const result = dataSource.fetch();
 
-      expect(result).toEqual([]);
+      await expect(result).rejects.toThrow(/DNS resolution failed/);
     });
 
-    test('returns empty array when the connection stays idle for  too long', async () => {
+    test('returns appropriate error when the connection stays idle for too long', async () => {
       nock('https://cli.cdk.dev-tools.aws.dev')
         .get('/notices.json')
         .delayConnection(3500)
         .reply(200, {
           notices: [BASIC_NOTICE],
         });
 
-      const result = await dataSource.fetch();
+      const result = dataSource.fetch();
 
-      expect(result).toEqual([]);
+      await expect(result).rejects.toThrow(/timed out/);
     });
 
     test('returns empty array when the request takes too long to finish', async () => {
@@ -255,9 +255,9 @@ describe('cli notices', () => {
           notices: [BASIC_NOTICE],
         });
 
-      const result = await dataSource.fetch();
+      const result = dataSource.fetch();
 
-      expect(result).toEqual([]);
+      await expect(result).rejects.toThrow(/timed out/);
     });
 
     function mockCall(statusCode: number, body: any): Promise<Notice[]> {
@@ -313,6 +313,10 @@ describe('cli notices', () => {
     test('retrieves data from the delegate when the file cannot be read', async () => {
       const debugSpy = jest.spyOn(logging, 'debug');
 
+      if (fs.existsSync('does-not-exist.json')) {
+        fs.unlinkSync('does-not-exist.json');
+      }
+
       const dataSource = dataSourceWithDelegateReturning(freshData, 'does-not-exist.json');
 
       const notices = await dataSource.fetch();
@@ -335,6 +339,20 @@ describe('cli notices', () => {
       expect(notices).toEqual(freshData);
     });
 
+    test('error in delegate gets turned into empty result by cached source', async () => {
+      // GIVEN
+      const delegate = {
+        fetch: jest.fn().mockRejectedValue(new Error('fetching failed')),
+      };
+      const dataSource = new CachedDataSource(fileName, delegate, true);
+
+      // WHEN
+      const notices = await dataSource.fetch();
+
+      // THEN
+      expect(notices).toEqual([]);
+    });
+
     function dataSourceWithDelegateReturning(notices: Notice[], file: string = fileName, ignoreCache: boolean = false) {
       const delegate = {
         fetch: jest.fn(),