Retry on failed request to mirror node (#679)

- Introduce axios-retry for retrying failed requests to the mirror node
- Add environmental variables for `delay` and `retry` counts ( 0 `retry` counts disables `axios-retry` )
- Change hbar rate limiter test to one which spends more. This increases the speed, because it's hitting limiter faster.
- Bump timeout for rata limiter acceptance tests, because ofter 240 seconds are not enough.
- Bump hbar rate limiter duration in local acceptance test, because it's failing otherwise.
- Set delays on several places, because some of the tests are hitting rate limit

Signed-off-by: georgi-l95 <[email protected]>

Author: georgi-l95

.env.example

@@ -17,4 +17,6 @@ HBAR_RATE_LIMIT_TINYBAR =
 HBAR_RATE_LIMIT_DURATION =
 RATE_LIMIT_DISABLED =
 ETH_GET_LOGS_BLOCK_RANGE_LIMIT =
-DEV_MODE =
+DEV_MODE =
+MIRROR_NODE_RETRIES =
+MIRROR_NODE_RETRY_DELAY =

README.md

@@ -81,10 +81,11 @@ HBAR_RATE_LIMIT_TINYBAR = 6000000000
 HBAR_RATE_LIMIT_DURATION = 60000
 RATE_LIMIT_DISABLED = false
 DEV_MODE = false
+MIRROR_NODE_RETRIES = 3
+MIRROR_NODE_RETRY_DELAY = 500
 ```
 
 Note: Read more about `DEV_MODE` [here](docs/dev-mode.md)
-
 The following table highlights some initial configuration values to consider
 
 | Config     | Default | Description                                                                                                                                                                      |

packages/relay/src/lib/clients/mirrorNodeClient.ts

@@ -24,6 +24,7 @@ import { Logger } from "pino";
 import constants from './../constants';
 import { Histogram, Registry } from 'prom-client';
 import { formatRequestIdMessage } from '../../formatters';
+import axiosRetry from 'axios-retry';
 
 export interface ILimitOrderParams {
     limit?: number;
@@ -104,7 +105,23 @@ export class MirrorNodeClient {
             },
             timeout: 10 * 1000
         });
-
+        //@ts-ignore
+        axiosRetry(axiosClient, {
+            retries: parseInt(process.env.MIRROR_NODE_RETRIES!) || 3,
+            retryDelay: (retryCount, error) => {
+                const request = error?.request?._header;
+                const requestId = request ? request.split('\n')[3].substring(11,47) : '';
+                const requestIdPrefix = formatRequestIdMessage(requestId);
+                const delay = (parseInt(process.env.MIRROR_NODE_RETRY_DELAY!) || 500);
+                this.logger.trace(`${requestIdPrefix} Retry delay ${delay} ms`);
+                return delay;
+            },
+            retryCondition: (error) => {
+                return !error?.response?.status || MirrorNodeClientError.retryErrorCodes.includes(error?.response?.status);
+            },
+            shouldResetTimeout: true
+        });
+        
         return axiosClient;
     }
 
@@ -148,7 +165,11 @@ export class MirrorNodeClient {
         const requestIdPrefix = formatRequestIdMessage(requestId);
         let ms;
         try {
-            const response = await this.client.get(path);
+            const response = await this.client.get(path, {
+                headers:{
+                    'requestId': requestId || ''
+                }
+            });
             ms = Date.now() - start;
             this.logger.debug(`${requestIdPrefix} [GET] ${path} ${response.status} ${ms} ms`);
             this.mirrorResponseHistogram.labels(pathLabel, response.status).observe(ms);
@@ -436,4 +457,9 @@ export class MirrorNodeClient {
 
         return null;
     }
+
+    //exposing mirror node instance for tests
+    public getMirrorNodeInstance(){
+        return this.client;
+    }
 }

packages/relay/src/lib/errors/MirrorNodeClientError.ts

@@ -22,6 +22,8 @@
 export class MirrorNodeClientError extends Error {
     public statusCode: number;
 
+    static retryErrorCodes: Array<number> = [400, 404, 408, 425, 500]
+
     static ErrorCodes = {
       ECONNABORTED: 504
     };

packages/relay/tests/lib/eth.spec.ts

@@ -85,20 +85,12 @@ describe('Eth calls using MirrorNode', async function () {
   let ethImpl: EthImpl;
 
   this.beforeAll(() => {
-    // mock axios
-    const instance = axios.create({
-      baseURL: 'https://localhost:5551/api/v1',
-      responseType: 'json' as const,
-      headers: {
-        'Content-Type': 'application/json'
-      },
-      timeout: 10 * 1000
-    });
-
     // @ts-ignore
-    mock = new MockAdapter(instance, { onNoMatch: "throwException" });
+    mirrorNodeInstance = new MirrorNodeClient(process.env.MIRROR_NODE_URL, logger.child({ name: `mirror-node` }), registry);
+
     // @ts-ignore
-    mirrorNodeInstance = new MirrorNodeClient(process.env.MIRROR_NODE_URL, logger.child({ name: `mirror-node` }), registry, instance);
+    mock = new MockAdapter(mirrorNodeInstance.getMirrorNodeInstance(), { onNoMatch: "throwException" });
+
     sdkClientStub = sinon.createStubInstance(SDKClient);
     cache = new LRU({
       max: constants.CACHE_MAX,
@@ -536,6 +528,65 @@ describe('Eth calls using MirrorNode', async function () {
     }
   });
 
+  it('"eth_blockNumber" return the latest block number on second try', async function () {
+    mock.onGet('blocks?limit=1&order=desc').replyOnce(404, {
+      '_status': {
+        'messages': [
+          {
+            'message': 'Block not found'
+          }
+        ]
+      }
+    }).onGet('blocks?limit=1&order=desc').replyOnce(200, {
+      blocks: [defaultBlock]
+    });
+
+    const blockNumber = await ethImpl.blockNumber();
+    expect(blockNumber).to.be.eq(blockNumber);
+  });
+
+  it('"eth_blockNumber" should throw an error if no blocks are found after third try', async function () {
+    mock.onGet('blocks?limit=1&order=desc').replyOnce(404, {
+      '_status': {
+        'messages': [
+          {
+            'message': 'Block not found'
+          }
+        ]
+      }
+    }).onGet('blocks?limit=1&order=desc').replyOnce(404, {
+      '_status': {
+        'messages': [
+          {
+            'message': 'Block not found'
+          }
+        ]
+      }
+    }).onGet('blocks?limit=1&order=desc').replyOnce(404, {
+      '_status': {
+        'messages': [
+          {
+            'message': 'Block not found'
+          }
+        ]
+      }
+    }).onGet('blocks?limit=1&order=desc').replyOnce(404, {
+      '_status': {
+        'messages': [
+          {
+            'message': 'Block not found'
+          }
+        ]
+      }
+    });
+
+    try {
+      await ethImpl.blockNumber();
+    } catch (error: any) {
+      expect(error.message).to.equal('Error encountered retrieving latest block');
+    }
+  });
+
   it('eth_getBlockByNumber with match', async function () {
     // mirror node request mocks
     mock.onGet(`blocks/${blockNumber}`).reply(200, defaultBlock);

packages/server/tests/acceptance/htsPrecompile/tokenCreate.spec.ts

@@ -173,6 +173,9 @@ describe('@tokencreate HTS Precompile Token Create Acceptance Tests', async func
   });
 
   it('should associate to a token with custom fees', async function() {
+    //delay for hbar rate limiter to reset
+    await new Promise(r => setTimeout(r, parseInt(process.env.HBAR_RATE_LIMIT_DURATION!)));
+
     const mainContractOwner = new ethers.Contract(mainContractAddress, TokenCreateJson.abi, accounts[0].wallet);
     const txCO = await mainContractOwner.associateTokenPublic(mainContractAddress, HTSTokenWithCustomFeesContractAddress, { gasLimit: 10000000 });
     expect((await txCO.wait()).events.filter(e => e.event === 'ResponseCode')[0].args.responseCode).to.equal(TX_SUCCESS_CODE);

packages/server/tests/acceptance/htsPrecompile/tokenManagement.spec.ts

@@ -136,6 +136,9 @@ describe('@tokenmanagement HTS Precompile Token Management Acceptance Tests', as
     let tokenAddress, tokenContract, nftAddress;
 
     before(async function() {
+      //delay for hbar rate limiter to reset
+      await new Promise(r => setTimeout(r, parseInt(process.env.HBAR_RATE_LIMIT_DURATION!)));
+
       // Create token and nft contracts
       tokenAddress = await createHTSToken();
       nftAddress = await createNftHTSToken();
@@ -562,8 +565,8 @@ describe('@tokenmanagement HTS Precompile Token Management Acceptance Tests', as
       expect(tokenExpiryInfoAfter.autoRenewPeriod).to.equal(expiryInfo.autoRenewPeriod);
       expect(newRenewAccountEvmAddress.toLowerCase()).to.equal(expectedRenewAddress.toLowerCase());
 
-      //use close to with delta 300 seconds, because we don't know the exact second it was set to expiry
-      expect(tokenExpiryInfoAfter.second).to.be.closeTo(epoch, 300);
+      //use close to with delta 400 seconds, because we don't know the exact second it was set to expiry
+      expect(tokenExpiryInfoAfter.second).to.be.closeTo(epoch, 400);
     });
 
     it('should be able to get and update non fungible token expiry info', async function() {
@@ -605,8 +608,8 @@ describe('@tokenmanagement HTS Precompile Token Management Acceptance Tests', as
       expect(tokenExpiryInfoAfter.autoRenewPeriod).to.equal(expiryInfo.autoRenewPeriod);
       expect(newRenewAccountEvmAddress.toLowerCase()).to.equal(expectedRenewAddress.toLowerCase());
 
-      //use close to with delta 300 seconds, because we don't know the exact second it was set to expiry
-      expect(tokenExpiryInfoAfter.second).to.be.closeTo(epoch, 300);
+      //use close to with delta 400 seconds, because we don't know the exact second it was set to expiry
+      expect(tokenExpiryInfoAfter.second).to.be.closeTo(epoch, 400);
     });
   });
 

packages/server/tests/acceptance/rateLimiter.spec.ts

@@ -29,9 +29,10 @@ import { ContractFunctionParameters } from '@hashgraph/sdk';
 import parentContractJson from '../contracts/Parent.json';
 import { predefined } from '@hashgraph/json-rpc-relay/src/lib/errors/JsonRpcError';
 import { Utils } from '../helpers/utils';
+import BaseHTSJson from '../contracts/contracts_v1/BaseHTS.json';
 
 describe('@ratelimiter Rate Limiters Acceptance Tests', function () {
-    this.timeout(240 * 1000); // 240 seconds
+    this.timeout(480 * 1000); // 480 seconds
 
     const accounts: AliasAccount[] = [];
 
@@ -87,15 +88,16 @@ describe('@ratelimiter Rate Limiters Acceptance Tests', function () {
     });
 
     describe('HBAR Limiter Acceptance Tests', function () {
-        this.timeout(240 * 1000); // 240 seconds
+        this.timeout(480 * 1000); // 480 seconds
 
         this.beforeAll(async () => {
             requestId = Utils.generateRequestId();
             const requestIdPrefix = Utils.formatRequestIdMessage(requestId);
 
             logger.info(`${requestIdPrefix} Creating accounts`);
-            accounts[0] = await servicesNode.createAliasAccount(15, null, requestId);
-            accounts[1] = await servicesNode.createAliasAccount(100, null, requestId);
+            logger.info(`${requestIdPrefix} HBAR_RATE_LIMIT_TINYBAR: ${process.env.HBAR_RATE_LIMIT_TINYBAR}`);
+            accounts[0] = await servicesNode.createAliasAccount(15, relay.provider, requestId);
+            accounts[1] = await servicesNode.createAliasAccount(200, relay.provider, requestId);
             contractId = await accounts[0].client.createParentContract(parentContractJson, requestId);
 
             const params = new ContractFunctionParameters().addUint256(1);
@@ -126,22 +128,24 @@ describe('@ratelimiter Rate Limiters Acceptance Tests', function () {
                 type: 2
             };
 
+            async function deployBaseHTSContract() {
+                const baseHTSFactory = new ethers.ContractFactory(BaseHTSJson.abi, BaseHTSJson.bytecode, accounts[1].wallet);
+                const baseHTS = await baseHTSFactory.deploy({gasLimit: 10_000_000});
+                const { contractAddress } = await baseHTS.deployTransaction.wait();
+            
+                return contractAddress;
+              }
+
             it('should fail to execute "eth_sendRawTransaction" due to HBAR rate limit exceeded ', async function () {
                 await new Promise(r => setTimeout(r, parseInt(process.env.HBAR_RATE_LIMIT_DURATION!)));
+                const requestIdPrefix = Utils.formatRequestIdMessage(requestId);
+
                 let rateLimit = false;
                 try {
                     for (let index = 0; index < parseInt(process.env.TIER_1_RATE_LIMIT!) * 2; index++) {
-                        const gasPrice = await relay.gasPrice(requestId);
-
-                        const transaction = {
-                            ...defaultLondonTransactionData,
-                            to: mirrorContract.evm_address,
-                            nonce: await relay.getAccountNonce(accounts[1].address, requestId),
-                            maxPriorityFeePerGas: gasPrice,
-                            maxFeePerGas: gasPrice,
-                        };
-                        const signedTx = await accounts[1].wallet.signTransaction(transaction);
-                        await relay.call('eth_sendRawTransaction', [signedTx], requestId);
+                        const BaseHTSContractAddress = await deployBaseHTSContract();
+                        const baseHTSContract = new ethers.Contract(BaseHTSContractAddress, BaseHTSJson.abi, accounts[0].wallet);
+                        logger.info(`${requestIdPrefix} Contract deployed to ${baseHTSContract.address}`);
                         await new Promise(r => setTimeout(r, 1));
                     }
                 } catch (error) {

packages/server/tests/localAcceptance.env

@@ -19,7 +19,9 @@ TIER_1_RATE_LIMIT = 100
 TIER_2_RATE_LIMIT = 800
 TIER_3_RATE_LIMIT = 1600
 LIMIT_DURATION = 60000
-HBAR_RATE_LIMIT_TINYBAR = 15000000000
-HBAR_RATE_LIMIT_DURATION = 60000
-RATE_LIMIT_DISABLED=false
-DEV_MODE=false
+HBAR_RATE_LIMIT_TINYBAR = 11000000000
+HBAR_RATE_LIMIT_DURATION = 80000
+RATE_LIMIT_DISABLED = false
+DEV_MODE = false
+MIRROR_NODE_RETRIES = 3
+MIRROR_NODE_RETRY_DELAY = 500