From 911adb59e466e90fe52a31eacb8623bbb9c965cd Mon Sep 17 00:00:00 2001 From: satyajeetkolhapure Date: Thu, 1 Sep 2022 16:39:19 +0100 Subject: [PATCH 1/7] added retry backoff mechanism in web socket handler --- .../src/forking/handlers/ws-handler.ts | 27 ++++++++++++++++--- 1 file changed, 23 insertions(+), 4 deletions(-) diff --git a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts index eca6f9e01a..33c34fec16 100644 --- a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts +++ b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts @@ -20,6 +20,12 @@ export class WsHandler extends BaseHandler implements Handler { }> >(); + // retry configuration + private retryIntervalBase: number = 3; + private retryCounter: number = 5; + private initialRetryCounter = this.retryCounter; + private retryTimeoutId: NodeJS.Timeout; + constructor(options: EthereumInternalOptions, abortSignal: AbortSignal) { super(options, abortSignal); @@ -46,10 +52,21 @@ export class WsHandler extends BaseHandler implements Handler { this.open = this.connect(this.connection, logging); this.connection.onclose = () => { // try to connect again... - // Issue: https://github.com/trufflesuite/ganache/issues/3476 - // TODO: backoff and eventually fail - // Issue: https://github.com/trufflesuite/ganache/issues/3477 - this.open = this.connect(this.connection, logging); + // backoff and eventually fail + if( this.retryCounter > 0 || this.retryCounter == -1 ) { + if( this.retryCounter !== -1 ) this.retryCounter--; + clearTimeout( this.retryTimeoutId ); + this.retryTimeoutId = setTimeout( () => { + const onCloseEvent = this.connection.onclose; + this.connection = new WebSocket(url.toString(), { + origin, + headers: this.headers + }); + this.connection.binaryType = "nodebuffer"; + this.connection.onclose = onCloseEvent; + this.open = this.connect(this.connection, logging); + }, Math.pow( this.retryIntervalBase, this.initialRetryCounter - this.retryCounter ) * 1000 ); + } }; this.abortSignal.addEventListener("abort", () => { this.connection.onclose = null; @@ -117,6 +134,8 @@ export class WsHandler extends BaseHandler implements Handler { () => { connection.onopen = null; connection.onerror = null; + // reset the retry counter + this.retryCounter = this.initialRetryCounter; }, err => { logging.logger.log(err); From 8611d3cac85a62396ba4e726c79548d355b6b79b Mon Sep 17 00:00:00 2001 From: satyajeetkolhapure Date: Thu, 8 Sep 2022 14:57:00 +0100 Subject: [PATCH 2/7] moved websocket instantiation into connect method. added reconnect method --- .../src/forking/handlers/ws-handler.ts | 67 ++++++++++--------- 1 file changed, 34 insertions(+), 33 deletions(-) diff --git a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts index 33c34fec16..6a34408329 100644 --- a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts +++ b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts @@ -21,8 +21,8 @@ export class WsHandler extends BaseHandler implements Handler { >(); // retry configuration - private retryIntervalBase: number = 3; - private retryCounter: number = 5; + private retryIntervalBase: number = 2; + private retryCounter: number = 3; private initialRetryCounter = this.retryCounter; private retryTimeoutId: NodeJS.Timeout; @@ -34,38 +34,16 @@ export class WsHandler extends BaseHandler implements Handler { logging } = options; - this.connection = new WebSocket(url.toString(), { - origin, - headers: this.headers - }); - // `nodebuffer` is already the default, but I just wanted to be explicit - // here because when `nodebuffer` is the binaryType the `message` event's - // data type is guaranteed to be a `Buffer`. We don't need to check for - // different types of data. - // I mention all this because if `arraybuffer` or `fragment` is used for the - // binaryType the `"message"` event's `data` may end up being - // `ArrayBuffer | Buffer`, or `Buffer[] | Buffer`, respectively. - // If you need to change this, you probably need to change our `onMessage` - // handler too. - this.connection.binaryType = "nodebuffer"; - - this.open = this.connect(this.connection, logging); + this.open = this.connect(url.toString(), origin, logging); this.connection.onclose = () => { // try to connect again... // backoff and eventually fail - if( this.retryCounter > 0 || this.retryCounter == -1 ) { - if( this.retryCounter !== -1 ) this.retryCounter--; + if( this.retryCounter > 0 ) { clearTimeout( this.retryTimeoutId ); this.retryTimeoutId = setTimeout( () => { - const onCloseEvent = this.connection.onclose; - this.connection = new WebSocket(url.toString(), { - origin, - headers: this.headers - }); - this.connection.binaryType = "nodebuffer"; - this.connection.onclose = onCloseEvent; - this.open = this.connect(this.connection, logging); + this.reconnect(url.toString(), origin, logging); }, Math.pow( this.retryIntervalBase, this.initialRetryCounter - this.retryCounter ) * 1000 ); + this.retryCounter--; } }; this.abortSignal.addEventListener("abort", () => { @@ -123,17 +101,32 @@ export class WsHandler extends BaseHandler implements Handler { } private connect( - connection: WebSocket, + url: string, + origin: string, logging: EthereumInternalOptions["logging"] ) { + this.connection = new WebSocket(url, { + origin, + headers: this.headers + }); + // `nodebuffer` is already the default, but I just wanted to be explicit + // here because when `nodebuffer` is the binaryType the `message` event's + // data type is guaranteed to be a `Buffer`. We don't need to check for + // different types of data. + // I mention all this because if `arraybuffer` or `fragment` is used for the + // binaryType the `"message"` event's `data` may end up being + // `ArrayBuffer | Buffer`, or `Buffer[] | Buffer`, respectively. + // If you need to change this, you probably need to change our `onMessage` + // handler too. + this.connection.binaryType = "nodebuffer"; let open = new Promise((resolve, reject) => { - connection.onopen = resolve; - connection.onerror = reject; + this.connection.onopen = resolve; + this.connection.onerror = reject; }); open.then( () => { - connection.onopen = null; - connection.onerror = null; + this.connection.onopen = null; + this.connection.onerror = null; // reset the retry counter this.retryCounter = this.initialRetryCounter; }, @@ -144,6 +137,14 @@ export class WsHandler extends BaseHandler implements Handler { return open; } + private reconnect (url: string, + origin: string, + logging: EthereumInternalOptions["logging"]) { + const onCloseEvent = this.connection.onclose; + this.open = this.connect(url, origin, logging); + this.connection.onclose = onCloseEvent; + } + public async close() { await super.close(); this.connection.close(); From 1cf558cbe7f13c92a418f9f613f8b86d6e58b3ee Mon Sep 17 00:00:00 2001 From: satyajeetkolhapure Date: Fri, 9 Sep 2022 17:45:06 +0100 Subject: [PATCH 3/7] merged develop --- src/packages/ganache/npm-shrinkwrap.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/packages/ganache/npm-shrinkwrap.json b/src/packages/ganache/npm-shrinkwrap.json index 67c6cdfcc0..ba38087d2f 100644 --- a/src/packages/ganache/npm-shrinkwrap.json +++ b/src/packages/ganache/npm-shrinkwrap.json @@ -1,6 +1,6 @@ { "name": "ganache", - "version": "7.3.0", + "version": "7.4.1", "lockfileVersion": 1, "requires": true, "dependencies": { From cdb5368406f1ae7d05ab7b8623a1ab9483141883 Mon Sep 17 00:00:00 2001 From: satyajeetkolhapure Date: Fri, 9 Sep 2022 18:21:08 +0100 Subject: [PATCH 4/7] changed ganache version in shrinkstap --- src/packages/ganache/npm-shrinkwrap.json | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/packages/ganache/npm-shrinkwrap.json b/src/packages/ganache/npm-shrinkwrap.json index ba38087d2f..c69b456573 100644 --- a/src/packages/ganache/npm-shrinkwrap.json +++ b/src/packages/ganache/npm-shrinkwrap.json @@ -1,6 +1,6 @@ { "name": "ganache", - "version": "7.4.1", + "version": "7.4.3", "lockfileVersion": 1, "requires": true, "dependencies": { From 926e2137447d76db4ee1ca344e1f256edf1ace17 Mon Sep 17 00:00:00 2001 From: satyajeetkolhapure Date: Mon, 12 Dec 2022 14:22:02 +0000 Subject: [PATCH 5/7] added retry mechanism considering in flight requests --- .../src/forking/handlers/ws-handler.ts | 127 +++++++++++++----- .../tests/forking/handlers/ws-handler.test.ts | 79 +++++++++++ 2 files changed, 171 insertions(+), 35 deletions(-) create mode 100644 src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts diff --git a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts index 6a34408329..ecb1898425 100644 --- a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts +++ b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts @@ -9,6 +9,11 @@ import { JsonRpcResponse, JsonRpcError } from "@ganache/utils"; const { JSONRPC_PREFIX } = BaseHandler; +export type RetryConfiguration = { + retryIntervalBaseInSeconds: number; + retryCounter: number; +}; + export class WsHandler extends BaseHandler implements Handler { private open: Promise; private connection: WebSocket; @@ -20,37 +25,65 @@ export class WsHandler extends BaseHandler implements Handler { }> >(); + // queue requests when connection is closed. + private delayedRequestsQueue = []; + // flag to identify if adhoc reconnection attempt. + private adhocReconnectionRequest = false; + // retry configuration - private retryIntervalBase: number = 2; private retryCounter: number = 3; - private initialRetryCounter = this.retryCounter; + private retryIntervalBaseInSeconds: number = 2; + private initialRetryCounter: number; private retryTimeoutId: NodeJS.Timeout; - constructor(options: EthereumInternalOptions, abortSignal: AbortSignal) { + // socket configuration + private url: string; + private origin: string; + private logging: EthereumInternalOptions["logging"]; + + constructor( + options: EthereumInternalOptions, + abortSignal: AbortSignal, + retryConfiguration?: RetryConfiguration | undefined + ) { super(options, abortSignal); const { fork: { url, origin }, logging } = options; + this.url = url.toString(); + this.origin = origin; + this.logging = logging; + + // set retry configuration values + if (retryConfiguration) { + this.retryCounter = retryConfiguration.retryCounter; + this.initialRetryCounter = retryConfiguration.retryIntervalBaseInSeconds; + } + this.initialRetryCounter = this.retryCounter; - this.open = this.connect(url.toString(), origin, logging); - this.connection.onclose = () => { + const onCloseEvent = () => { // try to connect again... // backoff and eventually fail - if( this.retryCounter > 0 ) { - clearTimeout( this.retryTimeoutId ); - this.retryTimeoutId = setTimeout( () => { - this.reconnect(url.toString(), origin, logging); - }, Math.pow( this.retryIntervalBase, this.initialRetryCounter - this.retryCounter ) * 1000 ); - this.retryCounter--; - } + // do not schedule reconnection for adhoc reconnection requests + if (this.retryCounter === 0) { + throw new Error("Connection to Infura has failed. Try again"); + } else { + if (!this.adhocReconnectionRequest) { + this.retryCounter--; + clearTimeout(this.retryTimeoutId); + this.retryTimeoutId = setTimeout(async () => { + this.reconnect(this.url, this.origin, false); + }, Math.pow(this.retryIntervalBaseInSeconds, this.initialRetryCounter - this.retryCounter) * 1000); + } + } }; + this.open = this.connect(this.url, this.origin, onCloseEvent); this.abortSignal.addEventListener("abort", () => { this.connection.onclose = null; this.connection.close(1000); }); - this.connection.onmessage = this.onMessage.bind(this); } public async request( @@ -58,7 +91,14 @@ export class WsHandler extends BaseHandler implements Handler { params: unknown[], options = { disableCache: false } ) { - await this.open; + try { + await this.open; + } catch (er) { + this.logging.logger.log("Connection to Infura has failed"); + // skip the reconnection if connection is being made + if (this.connection.readyState !== this.connection.CONNECTING) + this.reconnect(this.url, this.origin, true); + } if (this.abortSignal.aborted) return Promise.reject(new AbortError()); const key = JSON.stringify({ method, params }); @@ -76,7 +116,13 @@ export class WsHandler extends BaseHandler implements Handler { // Issue: https://github.com/trufflesuite/ganache/issues/3478 this.inFlightRequests.set(messageId, deferred); - this.connection.send(`${JSONRPC_PREFIX}${messageId},${key.slice(1)}`); + // if connection is alive send request else delay the request + const data = `${JSONRPC_PREFIX}${messageId},${key.slice(1)}`; + if (this.connection && this.connection.readyState === 1) { + this.connection.send(data); + } else { + this.delayRequest(data); + } return deferred.promise.finally(() => this.requestCache.delete(key)); }; return await this.queueRequest(method, params, key, send, options); @@ -100,11 +146,7 @@ export class WsHandler extends BaseHandler implements Handler { } } - private connect( - url: string, - origin: string, - logging: EthereumInternalOptions["logging"] - ) { + private connect(url: string, origin: string, onCloseEvent: any) { this.connection = new WebSocket(url, { origin, headers: this.headers @@ -119,30 +161,45 @@ export class WsHandler extends BaseHandler implements Handler { // If you need to change this, you probably need to change our `onMessage` // handler too. this.connection.binaryType = "nodebuffer"; + this.connection.onclose = onCloseEvent; + this.connection.onmessage = this.onMessage.bind(this); let open = new Promise((resolve, reject) => { this.connection.onopen = resolve; this.connection.onerror = reject; }); - open.then( - () => { - this.connection.onopen = null; - this.connection.onerror = null; - // reset the retry counter - this.retryCounter = this.initialRetryCounter; - }, - err => { - logging.logger.log(err); - } - ); + open.then(() => { + this.connection.onopen = null; + this.connection.onerror = null; + // reset the retry counter and any timeouts scheduled for retries + this.retryCounter = this.initialRetryCounter; + clearTimeout(this.retryTimeoutId); + + this.adhocReconnectionRequest = false; + // process delayed requests which were queued at the time of connection failure + this.sendDelayedRequests(); + }); return open; } - private reconnect (url: string, + private reconnect( + url: string, origin: string, - logging: EthereumInternalOptions["logging"]) { + adhocReconnectionRequest: boolean = false + ) { + this.adhocReconnectionRequest = adhocReconnectionRequest; const onCloseEvent = this.connection.onclose; - this.open = this.connect(url, origin, logging); - this.connection.onclose = onCloseEvent; + this.open = this.connect(url, origin, onCloseEvent); + } + + private delayRequest(request: any) { + this.delayedRequestsQueue.push(request); + } + + private sendDelayedRequests() { + while (this.delayedRequestsQueue.length > 0) { + const request = this.delayedRequestsQueue.pop(); + this.connection.send(request); + } } public async close() { diff --git a/src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts b/src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts new file mode 100644 index 0000000000..0b5e039790 --- /dev/null +++ b/src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts @@ -0,0 +1,79 @@ +import assert from "assert"; +import AbortController from "abort-controller"; +import { WsHandler } from "../../../src/forking/handlers/ws-handler"; +import { + EthereumOptionsConfig, + EthereumProviderOptions +} from "@ganache/ethereum-options"; +import WebSocket from "ws"; + +const createWebSocketServer = (port: number): WebSocket.Server => { + let wsServer = new WebSocket.Server({ port }); + wsServer.on("connection", async ws => { + ws.on("message", data => { + const message = JSON.parse(data.toString()); + ws.send( + Buffer.from( + JSON.stringify({ + id: message.id, + jsonrpc: "2.0", + result: "0x0" + }), + "utf-8" + ) + ); + if (message.method === "client-disconnect") { + setTimeout(() => { + ws.terminate(); + }, 10); + } + }); + }); + return wsServer; +}; + +// create test server +const URL = "ws://localhost:1001/"; +let wsServer: WebSocket.Server; +let wsHandler: WsHandler; +wsServer = createWebSocketServer(1001); + +describe("ws-handler", function () { + describe("retries", function () { + before(() => { + const providerOptions = EthereumOptionsConfig.normalize({ + fork: { + url: URL, + origin: "test" + } + } as EthereumProviderOptions); + const abortController: AbortController = new AbortController(); + wsHandler = new WsHandler(providerOptions, abortController.signal, { + retryCounter: 4, + retryIntervalBaseInSeconds: 3 + }); + }); + + after(() => { + wsHandler.close(); + wsServer.close(); + }); + + it("should attempt to reconnect the server when connection is terminated", async () => { + // send a request to websocket server to get connection termination. + await wsHandler.request("client-disconnect", [], { + disableCache: true + }); + await new Promise(resolve => setTimeout(resolve, 100)); + + // send request after connection is terminated + const retryPromise = wsHandler.request("retry", [], { + disableCache: true + }); + + // assert the result + const response = await retryPromise; + assert.equal(response, "0x0"); + }).timeout(10000); + }); +}); From 848bf46fe946a422a498ba4aa061db2539ddba82 Mon Sep 17 00:00:00 2001 From: satyajeetkolhapure Date: Tue, 13 Dec 2022 13:10:27 +0000 Subject: [PATCH 6/7] changed port in ws-handler tests --- .../ethereum/tests/forking/handlers/ws-handler.test.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts b/src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts index 0b5e039790..6008b06cf0 100644 --- a/src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts +++ b/src/chains/ethereum/ethereum/tests/forking/handlers/ws-handler.test.ts @@ -33,10 +33,10 @@ const createWebSocketServer = (port: number): WebSocket.Server => { }; // create test server -const URL = "ws://localhost:1001/"; +const URL = "ws://localhost:8888/"; let wsServer: WebSocket.Server; let wsHandler: WsHandler; -wsServer = createWebSocketServer(1001); +wsServer = createWebSocketServer(8888); describe("ws-handler", function () { describe("retries", function () { From c9f24bc6e00c91893cb823a962c38193867e9b45 Mon Sep 17 00:00:00 2001 From: satyajeetkolhapure Date: Tue, 13 Dec 2022 14:27:13 +0000 Subject: [PATCH 7/7] logged error instead of throwing --- src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts index ecb1898425..4dc81c9b3f 100644 --- a/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts +++ b/src/chains/ethereum/ethereum/src/forking/handlers/ws-handler.ts @@ -68,7 +68,7 @@ export class WsHandler extends BaseHandler implements Handler { // backoff and eventually fail // do not schedule reconnection for adhoc reconnection requests if (this.retryCounter === 0) { - throw new Error("Connection to Infura has failed. Try again"); + this.logging.logger.log("Connection to Infura has failed. Try again"); } else { if (!this.adhocReconnectionRequest) { this.retryCounter--;