Merge branch 'fix/request-node-logging' of https://github.com/RequestNetwork/requestNetwork into fix/request-node-logging

Author: rodrigopavezi

README.md

@@ -83,6 +83,12 @@ Test all the packages in the monorepo.
 yarn run test
 ```
 
+Test a specific package by replacing `@requestnetwork/request-client.js` with the desired package name:
+
+```bash
+yarn workspace @requestnetwork/request-client.js test
+```
+
 ## License
 
 [MIT](https://github.com/RequestNetwork/requestNetwork/blob/master/LICENSE)

packages/request-client.js/src/http-config-defaults.ts

@@ -6,10 +6,12 @@ const config: ClientTypes.IHttpDataAccessConfig = {
   httpRequestRetryDelay: 100,
   httpRequestExponentialBackoffDelay: 0,
   httpRequestMaxExponentialBackoffDelay: 30000,
-  getConfirmationMaxRetry: 30,
-  getConfirmationRetryDelay: 1000,
-  getConfirmationExponentialBackoffDelay: 0,
-  getConfirmationMaxExponentialBackoffDelay: 30000,
+
+  // Exponential backoff starting at 1s, doubling after each retry, up to a maximum of 64s and max 7 retries with an initial 3s defer delay, yielding a total of 8 calls and total timeout of 130s
+  getConfirmationMaxRetry: 7,
+  getConfirmationRetryDelay: 0,
+  getConfirmationExponentialBackoffDelay: 1000,
+  getConfirmationMaxExponentialBackoffDelay: 64000,
   getConfirmationDeferDelay: 3000,
 };
 

packages/request-client.js/src/http-data-access.ts

@@ -98,8 +98,6 @@ export default class HttpDataAccess implements DataAccessTypes.IDataAccess {
       { channelId, topics, transactionData },
     );
 
-    const transactionHash: string = normalizeKeccak256Hash(transactionData).value;
-
     // Create the return result with EventEmitter
     const result: DataAccessTypes.IReturnPersistTransaction = Object.assign(
       new EventEmitter() as DataAccessTypes.PersistTransactionEmitter,
@@ -109,33 +107,15 @@ export default class HttpDataAccess implements DataAccessTypes.IDataAccess {
     // Try to get the confirmation
     new Promise((r) => setTimeout(r, this.httpConfig.getConfirmationDeferDelay))
       .then(async () => {
-        const confirmedData =
-          await this.fetchAndRetry<DataAccessTypes.IReturnPersistTransactionRaw>(
-            '/getConfirmedTransaction',
-            {
-              transactionHash,
-            },
-            {
-              maxRetries: this.httpConfig.getConfirmationMaxRetry,
-              retryDelay: this.httpConfig.getConfirmationRetryDelay,
-              exponentialBackoffDelay: this.httpConfig.getConfirmationExponentialBackoffDelay,
-              maxExponentialBackoffDelay: this.httpConfig.getConfirmationMaxExponentialBackoffDelay,
-            },
-          );
+        const confirmedData = await this.getConfirmedTransaction(transactionData);
         // when found, emit the event 'confirmed'
         result.emit('confirmed', confirmedData);
       })
       .catch((e) => {
         let error: Error = e;
-        if (e.status === 404) {
+        if (e && 'status' in e && e.status === 404) {
           error = new Error(
-            `Transaction confirmation not received. Try polling
-          getTransactionsByChannelId() until the transaction is confirmed.
-          deferDelay: ${this.httpConfig.getConfirmationDeferDelay}ms,
-          maxRetries: ${this.httpConfig.getConfirmationMaxRetry},
-          retryDelay: ${this.httpConfig.getConfirmationRetryDelay}ms,
-          exponentialBackoffDelay: ${this.httpConfig.getConfirmationExponentialBackoffDelay}ms,
-          maxExponentialBackoffDelay: ${this.httpConfig.getConfirmationMaxExponentialBackoffDelay}ms`,
+            `Timeout while confirming the Request was persisted. It is likely that the Request will be confirmed eventually. Catch this error and use getConfirmedTransaction() to continue polling for confirmation. Adjusting the httpConfig settings on the RequestNetwork object to avoid future timeouts. Avoid calling persistTransaction() again to prevent creating a duplicate Request.`,
           );
         }
         result.emit('error', error);
@@ -144,6 +124,29 @@ export default class HttpDataAccess implements DataAccessTypes.IDataAccess {
     return result;
   }
 
+  /**
+   * Gets a transaction from the node through HTTP.
+   * @param transactionData The transaction data
+   */
+  public async getConfirmedTransaction(
+    transactionData: DataAccessTypes.ITransaction,
+  ): Promise<DataAccessTypes.IReturnPersistTransaction> {
+    const transactionHash: string = normalizeKeccak256Hash(transactionData).value;
+
+    return await this.fetchAndRetry(
+      '/getConfirmedTransaction',
+      {
+        transactionHash,
+      },
+      {
+        maxRetries: this.httpConfig.getConfirmationMaxRetry,
+        retryDelay: this.httpConfig.getConfirmationRetryDelay,
+        exponentialBackoffDelay: this.httpConfig.getConfirmationExponentialBackoffDelay,
+        maxExponentialBackoffDelay: this.httpConfig.getConfirmationMaxExponentialBackoffDelay,
+      },
+    );
+  }
+
   /**
    * Gets the transactions for a channel from the node through HTTP.
    *

packages/request-client.js/test/http-data-access.test.ts

@@ -29,22 +29,18 @@ describe('HttpDataAccess', () => {
           getConfirmationMaxRetry: 0,
         },
       });
-      await expect(
-        new Promise((resolve, reject) =>
-          httpDataAccess.persistTransaction({}, '', []).then((returnPersistTransaction) => {
-            returnPersistTransaction.on('confirmed', resolve);
-            returnPersistTransaction.on('error', reject);
-          }),
-        ),
-      ).rejects.toThrow(
-        new Error(`Transaction confirmation not received. Try polling
-          getTransactionsByChannelId() until the transaction is confirmed.
-          deferDelay: 0ms,
-          maxRetries: 0,
-          retryDelay: 1000ms,
-          exponentialBackoffDelay: 0ms,
-          maxExponentialBackoffDelay: 30000ms`),
-      );
+      const returnPersistTransaction = await httpDataAccess.persistTransaction({}, '', []);
+      await Promise.race([
+        new Promise<void>((resolve) => {
+          returnPersistTransaction.on('error', (e: any) => {
+            expect(e.message).toBe(
+              'Timeout while confirming the Request was persisted. It is likely that the Request will be confirmed eventually. Catch this error and use getConfirmedTransaction() to continue polling for confirmation. Adjusting the httpConfig settings on the RequestNetwork object to avoid future timeouts. Avoid calling persistTransaction() again to prevent creating a duplicate Request.',
+            );
+            resolve();
+          });
+        }),
+        new Promise((_, reject) => setTimeout(() => reject(new Error('Test timed out')), 5000)),
+      ]);
     });
   });
 });

packages/utils/src/retry.ts

@@ -61,7 +61,7 @@ const retry = <TParams extends unknown[], TReturn>(
             setTimeout(
               resolve,
               retryDelay +
-                Math.min(maxExponentialBackoffDelay, exponentialBackoffDelay * 2 ** retry),
+                Math.min(maxExponentialBackoffDelay, (exponentialBackoffDelay / 2) * 2 ** retry),
             ),
           );
 

packages/utils/test/retry.test.ts

@@ -131,38 +131,90 @@ describe('Retry', () => {
       throw new Error(`threw`);
     });
 
-    retry(throwFn, {
-      exponentialBackoffDelay: 1000,
-      maxExponentialBackoffDelay: 7000,
+    const retryPromise = retry(throwFn, {
+      retryDelay: 0,
+      // Exponential backoff starting at 1s, doubling after each retry, up to a maximum of 64s and max 7 retries, yielding a total of 8 call snad total timeout of 127s
+      maxRetries: 7,
+      exponentialBackoffDelay: 1000, // 1s
+      maxExponentialBackoffDelay: 64000, // 64s
     })();
 
-    // Should call immediately
+    // Should call immediately (1 total calls, 0ms total elapsed)
     expect(throwFn).toHaveBeenCalledTimes(1);
 
-    // Exponential backoff should only call a second time after 2000ms
-    jest.advanceTimersByTime(1100);
+    expect(Date.now()).toBe(0);
+
+    // 1st retry after 1s (2 total calls, 1000ms total elapsed)
+    jest.advanceTimersByTime(999);
     await Promise.resolve();
     expect(throwFn).toHaveBeenCalledTimes(1);
-    jest.advanceTimersByTime(1100);
+    jest.advanceTimersByTime(1);
     await Promise.resolve();
     expect(throwFn).toHaveBeenCalledTimes(2);
+    expect(Date.now()).toBe(1000);
+
+    // 2nd retry after 3s (3 total calls, 3000ms total elapsed)
+    jest.advanceTimersByTime(1999);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(2);
+    jest.advanceTimersByTime(1);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(3);
+    expect(Date.now()).toBe(3000);
 
-    // Exponential backoff should call a third time after 4100ms
-    jest.advanceTimersByTime(4100);
+    // 3rd retry after 4s (4 total calls, 7000ms total elapsed)
+    jest.advanceTimersByTime(3999);
     await Promise.resolve();
     expect(throwFn).toHaveBeenCalledTimes(3);
+    jest.advanceTimersByTime(1);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(4);
+    expect(Date.now()).toBe(7000);
 
-    // Exponential backoff should call a fourth time after 7100ms
-    // since maxExponentialBackoffDelay (7000) < 8000
-    jest.advanceTimersByTime(7100);
+    // 4th retry after 8s (5 total calls, 15000ms total elapsed)
+    jest.advanceTimersByTime(7999);
     await Promise.resolve();
     expect(throwFn).toHaveBeenCalledTimes(4);
+    jest.advanceTimersByTime(1);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(5);
+    expect(Date.now()).toBe(15000);
 
-    // Exponential backoff should call a fifth time after 7100ms
-    // since maxExponentialBackoffDelay (7000) < 8000
-    jest.advanceTimersByTime(7100);
+    // 5th retry after 16s (6 total calls, 31000ms total elapsed)
+    jest.advanceTimersByTime(15999);
     await Promise.resolve();
     expect(throwFn).toHaveBeenCalledTimes(5);
+    jest.advanceTimersByTime(1);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(6);
+    expect(Date.now()).toBe(31000);
+
+    // 6th retry after 32s (7 total calls, 63000ms total elapsed)
+    jest.advanceTimersByTime(31999);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(6);
+    jest.advanceTimersByTime(1);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(7);
+    expect(Date.now()).toBe(63000);
+
+    // 7th retry after 64s (8 total calls, 127000ms total elapsed)
+    jest.advanceTimersByTime(63999);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(7);
+    jest.advanceTimersByTime(1);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(8);
+    expect(Date.now()).toBe(127000);
+
+    // Reject and throw after the last retry
+    await expect(retryPromise).rejects.toThrow('threw');
+
+    // No further retries
+    jest.advanceTimersByTime(1000000000);
+    await Promise.resolve();
+    expect(throwFn).toHaveBeenCalledTimes(8);
+    expect(Date.now()).toBe(1000127000);
 
     jest.useRealTimers();
   });