From fdfd5381a556661a181187da6beb3b84fe01c510 Mon Sep 17 00:00:00 2001 From: Andrew Stanton-Nurse Date: Thu, 3 May 2018 09:26:48 -0700 Subject: [PATCH 1/3] clean up the shutdown timer --- clients/ts/signalr/src/LongPollingTransport.ts | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/clients/ts/signalr/src/LongPollingTransport.ts b/clients/ts/signalr/src/LongPollingTransport.ts index b2b456f8a2..c8e31ee7ce 100644 --- a/clients/ts/signalr/src/LongPollingTransport.ts +++ b/clients/ts/signalr/src/LongPollingTransport.ts @@ -147,6 +147,14 @@ export class LongPollingTransport implements ITransport { } } } finally { + // Trigger the poll aborted token so we don't set the shutdown timer + this.pollAbort.abort(); + + // Clean up the shutdown timer if it was registered + if (this.shutdownTimer) { + clearTimeout(this.shutdownTimer); + } + // Fire our onclosed event if (this.onclose) { this.logger.log(LogLevel.Trace, `(LongPolling transport) Firing onclose event. Error: ${closeError || ""}`); @@ -179,7 +187,7 @@ export class LongPollingTransport implements ITransport { this.logger.log(LogLevel.Trace, "(LongPolling transport) DELETE request accepted."); } finally { - // Abort the poll after 5 seconds if the server doesn't stop it. + // Abort the poll after the shutdown timeout if the server doesn't stop the poll. if (!this.pollAbort.aborted) { this.shutdownTimer = setTimeout(() => { this.logger.log(LogLevel.Warning, "(LongPolling transport) server did not terminate after DELETE request, canceling poll."); From 6f77eaca134e10307b71f3980ddb7231367dd40d Mon Sep 17 00:00:00 2001 From: Andrew Stanton-Nurse Date: Thu, 3 May 2018 12:09:07 -0700 Subject: [PATCH 2/3] add tests --- .../signalr/spec/LongPollingTransport.spec.ts | 60 ++++++++++++++++++- .../ts/signalr/src/LongPollingTransport.ts | 3 - 2 files changed, 58 insertions(+), 5 deletions(-) diff --git a/clients/ts/signalr/spec/LongPollingTransport.spec.ts b/clients/ts/signalr/spec/LongPollingTransport.spec.ts index 8023ab27d4..018e1ece9d 100644 --- a/clients/ts/signalr/spec/LongPollingTransport.spec.ts +++ b/clients/ts/signalr/spec/LongPollingTransport.spec.ts @@ -6,7 +6,8 @@ import { LongPollingTransport } from "../src/LongPollingTransport"; import { ConsoleLogger } from "../src/Utils"; import { TestHttpClient } from "./TestHttpClient"; -import { asyncit as it, PromiseSource } from "./Utils"; +import { asyncit as it, PromiseSource, delay } from "./Utils"; +import { HttpError, TimeoutError } from "../src/Errors"; describe("LongPollingTransport", () => { it("shuts down poll after timeout even if server doesn't shut it down on receiving the DELETE", async () => { @@ -48,6 +49,8 @@ describe("LongPollingTransport", () => { return new HttpResponse(200); } else { await deleteReceived.promise; + // Force the shutdown timer to be registered by not returning inline + await delay(10); pollCompleted.resolve(); return new HttpResponse(204); } @@ -56,7 +59,8 @@ describe("LongPollingTransport", () => { deleteReceived.resolve(); return new HttpResponse(202); }); - const transport = new LongPollingTransport(client, null, NullLogger.instance, false); + const logMessages: string[] = []; + const transport = new LongPollingTransport(client, null, NullLogger.instance, false, 100); await transport.connect("http://example.com", TransferFormat.Text); await transport.stop(); @@ -64,4 +68,56 @@ describe("LongPollingTransport", () => { // This should complete, because the DELETE request triggers it to stop. await pollCompleted.promise; }); + + for (const result of [200, 204, 300, new HttpError("Boom", 500), new TimeoutError()]) { + const resultName = typeof result === "number" ? result.toString() : result.constructor.name; + it(`does not fire shutdown timer when poll terminates with ${resultName}`, async () => { + let firstPoll = true; + const deleteReceived = new PromiseSource(); + const pollCompleted = new PromiseSource(); + const client = new TestHttpClient() + .on("GET", async (r) => { + if (firstPoll) { + firstPoll = false; + return new HttpResponse(200); + } else { + await deleteReceived.promise; + // Force the shutdown timer to be registered by not returning inline + await delay(10); + pollCompleted.resolve(); + + if (typeof result === "number") { + return new HttpResponse(result); + } else { + throw result; + } + } + }) + .on("DELETE", (r) => { + deleteReceived.resolve(); + return new HttpResponse(202); + }); + const logMessages: string[] = []; + const transport = new LongPollingTransport(client, null, { + log(level: LogLevel, message: string) { + logMessages.push(message); + }, + }, false, 100); + + await transport.connect("http://example.com", TransferFormat.Text); + await transport.stop(); + + // This should complete, because the DELETE request triggers it to stop. + await pollCompleted.promise; + + // Wait for the shutdown timeout to elapse + // This can be much cleaner when we port to Jest because it has a built-in set of + // fake timers! + await delay(150); + + expect(logMessages) + .not + .toContain("(LongPolling transport) server did not terminate after DELETE request, canceling poll."); + }); + } }); \ No newline at end of file diff --git a/clients/ts/signalr/src/LongPollingTransport.ts b/clients/ts/signalr/src/LongPollingTransport.ts index c8e31ee7ce..1874d21277 100644 --- a/clients/ts/signalr/src/LongPollingTransport.ts +++ b/clients/ts/signalr/src/LongPollingTransport.ts @@ -108,9 +108,6 @@ export class LongPollingTransport implements ITransport { if (response.statusCode === 204) { this.logger.log(LogLevel.Information, "(LongPolling transport) Poll terminated by server"); - // If we were on a timeout waiting for shutdown, unregister it. - clearTimeout(this.shutdownTimer); - this.running = false; } else if (response.statusCode !== 200) { this.logger.log(LogLevel.Error, `(LongPolling transport) Unexpected response code: ${response.statusCode}`); From 1282fde338d52e419fdf6624fa3bfe96449d7ecd Mon Sep 17 00:00:00 2001 From: Andrew Stanton-Nurse Date: Thu, 3 May 2018 17:55:25 -0700 Subject: [PATCH 3/3] less flaky test --- .../ts/signalr/spec/LongPollingTransport.spec.ts | 7 +++---- clients/ts/signalr/src/LongPollingTransport.ts | 15 ++++++++++++--- 2 files changed, 15 insertions(+), 7 deletions(-) diff --git a/clients/ts/signalr/spec/LongPollingTransport.spec.ts b/clients/ts/signalr/spec/LongPollingTransport.spec.ts index 018e1ece9d..29e7fb9505 100644 --- a/clients/ts/signalr/spec/LongPollingTransport.spec.ts +++ b/clients/ts/signalr/spec/LongPollingTransport.spec.ts @@ -8,6 +8,7 @@ import { ConsoleLogger } from "../src/Utils"; import { TestHttpClient } from "./TestHttpClient"; import { asyncit as it, PromiseSource, delay } from "./Utils"; import { HttpError, TimeoutError } from "../src/Errors"; +import { AbortSignal } from "../src/AbortController"; describe("LongPollingTransport", () => { it("shuts down poll after timeout even if server doesn't shut it down on receiving the DELETE", async () => { @@ -59,7 +60,6 @@ describe("LongPollingTransport", () => { deleteReceived.resolve(); return new HttpResponse(202); }); - const logMessages: string[] = []; const transport = new LongPollingTransport(client, null, NullLogger.instance, false, 100); await transport.connect("http://example.com", TransferFormat.Text); @@ -115,9 +115,8 @@ describe("LongPollingTransport", () => { // fake timers! await delay(150); - expect(logMessages) - .not - .toContain("(LongPolling transport) server did not terminate after DELETE request, canceling poll."); + // The pollAbort token should be left unaborted because we shut down gracefully. + expect(transport.pollAborted).toBe(false); }); } }); \ No newline at end of file diff --git a/clients/ts/signalr/src/LongPollingTransport.ts b/clients/ts/signalr/src/LongPollingTransport.ts index 1874d21277..6fdc830320 100644 --- a/clients/ts/signalr/src/LongPollingTransport.ts +++ b/clients/ts/signalr/src/LongPollingTransport.ts @@ -10,6 +10,7 @@ import { Arg, getDataDetail, sendMessage } from "./Utils"; const SHUTDOWN_TIMEOUT = 5 * 1000; +// Not exported from 'index', this type is internal. export class LongPollingTransport implements ITransport { private readonly httpClient: HttpClient; private readonly accessTokenFactory: () => string | Promise; @@ -22,6 +23,12 @@ export class LongPollingTransport implements ITransport { private shutdownTimer: any; // We use 'any' because this is an object in NodeJS. But it still gets passed to clearTimeout, so it doesn't really matter private shutdownTimeout: number; private running: boolean; + private stopped: boolean; + + // This is an internal type, not exported from 'index' so this is really just internal. + public get pollAborted() { + return this.pollAbort.aborted; + } constructor(httpClient: HttpClient, accessTokenFactory: () => string | Promise, logger: ILogger, logMessageContent: boolean, shutdownTimeout?: number) { this.httpClient = httpClient; @@ -144,8 +151,8 @@ export class LongPollingTransport implements ITransport { } } } finally { - // Trigger the poll aborted token so we don't set the shutdown timer - this.pollAbort.abort(); + // Indicate that we've stopped so the shutdown timer doesn't get registered. + this.stopped = true; // Clean up the shutdown timer if it was registered if (this.shutdownTimer) { @@ -185,9 +192,11 @@ export class LongPollingTransport implements ITransport { this.logger.log(LogLevel.Trace, "(LongPolling transport) DELETE request accepted."); } finally { // Abort the poll after the shutdown timeout if the server doesn't stop the poll. - if (!this.pollAbort.aborted) { + if (!this.stopped) { this.shutdownTimer = setTimeout(() => { this.logger.log(LogLevel.Warning, "(LongPolling transport) server did not terminate after DELETE request, canceling poll."); + + // Abort any outstanding poll this.pollAbort.abort(); }, this.shutdownTimeout); }