Fix cache expiration-related issues in Auto Polling mode (#106)

* Make auto polling loop fault-tolerant + make timing more accurate * Check for expiration on every iteration in Auto Polling mode + allow a tolerance of 500ms to prevent missing fetches due to timer inaccuracy + sync with cache even in offline mode * Fix a few broken tests * Fix CI * npm audit fix * Bump version
configcat · Sep 6, 2024 · d377986 · d377986
1 parent 66d0520
commit d377986
Show file tree

Hide file tree

Showing 9 changed files with 145 additions and 73 deletions.
diff --git a/.github/workflows/common-js-ci.yml b/.github/workflows/common-js-ci.yml
@@ -18,6 +18,9 @@ jobs:
       matrix:
         node: [ 14, 16, 18, 20 ]
         os: [ macos-latest, ubuntu-latest, windows-latest ]
+        exclude:
+          - node: 14
+            os: macos-latest
       fail-fast: false
     name: Test [${{ matrix.os }}, Node ${{ matrix.node }}]
     steps:

diff --git a/package-lock.json b/package-lock.json
diff --git a/package.json b/package.json
@@ -1,6 +1,6 @@
 {
   "name": "configcat-common",
-  "version": "9.3.0",
+  "version": "9.3.1",
   "description": "ConfigCat is a configuration as a service that lets you manage your features and configurations without actually deploying new code.",
   "main": "lib/index.js",
   "types": "lib/index.d.ts",

diff --git a/src/AutoPollConfigService.ts b/src/AutoPollConfigService.ts
@@ -4,22 +4,28 @@ import type { IConfigFetcher } from "./ConfigFetcher";
 import type { IConfigService, RefreshResult } from "./ConfigServiceBase";
 import { ClientCacheState, ConfigServiceBase } from "./ConfigServiceBase";
 import type { ProjectConfig } from "./ProjectConfig";
-import { delay } from "./Utils";
+import { AbortToken, delay } from "./Utils";
+
+export const POLL_EXPIRATION_TOLERANCE_MS = 500;
 
 export class AutoPollConfigService extends ConfigServiceBase<AutoPollOptions> implements IConfigService {
 
   private initialized: boolean;
   private readonly initializationPromise: Promise<boolean>;
   private signalInitialization: () => void = () => { /* Intentional no-op. */ };
-  private workerTimerId?: ReturnType<typeof setTimeout>;
+  private stopToken = new AbortToken();
   private readonly pollIntervalMs: number;
+  private readonly pollExpirationMs: number;
   readonly readyPromise: Promise<ClientCacheState>;
 
   constructor(configFetcher: IConfigFetcher, options: AutoPollOptions) {
 
     super(configFetcher, options);
 
     this.pollIntervalMs = options.pollIntervalSeconds * 1000;
+    // Due to the inaccuracy of the timer, some tolerance should be allowed when checking for
+    // cache expiration in the polling loop, otherwise some fetch operations may be missed.
+    this.pollExpirationMs = this.pollIntervalMs - POLL_EXPIRATION_TOLERANCE_MS;
 
     const initialCacheSyncUp = this.syncUpWithCache();
 
@@ -48,7 +54,7 @@ export class AutoPollConfigService extends ConfigServiceBase<AutoPollOptions> im
     });
 
     if (!options.offline) {
-      this.startRefreshWorker(initialCacheSyncUp);
+      this.startRefreshWorker(initialCacheSyncUp, this.stopToken);
     }
   }
 
@@ -58,12 +64,12 @@ export class AutoPollConfigService extends ConfigServiceBase<AutoPollOptions> im
       return true;
     }
 
-    const delayCleanup: { clearTimer?: () => void } = {};
+    const abortToken = new AbortToken();
     const success = await Promise.race([
       initSignalPromise.then(() => true),
-      delay(this.options.maxInitWaitTimeSeconds * 1000, delayCleanup).then(() => false)
+      delay(this.options.maxInitWaitTimeSeconds * 1000, abortToken).then(() => false)
     ]);
-    delayCleanup.clearTimer!();
+    abortToken.abort();
     return success;
   }
 
@@ -105,7 +111,7 @@ export class AutoPollConfigService extends ConfigServiceBase<AutoPollOptions> im
   dispose(): void {
     this.options.logger.debug("AutoPollConfigService.dispose() called.");
     super.dispose();
-    if (this.workerTimerId) {
+    if (!this.stopToken.aborted) {
       this.stopRefreshWorker();
     }
   }
@@ -116,58 +122,65 @@ export class AutoPollConfigService extends ConfigServiceBase<AutoPollOptions> im
   }
 
   protected setOnlineCore(): void {
-    this.startRefreshWorker();
+    this.startRefreshWorker(null, this.stopToken);
   }
 
   protected setOfflineCore(): void {
     this.stopRefreshWorker();
+    this.stopToken = new AbortToken();
   }
 
-  private async startRefreshWorker(initialCacheSyncUp?: ProjectConfig | Promise<ProjectConfig>) {
+  private async startRefreshWorker(initialCacheSyncUp: ProjectConfig | Promise<ProjectConfig> | null, stopToken: AbortToken) {
     this.options.logger.debug("AutoPollConfigService.startRefreshWorker() called.");
 
-    const delayMs = this.pollIntervalMs;
+    let isFirstIteration = true;
+    while (!stopToken.aborted) {
+      try {
+        const scheduledNextTimeMs = new Date().getTime() + this.pollIntervalMs;
+        try {
+          await this.refreshWorkerLogic(isFirstIteration, initialCacheSyncUp);
+        }
+        catch (err) {
+          this.options.logger.autoPollConfigServiceErrorDuringPolling(err);
+        }
+
+        const realNextTimeMs = scheduledNextTimeMs - new Date().getTime();
+        if (realNextTimeMs > 0) {
+          await delay(realNextTimeMs, stopToken);
+        }
+      }
+      catch (err) {
+        this.options.logger.autoPollConfigServiceErrorDuringPolling(err);
+      }
+
+      isFirstIteration = false;
+      initialCacheSyncUp = null; // allow GC to collect the Promise and its result
+    }
+  }
+
+  private stopRefreshWorker() {
+    this.options.logger.debug("AutoPollConfigService.stopRefreshWorker() called.");
+    this.stopToken.abort();
+  }
+
+  private async refreshWorkerLogic(isFirstIteration: boolean, initialCacheSyncUp: ProjectConfig | Promise<ProjectConfig> | null) {
+    this.options.logger.debug("AutoPollConfigService.refreshWorkerLogic() - called.");
 
     const latestConfig = await (initialCacheSyncUp ?? this.options.cache.get(this.cacheKey));
-    if (latestConfig.isExpired(this.pollIntervalMs)) {
+    if (latestConfig.isExpired(this.pollExpirationMs)) {
       // Even if the service gets disposed immediately, we allow the first refresh for backward compatibility,
       // i.e. to not break usage patterns like this:
       // ```
       // client.getValueAsync("SOME_KEY", false).then(value => { /* ... */ }, user);
       // client.dispose();
       // ```
-      if (!this.isOfflineExactly) {
+      if (isFirstIteration ? !this.isOfflineExactly : !this.isOffline) {
         await this.refreshConfigCoreAsync(latestConfig);
       }
     }
-    else {
+    else if (isFirstIteration) {
       this.signalInitialization();
     }
-
-    this.options.logger.debug("AutoPollConfigService.startRefreshWorker() - calling refreshWorkerLogic()'s setTimeout.");
-    this.workerTimerId = setTimeout(d => this.refreshWorkerLogic(d), delayMs, delayMs);
-  }
-
-  private stopRefreshWorker() {
-    this.options.logger.debug("AutoPollConfigService.stopRefreshWorker() - clearing setTimeout.");
-    clearTimeout(this.workerTimerId);
-  }
-
-  private async refreshWorkerLogic(delayMs: number) {
-    if (this.disposed) {
-      this.options.logger.debug("AutoPollConfigService.refreshWorkerLogic() - called on a disposed client.");
-      return;
-    }
-
-    this.options.logger.debug("AutoPollConfigService.refreshWorkerLogic() - called.");
-
-    if (!this.isOffline) {
-      const latestConfig = await this.options.cache.get(this.cacheKey);
-      await this.refreshConfigCoreAsync(latestConfig);
-    }
-
-    this.options.logger.debug("AutoPollConfigService.refreshWorkerLogic() - calling refreshWorkerLogic()'s setTimeout.");
-    this.workerTimerId = setTimeout(d => this.refreshWorkerLogic(d), delayMs, delayMs);
   }
 
   getCacheState(cachedConfig: ProjectConfig): ClientCacheState {

diff --git a/src/ConfigCatLogger.ts b/src/ConfigCatLogger.ts
@@ -231,6 +231,14 @@ export class LoggerWrapper implements IConfigCatLogger {
     );
   }
 
+  autoPollConfigServiceErrorDuringPolling(ex: any): LogMessage {
+    return this.log(
+      LogLevel.Error, 1200,
+      "Error occurred during auto polling.",
+      ex
+    );
+  }
+
   /* SDK-specific error messages (2000-2999) */
 
   settingForVariationIdIsNotPresent(variationId: string): LogMessage {

diff --git a/src/Utils.ts b/src/Utils.ts
@@ -1,10 +1,49 @@
-export function delay(delayMs: number, delayCleanup?: { clearTimer?: () => void } | null): Promise<void> {
-  let timerId: ReturnType<typeof setTimeout>;
-  const promise = new Promise<void>(resolve => timerId = setTimeout(resolve, delayMs));
-  if (delayCleanup) {
-    delayCleanup.clearTimer = () => clearTimeout(timerId);
+// NOTE: Normally, we'd just use AbortController/AbortSignal, however that may not be available on all platforms,
+// and we don't want to include a complete polyfill. So we implement a simplified version that fits our use case.
+export class AbortToken {
+  private callbacks: (() => void)[] | null = [];
+  get aborted(): boolean { return !this.callbacks; }
+
+  abort(): void {
+    if (!this.aborted) {
+      const callbacks = this.callbacks!;
+      this.callbacks = null;
+      for (const callback of callbacks) {
+        callback();
+      }
+    }
   }
-  return promise;
+
+  registerCallback(callback: () => void): () => void {
+    if (this.aborted) {
+      callback();
+      return () => { };
+    }
+
+    this.callbacks!.push(callback);
+    return () => {
+      const callbacks = this.callbacks;
+      let index: number;
+      if (callbacks && (index = callbacks.indexOf(callback)) >= 0) {
+        callbacks.splice(index, 1);
+      }
+    };
+  }
+}
+
+export function delay(delayMs: number, abortToken?: AbortToken | null): Promise<boolean> {
+  let timerId: ReturnType<typeof setTimeout>;
+  return new Promise<boolean>(resolve => {
+    const unregisterAbortCallback = abortToken?.registerCallback(() => {
+      clearTimeout(timerId);
+      resolve(false);
+    });
+
+    timerId = setTimeout(() => {
+      unregisterAbortCallback?.();
+      resolve(true);
+    }, delayMs);
+  });
 }
 
 export function errorToString(err: any, includeStackTrace = false): string {

diff --git a/test/ConfigCatClientTests.ts b/test/ConfigCatClientTests.ts
@@ -526,11 +526,13 @@ describe("ConfigCatClient", () => {
       setupHooks: hooks => hooks.on("configChanged", () => configChangedEventCount++)
     };
     const options: AutoPollOptions = new AutoPollOptions("APIKEY", "common", "1.0.0", userOptions, null);
-    new ConfigCatClient(options, configCatKernel);
-
-    await delay(2.5 * pollIntervalSeconds * 1000);
+    const client = new ConfigCatClient(options, configCatKernel);
+    try {
+      await delay(2.5 * pollIntervalSeconds * 1000);
 
-    assert.equal(configChangedEventCount, 3);
+      assert.equal(configChangedEventCount, 3);
+    }
+    finally { client.dispose(); }
   });
 
   it("Initialization With AutoPollOptions - config doesn't change - should fire configChanged only once", async () => {
@@ -544,11 +546,13 @@ describe("ConfigCatClient", () => {
       setupHooks: hooks => hooks.on("configChanged", () => configChangedEventCount++)
     };
     const options: AutoPollOptions = new AutoPollOptions("APIKEY", "common", "1.0.0", userOptions, null);
-    new ConfigCatClient(options, configCatKernel);
-
-    await delay(2.5 * pollIntervalSeconds * 1000);
+    const client = new ConfigCatClient(options, configCatKernel);
+    try {
+      await delay(2.5 * pollIntervalSeconds * 1000);
 
-    assert.equal(configChangedEventCount, 1);
+      assert.equal(configChangedEventCount, 1); 
+    }
+    finally { client.dispose(); }
   });
 
   it("Initialization With AutoPollOptions - with maxInitWaitTimeSeconds - getValueAsync should wait", async () => {