Fix the floating setTimeout in introspection client (#655)

* Fix the floating setTimeout
* Add basic set of tests for ResponseCache

.vscode/launch.json

@@ -479,6 +479,23 @@
         "${workspaceFolder}/{core,clients}/*/lib/**/*.js"
       ]
     },
+    {
+      "name": "Backend iTwin Client Tests (Offline)",
+      "presentation": {
+        "group": "3_ClientsTests",
+        "order": 3
+      },
+      "cwd": "${workspaceFolder}/core/backend-itwin-client",
+      "type": "pwa-node",
+      "request": "launch",
+      "runtimeExecutable": "npm",
+      "runtimeArgs": [
+        "test"
+      ],
+      "outFiles": [
+        "${workspaceFolder}/{core,clients}/*/lib/**/*.js"
+      ]
+    },
     // UI TESTS
     {
       "name": "[UI] Tests: Abstract",

clients/telemetry/src/TelemetryClient.ts

@@ -61,34 +61,34 @@ export interface TelemetryClient {
 
 /** @alpha */
 export class TelemetryManager {
-  protected readonly _subClients: Set<TelemetryClient>;
+  protected readonly _clients: Set<TelemetryClient>;
 
-  constructor(...subClients: TelemetryClient[]) {
-    this._subClients = new Set<TelemetryClient>(subClients);
+  constructor(...clients: TelemetryClient[]) {
+    this._clients = new Set<TelemetryClient>(clients);
   }
 
-  /**
-   *
-   * This function should not throw errors
-   * @param requestContext
-   * @param telemetryEvent
-   */
   public async postTelemetry(requestContext: AuthorizedClientRequestContext, telemetryEvent: TelemetryEvent): Promise<void> {
-    const subClientPromises = Array.from(this._subClients).map(async (subClient) => {
+    const postPerClient = async (subClient: TelemetryClient) => {
       try {
         await subClient.postTelemetry(requestContext, telemetryEvent);
       } catch (err) {
         Logger.logError(TelemetryClientLoggerCategory.Telemetry, `Failed to post telemetry via subclient`, () => err);
       }
-    });
+    };
+
+    const subClientPromises = [];
+    for (const subClient of this._clients) {
+      subClientPromises.push(postPerClient(subClient));
+    }
+
     await Promise.all(subClientPromises);
   }
 
   public addClient(client: TelemetryClient): void {
-    this._subClients.add(client);
+    this._clients.add(client);
   }
 
   public hasClient(client: TelemetryClient): boolean {
-    return this._subClients.has(client);
+    return this._clients.has(client);
   }
 }

common/api/telemetry-client.api.md

@@ -81,14 +81,15 @@ export class TelemetryEvent {
 
 // @alpha (undocumented)
 export class TelemetryManager {
-    constructor(...subClients: TelemetryClient[]);
+    constructor(...clients: TelemetryClient[]);
     // (undocumented)
     addClient(client: TelemetryClient): void;
     // (undocumented)
+    protected readonly _clients: Set<TelemetryClient>;
+    // (undocumented)
     hasClient(client: TelemetryClient): boolean;
-    postTelemetry(requestContext: AuthorizedClientRequestContext, telemetryEvent: TelemetryEvent): Promise<void>;
     // (undocumented)
-    protected readonly _subClients: Set<TelemetryClient>;
+    postTelemetry(requestContext: AuthorizedClientRequestContext, telemetryEvent: TelemetryEvent): Promise<void>;
 }
 
 

common/changes/@bentley/backend-itwin-client/fix-floating-setTimeout_2021-01-25-22-35.json

@@ -0,0 +1,11 @@
+{
+  "changes": [
+    {
+      "packageName": "@bentley/backend-itwin-client",
+      "comment": "",
+      "type": "none"
+    }
+  ],
+  "packageName": "@bentley/backend-itwin-client",
+  "email": "31107829+calebmshafer@users.noreply.github.com"
+}

common/changes/@bentley/telemetry-client/fix-floating-setTimeout_2021-01-25-22-35.json

@@ -0,0 +1,11 @@
+{
+  "changes": [
+    {
+      "packageName": "@bentley/telemetry-client",
+      "comment": "",
+      "type": "none"
+    }
+  ],
+  "packageName": "@bentley/telemetry-client",
+  "email": "31107829+calebmshafer@users.noreply.github.com"
+}

core/backend-itwin-client/package.json

@@ -22,7 +22,7 @@
     "extract-api": "betools extract-api --entry=backend-itwin-client",
     "lint": "eslint -f visualstudio \"./src/**/*.ts\" 1>&2",
     "pretest": "npm run copy:test-assets",
-    "test": "",
+    "test": "betools test --grep=\"#integration\" --invert",
     "test:integration": "npm run pretest && betools test --grep=\"#integration\""
   },
   "repository": {
@@ -73,13 +73,15 @@
     "@types/nock": "^9.1.2",
     "@types/node": "10.14.1",
     "@types/semver": "^5.5.0",
+    "@types/sinon": "^9.0.0",
     "chai": "^4.1.2",
     "cpx": "^1.5.0",
     "eslint": "^6.8.0",
     "mocha": "^5.2.0",
     "nock": "^9.2.3",
     "nyc": "^14.0.0",
     "rimraf": "^3.0.2",
+    "sinon": "^9.0.2",
     "source-map-support": "^0.5.6",
     "ts-node": "^7.0.1",
     "typescript": "~3.7.4"
@@ -105,4 +107,4 @@
     ],
     "extends": "plugin:@bentley/imodeljs-recommended"
   }
-}
+}

core/backend-itwin-client/src/oidc/introspection/IntrospectionResponseCache.ts

@@ -8,52 +8,60 @@
 
 import { IntrospectionResponse } from "./IntrospectionResponse";
 
-/**
+/** The IntrospectionResponseCache is a simple dictionary of [[IntrospectionResponse]] that are currently in use.
+ * The entries will removed automatically if their tokens expire.
  * @alpha
- * The class UserTokenCache is a simple dictionary of tokens that are currently in use. The entries
- * will removed automatically if their tokens expire.
  */
 export abstract class IntrospectionResponseCache {
-  /**
-   * Adds the given token to the cache. The token will removed automatically from the cache if
-   * it's about to expire.
-   * @param key       Key of the token entry.
-   * @param token     UserToken that is associated with the key.
+  /** Adds the given response to the cache. The response will be added if it has not yet expired.
+   * @param key       A unique string to identify the response within the cache.
+   * @param response  A response associated with the key.
    */
   public async add(key: string, response: IntrospectionResponse): Promise<void> {
     if (!response.exp) // do not cache any response without a known expiration time
       return;
 
     const currentTimeInSeconds = new Date().getTime() / 1000; // UTC time in seconds since 1970-01-01
     const secondsUntilExpiration = response.exp - currentTimeInSeconds;
-    if (secondsUntilExpiration > 0) {
-      setTimeout(async () => this.remove(key), secondsUntilExpiration * 1000);
+    if (secondsUntilExpiration > 0)
       await this.storeResponse(key, response);
-    }
   }
 
-  protected abstract async storeResponse(key: string, response: IntrospectionResponse): Promise<void>;
+  protected abstract storeResponse(key: string, response: IntrospectionResponse): Promise<void>;
 
-  /**
-   * Gets the User token for the given key.
-   * @param key       Key of the token entry.
-   * @returns         The Token if it can be found or undefined if not.
+  /** Gets the [[IntrospectionResponse]] for the given key.
+   *
+   * Note: Removes the response if it has already expired.
+   *
+   * @param key Key of the token entry.
+   * @returns   If the key exists and has not yet expired, the IntrospectionResponse associated with the provided key.  Otherwise, undefined.
    */
   public async get(key: string): Promise<IntrospectionResponse | undefined> {
-    return this.getResponse(key);
+    const response = await this.getResponse(key);
+    if (undefined === response)
+      return undefined;
+
+    const currentTimeInSeconds = new Date().getTime() / 1000; // UTC time in seconds since 1970-01-01
+    const secondsUntilExpiration = response.exp! - currentTimeInSeconds;
+    if (secondsUntilExpiration <= 0) {
+      await this.remove(key);
+      return undefined;
+    }
+
+    return response;
   }
 
-  protected abstract async getResponse(key: string): Promise<IntrospectionResponse | undefined>;
+  protected abstract getResponse(key: string): Promise<IntrospectionResponse | undefined>;
 
   /**
-   * Removes the token with the given key from the cache.
-   * @param key       Key of the token entry.
+   * Removes the response associated with the given key from the cache.
+   * @param key  Key of the response entry.
    */
   private async remove(key: string): Promise<void> {
     await this.deleteResponse(key);
   }
 
-  protected abstract async deleteResponse(key: string): Promise<void>;
+  protected abstract deleteResponse(key: string): Promise<void>;
 }
 
 /** @alpha */

core/backend-itwin-client/src/test/Introspection.test.ts

@@ -0,0 +1,83 @@
+/*---------------------------------------------------------------------------------------------
+* Copyright (c) Bentley Systems, Incorporated. All rights reserved.
+* See LICENSE.md in the project root for license terms and full copyright notice.
+*--------------------------------------------------------------------------------------------*/
+
+import { assert } from "chai";
+import * as sinon from "sinon";
+import { MemoryIntrospectionResponseCache } from "../oidc/introspection/IntrospectionResponseCache";
+import { IntrospectionResponse } from "../oidc/introspection/IntrospectionResponse";
+
+describe("MemoryIntrospectionResponseCache", async () => {
+  it("adds the token to the cache with a valid expiration", async () => {
+    const testRes: IntrospectionResponse = {
+      active: true,
+      client_id: "test", // eslint-disable-line @typescript-eslint/naming-convention
+      scope: "test",
+      exp: Date.now() + 10000, // make the timeout long enough it won't be removed.
+    };
+
+    const newCache = new MemoryIntrospectionResponseCache();
+    await newCache.add("test", testRes);
+
+    const res = await newCache.get("test");
+    assert.isDefined(res);
+    assert.equal(res?.client_id, "test");
+  });
+
+  it("does not add the token to the cache when the token is already expired", async () => {
+    const testRes: IntrospectionResponse = {
+      active: true,
+      client_id: "test", // eslint-disable-line @typescript-eslint/naming-convention
+      scope: "test",
+      exp: new Date().getTime() / 1000 - 10000, // make the timeout prior to the time right now.
+    };
+
+    const newCache = new MemoryIntrospectionResponseCache();
+    await newCache.add("test", testRes);
+
+    const res = await newCache.get("test");
+    assert.isUndefined(res);
+  });
+
+  it("does not add to the cache if missing an expiration in response object", async () => {
+    const testRes: IntrospectionResponse = {
+      active: true,
+      client_id: "test", // eslint-disable-line @typescript-eslint/naming-convention
+      scope: "test",
+    };
+
+    const newCache = new MemoryIntrospectionResponseCache();
+    await newCache.add("test", testRes);
+
+    const res = await newCache.get("test");
+    assert.isUndefined(res);
+  });
+
+  it("adds the response to the cache and removes it after a timeout", async () => {
+    const clock = sinon.useFakeTimers();
+
+    const testRes: IntrospectionResponse = {
+      active: true,
+      client_id: "test", // eslint-disable-line @typescript-eslint/naming-convention
+      scope: "test",
+      exp: (new Date().getTime() + 10) / 1000,
+    };
+
+    const newCache = new MemoryIntrospectionResponseCache();
+    await newCache.add("test", testRes);
+
+    let res = await newCache.get("test");
+    assert.isDefined(res);
+    assert.equal(res?.client_id, "test");
+
+    // set clock to go past timeout
+    clock.tick(100);
+
+    // the key should be removed
+    res = await newCache.get("test");
+    assert.isUndefined(res);
+
+    clock.restore();
+  });
+});