From 6e280c4ac31278894e6141474045c2c2a76c74d5 Mon Sep 17 00:00:00 2001 From: TsvetanMilanov Date: Thu, 29 Nov 2018 16:48:38 +0200 Subject: [PATCH 1/3] Retry sporadically stuck requests/responses Sometimes we have sporadically stuck http requests/responses and in those cases the CLI is just waiting and not doing anything. If we retry the requests, they will pass. That's why we need to add a retry logic in the http client. --- lib/common/http-client.ts | 79 ++++++++++++++++++++++++++++++++++----- 1 file changed, 69 insertions(+), 10 deletions(-) diff --git a/lib/common/http-client.ts b/lib/common/http-client.ts index fa191f1922..25f8e524e2 100644 --- a/lib/common/http-client.ts +++ b/lib/common/http-client.ts @@ -9,13 +9,36 @@ import * as request from "request"; export class HttpClient implements Server.IHttpClient { private defaultUserAgent: string; private static STATUS_CODE_REGEX = /statuscode=(\d+)/i; + private static STUCK_REQUEST_ERROR_MESSAGE = "The request can't receive any response."; + private static STUCK_RESPONSE_ERROR_MESSAGE = "Can't receive all parts of the response."; + private static STUCK_REQUEST_TIMEOUT = 60000; + // We receive multiple response packets every ms but we don't need to be very aggressive here. + private static STUCK_RESPONSE_CHECK_INTERVAL = 10000; constructor(private $config: Config.IConfig, private $logger: ILogger, private $proxyService: IProxyService, private $staticConfig: Config.IStaticConfig) { } - async httpRequest(options: any, proxySettings?: IProxySettings): Promise { + public async httpRequest(options: any, proxySettings?: IProxySettings): Promise { + try { + const result = await this.httpRequestCore(options, proxySettings); + return result; + } catch (err) { + if (err.message === HttpClient.STUCK_REQUEST_ERROR_MESSAGE || err.message === HttpClient.STUCK_RESPONSE_ERROR_MESSAGE) { + // Retry the request immediately because there are at least 10 seconds between the two requests. + // We have to retry only once the sporadically stuck requests/responses. + // We can add exponential backoff retry here if we decide that we need to workaround bigger network issues on the client side. + this.$logger.warn("%s Retrying request to %s...", err.message, options.url || options); + const retryResult = await this.httpRequestCore(options, proxySettings); + return retryResult; + } + + throw err; + } + } + + private async httpRequestCore(options: any, proxySettings?: IProxySettings): Promise { if (_.isString(options)) { options = { url: options, @@ -73,6 +96,10 @@ export class HttpClient implements Server.IHttpClient { const result = new Promise((resolve, reject) => { let timerId: number; + let stuckRequestTimerId: number; + let stuckResponseIntervalId: NodeJS.Timer; + let hasResponse = false; + const timers: number[] = []; const promiseActions: IPromiseActions = { resolve, @@ -82,8 +109,9 @@ export class HttpClient implements Server.IHttpClient { if (options.timeout) { timerId = setTimeout(() => { - this.setResponseResult(promiseActions, timerId, { err: new Error(`Request to ${unmodifiedOptions.url} timed out.`) }, ); + this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err: new Error(`Request to ${unmodifiedOptions.url} timed out.`) }); }, options.timeout); + timers.push(timerId); delete options.timeout; } @@ -95,6 +123,16 @@ export class HttpClient implements Server.IHttpClient { this.$logger.trace("httpRequest: %s", util.inspect(options)); const requestObj = request(options); + stuckRequestTimerId = setTimeout(() => { + clearTimeout(stuckRequestTimerId); + stuckRequestTimerId = null; + if (!hasResponse) { + requestObj.abort(); + this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err: new Error(HttpClient.STUCK_REQUEST_ERROR_MESSAGE) }); + } + }, options.timeout || HttpClient.STUCK_REQUEST_TIMEOUT); + timers.push(stuckRequestTimerId); + requestObj .on("error", (err: IHttpRequestError) => { this.$logger.trace("An error occurred while sending the request:", err); @@ -107,15 +145,29 @@ export class HttpClient implements Server.IHttpClient { const errorMessage = this.getErrorMessage(errorMessageStatusCode, null); err.proxyAuthenticationRequired = errorMessageStatusCode === HttpStatusCodes.PROXY_AUTHENTICATION_REQUIRED; err.message = errorMessage || err.message; - this.setResponseResult(promiseActions, timerId, { err }); + this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err }); }) .on("response", (response: Server.IRequestResponseData) => { + hasResponse = true; + let lastChunkTimestamp = Date.now(); + stuckResponseIntervalId = setInterval(() => { + if (Date.now() - lastChunkTimestamp > HttpClient.STUCK_RESPONSE_CHECK_INTERVAL) { + if ((response).destroy) { + (response).destroy(); + } + + this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err: new Error(HttpClient.STUCK_RESPONSE_ERROR_MESSAGE) }); + } + }, HttpClient.STUCK_RESPONSE_CHECK_INTERVAL); const successful = helpers.isRequestSuccessful(response); if (!successful) { pipeTo = undefined; } let responseStream = response; + responseStream.on("data", (chunk: string) => { + lastChunkTimestamp = Date.now(); + }); switch (response.headers["content-encoding"]) { case "gzip": responseStream = responseStream.pipe(zlib.createGunzip()); @@ -128,7 +180,7 @@ export class HttpClient implements Server.IHttpClient { if (pipeTo) { pipeTo.on("finish", () => { this.$logger.trace("httpRequest: Piping done. code = %d", response.statusCode.toString()); - this.setResponseResult(promiseActions, timerId, { response }); + this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { response }); }); responseStream.pipe(pipeTo); @@ -144,13 +196,13 @@ export class HttpClient implements Server.IHttpClient { const responseBody = data.join(""); if (successful) { - this.setResponseResult(promiseActions, timerId, { body: responseBody, response }); + this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { body: responseBody, response }); } else { const errorMessage = this.getErrorMessage(response.statusCode, responseBody); const err: any = new Error(errorMessage); err.response = response; err.body = responseBody; - this.setResponseResult(promiseActions, timerId, { err }); + this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err }); } }); } @@ -181,10 +233,17 @@ export class HttpClient implements Server.IHttpClient { return response; } - private setResponseResult(result: IPromiseActions, timerId: number, resultData: { response?: Server.IRequestResponseData, body?: string, err?: Error }): void { - if (timerId) { - clearTimeout(timerId); - timerId = null; + private setResponseResult(result: IPromiseActions, timers: number[], stuckResponseIntervalId: NodeJS.Timer, resultData: { response?: Server.IRequestResponseData, body?: string, err?: Error }): void { + timers.forEach(t => { + if (t) { + clearTimeout(t); + t = null; + } + }); + + if (stuckResponseIntervalId) { + clearInterval(stuckResponseIntervalId); + stuckResponseIntervalId = null; } if (!result.isResolved()) { From 1242a7b64bd36ca70b0a1b447f082bf1ee31d9eb Mon Sep 17 00:00:00 2001 From: TsvetanMilanov Date: Fri, 30 Nov 2018 13:17:25 +0200 Subject: [PATCH 2/3] Cleanup the timers and intervals in the http-client when the process is killed --- lib/common/http-client.ts | 71 ++++++++++++++++++++++++--------------- 1 file changed, 44 insertions(+), 27 deletions(-) diff --git a/lib/common/http-client.ts b/lib/common/http-client.ts index 25f8e524e2..a9e660c00f 100644 --- a/lib/common/http-client.ts +++ b/lib/common/http-client.ts @@ -7,7 +7,6 @@ import { HttpStatusCodes } from "./constants"; import * as request from "request"; export class HttpClient implements Server.IHttpClient { - private defaultUserAgent: string; private static STATUS_CODE_REGEX = /statuscode=(\d+)/i; private static STUCK_REQUEST_ERROR_MESSAGE = "The request can't receive any response."; private static STUCK_RESPONSE_ERROR_MESSAGE = "Can't receive all parts of the response."; @@ -15,10 +14,19 @@ export class HttpClient implements Server.IHttpClient { // We receive multiple response packets every ms but we don't need to be very aggressive here. private static STUCK_RESPONSE_CHECK_INTERVAL = 10000; + private defaultUserAgent: string; + private cleanupData: ICleanupRequestData[]; + constructor(private $config: Config.IConfig, private $logger: ILogger, + private $processService: IProcessService, private $proxyService: IProxyService, - private $staticConfig: Config.IStaticConfig) { } + private $staticConfig: Config.IStaticConfig) { + this.cleanupData = []; + this.$processService.attachToProcessExitSignals(this, () => { + this.cleanupData.forEach(d => this.cleanupAfterRequest(d)); + }); + } public async httpRequest(options: any, proxySettings?: IProxySettings): Promise { try { @@ -97,9 +105,9 @@ export class HttpClient implements Server.IHttpClient { const result = new Promise((resolve, reject) => { let timerId: number; let stuckRequestTimerId: number; - let stuckResponseIntervalId: NodeJS.Timer; let hasResponse = false; - const timers: number[] = []; + const cleanupRequestData: ICleanupRequestData = { timers: [], stuckResponseIntervalId: null }; + this.cleanupData.push(cleanupRequestData); const promiseActions: IPromiseActions = { resolve, @@ -109,9 +117,9 @@ export class HttpClient implements Server.IHttpClient { if (options.timeout) { timerId = setTimeout(() => { - this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err: new Error(`Request to ${unmodifiedOptions.url} timed out.`) }); + this.setResponseResult(promiseActions, cleanupRequestData, { err: new Error(`Request to ${unmodifiedOptions.url} timed out.`) }); }, options.timeout); - timers.push(timerId); + cleanupRequestData.timers.push(timerId); delete options.timeout; } @@ -128,10 +136,10 @@ export class HttpClient implements Server.IHttpClient { stuckRequestTimerId = null; if (!hasResponse) { requestObj.abort(); - this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err: new Error(HttpClient.STUCK_REQUEST_ERROR_MESSAGE) }); + this.setResponseResult(promiseActions, cleanupRequestData, { err: new Error(HttpClient.STUCK_REQUEST_ERROR_MESSAGE) }); } }, options.timeout || HttpClient.STUCK_REQUEST_TIMEOUT); - timers.push(stuckRequestTimerId); + cleanupRequestData.timers.push(stuckRequestTimerId); requestObj .on("error", (err: IHttpRequestError) => { @@ -145,18 +153,18 @@ export class HttpClient implements Server.IHttpClient { const errorMessage = this.getErrorMessage(errorMessageStatusCode, null); err.proxyAuthenticationRequired = errorMessageStatusCode === HttpStatusCodes.PROXY_AUTHENTICATION_REQUIRED; err.message = errorMessage || err.message; - this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err }); + this.setResponseResult(promiseActions, cleanupRequestData, { err }); }) .on("response", (response: Server.IRequestResponseData) => { hasResponse = true; let lastChunkTimestamp = Date.now(); - stuckResponseIntervalId = setInterval(() => { + cleanupRequestData.stuckResponseIntervalId = setInterval(() => { if (Date.now() - lastChunkTimestamp > HttpClient.STUCK_RESPONSE_CHECK_INTERVAL) { if ((response).destroy) { (response).destroy(); } - this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err: new Error(HttpClient.STUCK_RESPONSE_ERROR_MESSAGE) }); + this.setResponseResult(promiseActions, cleanupRequestData, { err: new Error(HttpClient.STUCK_RESPONSE_ERROR_MESSAGE) }); } }, HttpClient.STUCK_RESPONSE_CHECK_INTERVAL); const successful = helpers.isRequestSuccessful(response); @@ -180,7 +188,7 @@ export class HttpClient implements Server.IHttpClient { if (pipeTo) { pipeTo.on("finish", () => { this.$logger.trace("httpRequest: Piping done. code = %d", response.statusCode.toString()); - this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { response }); + this.setResponseResult(promiseActions, cleanupRequestData, { response }); }); responseStream.pipe(pipeTo); @@ -196,13 +204,13 @@ export class HttpClient implements Server.IHttpClient { const responseBody = data.join(""); if (successful) { - this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { body: responseBody, response }); + this.setResponseResult(promiseActions, cleanupRequestData, { body: responseBody, response }); } else { const errorMessage = this.getErrorMessage(response.statusCode, responseBody); const err: any = new Error(errorMessage); err.response = response; err.body = responseBody; - this.setResponseResult(promiseActions, timers, stuckResponseIntervalId, { err }); + this.setResponseResult(promiseActions, cleanupRequestData, { err }); } }); } @@ -233,19 +241,8 @@ export class HttpClient implements Server.IHttpClient { return response; } - private setResponseResult(result: IPromiseActions, timers: number[], stuckResponseIntervalId: NodeJS.Timer, resultData: { response?: Server.IRequestResponseData, body?: string, err?: Error }): void { - timers.forEach(t => { - if (t) { - clearTimeout(t); - t = null; - } - }); - - if (stuckResponseIntervalId) { - clearInterval(stuckResponseIntervalId); - stuckResponseIntervalId = null; - } - + private setResponseResult(result: IPromiseActions, cleanupRequestData: ICleanupRequestData, resultData: { response?: Server.IRequestResponseData, body?: string, err?: Error }): void { + this.cleanupAfterRequest(cleanupRequestData); if (!result.isResolved()) { result.isResolved = () => true; if (resultData.err) { @@ -317,5 +314,25 @@ export class HttpClient implements Server.IHttpClient { this.$logger.trace("Using proxy: %s", options.proxy); } } + + private cleanupAfterRequest(data: ICleanupRequestData): void { + data.timers.forEach(t => { + if (t) { + clearTimeout(t); + t = null; + } + }); + + if (data.stuckResponseIntervalId) { + clearInterval(data.stuckResponseIntervalId); + data.stuckResponseIntervalId = null; + } + } } + +interface ICleanupRequestData { + timers: number[]; + stuckResponseIntervalId: NodeJS.Timer; +} + $injector.register("httpClient", HttpClient); From 96098149225fa008cc76ed64cc9b7f84cddf43ff Mon Sep 17 00:00:00 2001 From: TsvetanMilanov Date: Fri, 30 Nov 2018 16:06:53 +0200 Subject: [PATCH 3/3] Cleanup the req/res streams --- lib/common/declarations.d.ts | 4 +++- lib/common/http-client.ts | 28 +++++++++++++++++++--------- 2 files changed, 22 insertions(+), 10 deletions(-) diff --git a/lib/common/declarations.d.ts b/lib/common/declarations.d.ts index 06bd4e3061..2ac51950f1 100644 --- a/lib/common/declarations.d.ts +++ b/lib/common/declarations.d.ts @@ -163,8 +163,10 @@ declare module Server { interface IRequestResponseData { statusCode: number; headers: { [index: string]: any }; + complete: boolean; pipe(destination: any, options?: { end?: boolean; }): IRequestResponseData; on(event: string, listener: Function): void; + destroy(error?: Error): void; } } @@ -758,7 +760,7 @@ interface IAnalyticsSettingsService { * Gets information for projects that are exported from playground * @param projectDir Project directory path */ - getPlaygroundInfo(projectDir?: string): Promise; + getPlaygroundInfo(projectDir?: string): Promise; } /** diff --git a/lib/common/http-client.ts b/lib/common/http-client.ts index a9e660c00f..cb30d342b2 100644 --- a/lib/common/http-client.ts +++ b/lib/common/http-client.ts @@ -24,7 +24,9 @@ export class HttpClient implements Server.IHttpClient { private $staticConfig: Config.IStaticConfig) { this.cleanupData = []; this.$processService.attachToProcessExitSignals(this, () => { - this.cleanupData.forEach(d => this.cleanupAfterRequest(d)); + this.cleanupData.forEach(d => { + this.cleanupAfterRequest(d); + }); }); } @@ -106,7 +108,7 @@ export class HttpClient implements Server.IHttpClient { let timerId: number; let stuckRequestTimerId: number; let hasResponse = false; - const cleanupRequestData: ICleanupRequestData = { timers: [], stuckResponseIntervalId: null }; + const cleanupRequestData: ICleanupRequestData = Object.create({ timers: [] }); this.cleanupData.push(cleanupRequestData); const promiseActions: IPromiseActions = { @@ -130,12 +132,12 @@ export class HttpClient implements Server.IHttpClient { this.$logger.trace("httpRequest: %s", util.inspect(options)); const requestObj = request(options); + cleanupRequestData.req = requestObj; stuckRequestTimerId = setTimeout(() => { clearTimeout(stuckRequestTimerId); stuckRequestTimerId = null; if (!hasResponse) { - requestObj.abort(); this.setResponseResult(promiseActions, cleanupRequestData, { err: new Error(HttpClient.STUCK_REQUEST_ERROR_MESSAGE) }); } }, options.timeout || HttpClient.STUCK_REQUEST_TIMEOUT); @@ -156,14 +158,11 @@ export class HttpClient implements Server.IHttpClient { this.setResponseResult(promiseActions, cleanupRequestData, { err }); }) .on("response", (response: Server.IRequestResponseData) => { + cleanupRequestData.res = response; hasResponse = true; let lastChunkTimestamp = Date.now(); cleanupRequestData.stuckResponseIntervalId = setInterval(() => { if (Date.now() - lastChunkTimestamp > HttpClient.STUCK_RESPONSE_CHECK_INTERVAL) { - if ((response).destroy) { - (response).destroy(); - } - this.setResponseResult(promiseActions, cleanupRequestData, { err: new Error(HttpClient.STUCK_RESPONSE_ERROR_MESSAGE) }); } }, HttpClient.STUCK_RESPONSE_CHECK_INTERVAL); @@ -245,8 +244,8 @@ export class HttpClient implements Server.IHttpClient { this.cleanupAfterRequest(cleanupRequestData); if (!result.isResolved()) { result.isResolved = () => true; - if (resultData.err) { - return result.reject(resultData.err); + if (resultData.err || !resultData.response.complete) { + return result.reject(resultData.err || new Error("Request canceled")); } const finalResult: any = resultData; @@ -327,12 +326,23 @@ export class HttpClient implements Server.IHttpClient { clearInterval(data.stuckResponseIntervalId); data.stuckResponseIntervalId = null; } + + if (data.req) { + data.req.abort(); + } + + if (data.res) { + data.res.destroy(); + } } + } interface ICleanupRequestData { timers: number[]; stuckResponseIntervalId: NodeJS.Timer; + req: request.Request; + res: Server.IRequestResponseData; } $injector.register("httpClient", HttpClient);