fix: polling in proxy repository now stops correctly (#3268)

### What

This patches two very subtle bugs in the proxy repository that cause it
to never actually stop polling the db in the background

## Details - Issue 1

We've recently started to get the following output when running `yarn
test`:

` Attempted to log "Error: Unable to acquire a connection
at Object.queryBuilder
(/home/simon/dev/unleash/node_modules/knex/lib/knex-builder/make-knex.js:111:26)`
        
This seems to occur for every test suite after running the proxy tests
and the full stack trace doesn't point to anything related to the
running tests that produce this output. Running a `git bisect` points to
this commit:
6e44a65
being the culprit but I believe that this may have surfaced the bug
rather than causing it.

Layering in a few console logs and running Unleash, seems to point to
the proxy repository setting up data polling but never actually
terminating it when `stop` was called, which is inline with the output
here - effectively the tests were continuing to run the polling in the
background after the suite had exited and jest freaks out that an async
task is running when it shouldn't be. This is easy to reproduce once the
console logs are in place in the `dataPolling` function, by running
Unleash - creating and deleting a front end token never terminates the
poll cycle.

I believe the cause here is some subtlety around using async functions
with timers - stop was being called, which results in the timer being
cleared but a scheduled async call was already on the stack, causing the
recursive call to resolve after stop, resurrecting the timer and
reinitializing the poll cycle.

I've moved the terminating code into the async callback. Which seems to
solve the problem here.

## Details - Issue 2

Related to the first issue, when the proxy service stops the underlying
Unleash Client, it never actually calls destroy on the client, it only
removes it from its internal map. That in turn means that the Client
never calls stop on the injected repository, it only removes it from
memory. However, the scheduled task is `async` and `unref`, meaning it
continues to spin in the background until every other process also
exits. This is patched by simply calling destroy on the client when
cleaning up

## The Ugly

This is really hard to test effectively, mostly because this is an issue
caused by internals within NodeJS and async. I've added a test that
reads the output from the debug log (and also placed a debug log in the
termination code). This also requires the test code to wait until the
async task completes. This is horribly fragile so if someone has a
better idea on how to prove this I would be a very happy human.

The second ugly part is that this is a subtle issue in complex code that
really, really needs to work correctly. I'm nervous about making changes
here without lots of eyes on this

src/lib/proxy/proxy-repository.ts

@@ -42,7 +42,9 @@ export class ProxyRepository
 
     private interval: number;
 
-    private timer: NodeJS.Timer;
+    private timer: NodeJS.Timer | null;
+
+    private running: boolean;
 
     constructor(
         config: Config,
@@ -73,6 +75,7 @@ export class ProxyRepository
     }
 
     async start(): Promise<void> {
+        this.running = true;
         await this.dataPolling();
 
         // Reload cached token data whenever something relevant has changed.
@@ -85,11 +88,19 @@ export class ProxyRepository
 
     stop(): void {
         this.stores.eventStore.off(ANY_EVENT, this.onAnyEvent);
-        clearTimeout(this.timer);
+        this.running = false;
     }
 
     private async dataPolling() {
         this.timer = setTimeout(async () => {
+            if (!this.running) {
+                clearTimeout(this.timer!);
+                this.timer = null;
+                this.logger.debug(
+                    'Shutting down data polling for proxy repository',
+                );
+                return;
+            }
             await this.dataPolling();
         }, this.randomizeDelay(this.interval, this.interval * 2)).unref();
 

src/lib/services/proxy-service.ts

@@ -46,7 +46,7 @@ export class ProxyService {
 
     private cachedFrontendSettings?: FrontendSettings;
 
-    private timer: NodeJS.Timeout;
+    private timer: NodeJS.Timeout | null;
 
     constructor(config: Config, stores: Stores, services: Services) {
         this.config = config;
@@ -150,6 +150,7 @@ export class ProxyService {
     }
 
     deleteClientForProxyToken(secret: string): void {
+        this.clients.get(secret)?.destroy();
         this.clients.delete(secret);
     }
 
@@ -200,7 +201,9 @@ export class ProxyService {
     }
 
     destroy(): void {
-        clearInterval(this.timer);
-        this.timer = null;
+        if (this.timer) {
+            clearInterval(this.timer);
+            this.timer = null;
+        }
     }
 }

src/test/e2e/api/proxy/proxy.e2e.test.ts

@@ -14,6 +14,7 @@ import {
     IStrategyConfig,
 } from '../../../../lib/types';
 import { ProxyRepository } from '../../../../lib/proxy';
+import { Logger } from '../../../../lib/logger';
 
 let app: IUnleashTest;
 let db: ITestDb;
@@ -27,6 +28,7 @@ beforeAll(async () => {
 
 afterEach(() => {
     app.services.proxyService.stopAll();
+    jest.clearAllMocks();
 });
 
 afterAll(async () => {
@@ -853,14 +855,15 @@ test('Should sync proxy for keys on an interval', async () => {
         ProxyRepository.prototype as any,
         'featuresForToken',
     );
+    expect(user).not.toBeNull();
     const proxyRepository = new ProxyRepository(
         {
             getLogger,
             frontendApi: { refreshIntervalInMs: 5000 },
         },
         db.stores,
         app.services,
-        user,
+        user!,
     );
 
     await proxyRepository.start();
@@ -891,7 +894,7 @@ test('Should change fetch interval', async () => {
         },
         db.stores,
         app.services,
-        user,
+        user!,
     );
 
     await proxyRepository.start();
@@ -919,7 +922,7 @@ test('Should not recursively set off timers on events', async () => {
         },
         db.stores,
         app.services,
-        user,
+        user!,
     );
 
     await proxyRepository.start();
@@ -934,7 +937,7 @@ test('Should not recursively set off timers on events', async () => {
 });
 
 test('should return all features when specified', async () => {
-    app.config.experimental.flags.proxyReturnAllToggles = true;
+    app.config.experimental!.flags.proxyReturnAllToggles = true;
     const frontendToken = await createApiToken(ApiTokenType.FRONTEND);
     await createFeatureToggle({
         name: 'enabledFeature1',
@@ -991,3 +994,47 @@ test('should return maxAge header on options call', async () => {
             expect(res.headers['access-control-max-age']).toBe('86400');
         });
 });
+
+test('should terminate data polling when stop is called', async () => {
+    const frontendToken = await createApiToken(ApiTokenType.FRONTEND);
+    const user = await app.services.apiTokenService.getUserForToken(
+        frontendToken.secret,
+    );
+
+    const logTrap = [];
+    const getDebugLogger = (): Logger => {
+        return {
+            /* eslint-disable-next-line */
+            debug: (message: any, ...args: any[]) => {
+                logTrap.push(message);
+            },
+            /* eslint-disable-next-line */
+            info: (...args: any[]) => {},
+            /* eslint-disable-next-line */
+            warn: (...args: any[]) => {},
+            /* eslint-disable-next-line */
+            error: (...args: any[]) => {},
+            /* eslint-disable-next-line */
+            fatal: (...args: any[]) => {},
+        };
+    };
+
+    /* eslint-disable-next-line */
+    const proxyRepository = new ProxyRepository(
+        {
+            getLogger: getDebugLogger,
+            frontendApi: { refreshIntervalInMs: 1 },
+        },
+        db.stores,
+        app.services,
+        user,
+    );
+
+    await proxyRepository.start();
+    proxyRepository.stop();
+    // Polling here is an async recursive call, so we gotta give it a bit of time
+    await new Promise((r) => setTimeout(r, 10));
+    expect(logTrap).toContain(
+        'Shutting down data polling for proxy repository',
+    );
+});