From e2b3d2f032ab71f1a8266c5bba6266712eca51b2 Mon Sep 17 00:00:00 2001 From: belloibrahv Date: Tue, 5 Nov 2024 12:19:57 +0100 Subject: [PATCH] Fix bugs on PR Signed-off-by: belloibrahv --- .../src/lib/clients/cache/localLRUCache.ts | 32 +- .../relay/src/lib/clients/cache/redisCache.ts | 58 ++- .../relay/src/lib/clients/mirrorNodeClient.ts | 52 ++- packages/relay/src/lib/clients/sdkClient.ts | 36 +- .../config/hbarSpendingPlanConfigService.ts | 12 +- .../ethAddressHbarSpendingPlanRepository.ts | 28 +- .../hbarLimiter/hbarSpendingPlanRepository.ts | 68 ++-- .../ipAddressHbarSpendingPlanRepository.ts | 28 +- packages/relay/src/lib/eth.ts | 372 ++++++++++++------ packages/relay/src/lib/hbarlimiter/index.ts | 52 ++- packages/relay/src/lib/poller.ts | 12 +- packages/relay/src/lib/precheck.ts | 134 ++++--- .../src/lib/services/debugService/index.ts | 4 +- .../ethService/ethCommonService/index.ts | 10 +- .../ethService/ethFilterService/index.ts | 32 +- .../lib/services/hbarLimitService/index.ts | 74 ++-- .../services/metricService/metricService.ts | 8 +- .../relay/src/lib/subscriptionController.ts | 22 +- packages/relay/tests/redisInMemoryServer.ts | 14 +- packages/server/src/server.ts | 16 +- .../server/tests/clients/metricsClient.ts | 4 +- packages/server/tests/clients/mirrorClient.ts | 4 +- packages/server/tests/clients/relayClient.ts | 32 +- .../server/tests/clients/servicesClient.ts | 64 +-- packages/server/tests/helpers/assertions.ts | 8 +- packages/server/tests/helpers/utils.ts | 8 +- packages/ws-server/src/controllers/index.ts | 16 +- .../src/metrics/connectionLimiter.ts | 4 +- packages/ws-server/src/utils/utils.ts | 12 +- packages/ws-server/src/webSocketServer.ts | 8 +- 30 files changed, 802 insertions(+), 422 deletions(-) diff --git a/packages/relay/src/lib/clients/cache/localLRUCache.ts b/packages/relay/src/lib/clients/cache/localLRUCache.ts index bccad80b12..da4d35e657 100644 --- a/packages/relay/src/lib/clients/cache/localLRUCache.ts +++ b/packages/relay/src/lib/clients/cache/localLRUCache.ts @@ -109,7 +109,9 @@ export class LocalLRUCache implements ICacheClient { const censoredKey = key.replace(Utils.IP_ADDRESS_REGEX, ''); const censoredValue = JSON.stringify(value).replace(/"ipAddress":"[^"]+"/, '"ipAddress":""'); const message = `Returning cached value ${censoredKey}:${censoredValue} on ${callingMethod} call`; - this.logger.trace(`${requestDetails.formattedRequestId} ${message}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} ${message}`); + } return value; } @@ -125,9 +127,11 @@ export class LocalLRUCache implements ICacheClient { */ public async getRemainingTtl(key: string, callingMethod: string, requestDetails: RequestDetails): Promise { const remainingTtl = this.cache.getRemainingTTL(key); // in milliseconds - this.logger.trace( - `${requestDetails.formattedRequestId} returning remaining TTL ${key}:${remainingTtl} on ${callingMethod} call`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} returning remaining TTL ${key}:${remainingTtl} on ${callingMethod} call`, + ); + } return remainingTtl; } @@ -158,9 +162,11 @@ export class LocalLRUCache implements ICacheClient { const message = `Caching ${censoredKey}:${censoredValue} on ${callingMethod} for ${ resolvedTtl > 0 ? `${resolvedTtl} ms` : 'indefinite time' }`; - this.logger.trace( - `${requestDetails.formattedRequestId} ${message} (cache size: ${this.cache.size}, max: ${this.options.max})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} ${message} (cache size: ${this.cache.size}, max: ${this.options.max})`, + ); + } } /** @@ -211,7 +217,9 @@ export class LocalLRUCache implements ICacheClient { * @param {RequestDetails} requestDetails - The request details for logging and tracking. */ public async delete(key: string, callingMethod: string, requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} delete cache for ${key}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} delete cache for ${key}`); + } this.cache.delete(key); } @@ -267,9 +275,11 @@ export class LocalLRUCache implements ICacheClient { const matchingKeys = keys.filter((key) => regex.test(key)); - this.logger.trace( - `${requestDetails.formattedRequestId} retrieving keys matching ${pattern} on ${callingMethod} call`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} retrieving keys matching ${pattern} on ${callingMethod} call`, + ); + } return matchingKeys; } } diff --git a/packages/relay/src/lib/clients/cache/redisCache.ts b/packages/relay/src/lib/clients/cache/redisCache.ts index 1961374604..e6df1fd975 100644 --- a/packages/relay/src/lib/clients/cache/redisCache.ts +++ b/packages/relay/src/lib/clients/cache/redisCache.ts @@ -137,7 +137,9 @@ export class RedisCache implements IRedisCacheClient { const censoredKey = key.replace(Utils.IP_ADDRESS_REGEX, ''); const censoredValue = result.replace(/"ipAddress":"[^"]+"/, '"ipAddress":""'); const message = `Returning cached value ${censoredKey}:${censoredValue} on ${callingMethod} call`; - this.logger.trace(`${requestDetails.formattedRequestId} ${message}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} ${message}`); + } // TODO: add metrics return JSON.parse(result); } @@ -175,7 +177,9 @@ export class RedisCache implements IRedisCacheClient { const message = `Caching ${censoredKey}:${censoredValue} on ${callingMethod} for ${ resolvedTtl > 0 ? `${resolvedTtl} ms` : 'indefinite time' }`; - this.logger.trace(`${requestDetails.formattedRequestId} ${message}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} ${message}`); + } // TODO: add metrics } @@ -204,9 +208,11 @@ export class RedisCache implements IRedisCacheClient { // Log the operation const entriesLength = Object.keys(keyValuePairs).length; - this.logger.trace( - `${requestDetails.formattedRequestId} caching multiple keys via ${callingMethod}, total keys: ${entriesLength}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} caching multiple keys via ${callingMethod}, total keys: ${entriesLength}`, + ); + } } /** @@ -239,9 +245,11 @@ export class RedisCache implements IRedisCacheClient { // Log the operation const entriesLength = Object.keys(keyValuePairs).length; - this.logger.trace( - `${requestDetails.formattedRequestId} caching multiple keys via ${callingMethod}, total keys: ${entriesLength}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} caching multiple keys via ${callingMethod}, total keys: ${entriesLength}`, + ); + } } /** @@ -255,7 +263,9 @@ export class RedisCache implements IRedisCacheClient { async delete(key: string, callingMethod: string, requestDetails: RequestDetails): Promise { const client = await this.getConnectedClient(); await client.del(key); - this.logger.trace(`${requestDetails.formattedRequestId} delete cache for ${key} on ${callingMethod} call`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} delete cache for ${key} on ${callingMethod} call`); + } // TODO: add metrics } @@ -323,7 +333,11 @@ export class RedisCache implements IRedisCacheClient { async incrBy(key: string, amount: number, callingMethod: string, requestDetails: RequestDetails): Promise { const client = await this.getConnectedClient(); const result = await client.incrBy(key, amount); - this.logger.trace(`${requestDetails.formattedRequestId} incrementing ${key} by ${amount} on ${callingMethod} call`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} incrementing ${key} by ${amount} on ${callingMethod} call`, + ); + } return result; } @@ -346,9 +360,11 @@ export class RedisCache implements IRedisCacheClient { ): Promise { const client = await this.getConnectedClient(); const result = await client.lRange(key, start, end); - this.logger.trace( - `${requestDetails.formattedRequestId} retrieving range [${start}:${end}] from ${key} on ${callingMethod} call`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} retrieving range [${start}:${end}] from ${key} on ${callingMethod} call`, + ); + } return result.map((item) => JSON.parse(item)); } @@ -365,9 +381,11 @@ export class RedisCache implements IRedisCacheClient { const client = await this.getConnectedClient(); const serializedValue = JSON.stringify(value); const result = await client.rPush(key, serializedValue); - this.logger.trace( - `${requestDetails.formattedRequestId} pushing ${serializedValue} to ${key} on ${callingMethod} call`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} pushing ${serializedValue} to ${key} on ${callingMethod} call`, + ); + } return result; } @@ -381,9 +399,11 @@ export class RedisCache implements IRedisCacheClient { async keys(pattern: string, callingMethod: string, requestDetails: RequestDetails): Promise { const client = await this.getConnectedClient(); const result = await client.keys(pattern); - this.logger.trace( - `${requestDetails.formattedRequestId} retrieving keys matching ${pattern} on ${callingMethod} call`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} retrieving keys matching ${pattern} on ${callingMethod} call`, + ); + } return result; } } diff --git a/packages/relay/src/lib/clients/mirrorNodeClient.ts b/packages/relay/src/lib/clients/mirrorNodeClient.ts index 9a45a91286..3801c4cf3e 100644 --- a/packages/relay/src/lib/clients/mirrorNodeClient.ts +++ b/packages/relay/src/lib/clients/mirrorNodeClient.ts @@ -228,7 +228,9 @@ export class MirrorNodeClient { const requestId = request ? request.split('\n')[3].substring(11, 47) : ''; const requestIdPrefix = formatRequestIdMessage(requestId); const delay = isDevMode ? mirrorNodeRetryDelayDevMode || 200 : mirrorNodeRetryDelay * retryCount; - this.logger.trace(`${requestIdPrefix} Retry delay ${delay} ms on '${error?.request?.path}'`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} Retry delay ${delay} ms on '${error?.request?.path}'`); + } return delay; }, retryCondition: (error) => { @@ -342,7 +344,9 @@ export class MirrorNodeClient { } const ms = Date.now() - start; - this.logger.debug(`${requestDetails.formattedRequestId} [${method}] ${path} ${response.status} ${ms} ms`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestDetails.formattedRequestId} [${method}] ${path} ${response.status} ${ms} ms`); + } this.mirrorResponseHistogram.labels(pathLabel, response.status?.toString()).observe(ms); return response.data; } catch (error: any) { @@ -399,17 +403,21 @@ export class MirrorNodeClient { const acceptedErrorResponses = MirrorNodeClient.acceptedErrorStatusesResponsePerRequestPathMap.get(pathLabel); if (error.response && acceptedErrorResponses?.includes(effectiveStatusCode)) { - this.logger.debug(`${requestIdPrefix} [${method}] ${path} ${effectiveStatusCode} status`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} [${method}] ${path} ${effectiveStatusCode} status`); + } return null; } // Contract Call returns 400 for a CONTRACT_REVERT but is a valid response, expected and should not be logged as error: if (pathLabel === MirrorNodeClient.CONTRACT_CALL_ENDPOINT && effectiveStatusCode === 400) { - this.logger.debug( - `${requestIdPrefix} [${method}] ${path} Contract Revert: ( StatusCode: '${effectiveStatusCode}', StatusText: '${ - error.response.statusText - }', Detail: '${JSON.stringify(error.response.detail)}',Data: '${JSON.stringify(error.response.data)}')`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} [${method}] ${path} Contract Revert: ( StatusCode: '${effectiveStatusCode}', StatusText: '${ + error.response.statusText + }', Detail: '${JSON.stringify(error.response.detail)}',Data: '${JSON.stringify(error.response.data)}')`, + ); + } } else { this.logger.error( new Error(error.message), @@ -437,9 +445,11 @@ export class MirrorNodeClient { if (page === pageMax) { // max page reached - this.logger.trace( - `${requestDetails.formattedRequestId} Max page reached ${pageMax} with ${results.length} results`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Max page reached ${pageMax} with ${results.length} results`, + ); + } throw predefined.PAGINATION_MAX(pageMax); } @@ -1282,11 +1292,13 @@ export class MirrorNodeClient { break; } - this.logger.trace( - `${requestDetails?.formattedRequestId} Repeating request ${methodName} with args ${JSON.stringify( - args, - )} retry count ${i} of ${repeatCount}. Waiting ${this.MIRROR_NODE_RETRY_DELAY} ms before repeating request`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails?.formattedRequestId} Repeating request ${methodName} with args ${JSON.stringify( + args, + )} retry count ${i} of ${repeatCount}. Waiting ${this.MIRROR_NODE_RETRY_DELAY} ms before repeating request`, + ); + } // Backoff before repeating request await new Promise((r) => setTimeout(r, this.MIRROR_NODE_RETRY_DELAY)); @@ -1314,9 +1326,11 @@ export class MirrorNodeClient { ): Promise { const formattedRequestId = requestDetails.formattedRequestId; - this.logger.trace( - `${formattedRequestId} Get transaction record via mirror node: transactionId=${transactionId}, txConstructorName=${txConstructorName}, callerName=${callerName}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${formattedRequestId} Get transaction record via mirror node: transactionId=${transactionId}, txConstructorName=${txConstructorName}, callerName=${callerName}`, + ); + } const transactionRecords = await this.repeatedRequest( this.getTransactionById.name, diff --git a/packages/relay/src/lib/clients/sdkClient.ts b/packages/relay/src/lib/clients/sdkClient.ts index 84b7c240f0..6ec7ef6833 100644 --- a/packages/relay/src/lib/clients/sdkClient.ts +++ b/packages/relay/src/lib/clients/sdkClient.ts @@ -539,9 +539,11 @@ export class SDKClient { const sdkClientError = new SDKClientError(e, e.message); if (sdkClientError.isTimeoutExceeded()) { const delay = retries * 1000; - this.logger.trace( - `${requestDetails.formattedRequestId} Contract call query failed with status ${sdkClientError.message}. Retrying again after ${delay} ms ...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Contract call query failed with status ${sdkClientError.message}. Retrying again after ${delay} ms ...`, + ); + } retries++; await new Promise((r) => setTimeout(r, delay)); continue; @@ -652,9 +654,11 @@ export class SDKClient { throw predefined.REQUEST_TIMEOUT; } - this.logger.debug( - `${requestIdPrefix} Fail to execute ${queryConstructorName} query: paymentTransactionId=${query.paymentTransactionId}, callerName=${callerName}, status=${sdkClientError.status}(${sdkClientError.status._code}), cost=${queryCost} tinybars`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Fail to execute ${queryConstructorName} query: paymentTransactionId=${query.paymentTransactionId}, callerName=${callerName}, status=${sdkClientError.status}(${sdkClientError.status._code}), cost=${queryCost} tinybars`, + ); + } throw sdkClientError; } finally { @@ -895,9 +899,11 @@ export class SDKClient { this.logger.warn(`${requestDetails.formattedRequestId} File ${fileId} is empty.`); throw new SDKClientError({}, `${requestDetails.formattedRequestId} Created file is empty. `); } - this.logger.trace( - `${requestDetails.formattedRequestId} Created file with fileId: ${fileId} and file size ${fileInfo.size}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Created file with fileId: ${fileId} and file size ${fileInfo.size}`, + ); + } } return fileId; @@ -945,7 +951,9 @@ export class SDKClient { ); if (fileInfo.isDeleted) { - this.logger.trace(`${requestDetails.formattedRequestId} Deleted file with fileId: ${fileId}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} Deleted file with fileId: ${fileId}`); + } } else { this.logger.warn(`${requestDetails.formattedRequestId} Fail to delete file with fileId: ${fileId} `); } @@ -1000,9 +1008,11 @@ export class SDKClient { let transactionFee: number = 0; let txRecordChargeAmount: number = 0; try { - this.logger.trace( - `${requestDetails.formattedRequestId} Get transaction record via consensus node: transactionId=${transactionId}, txConstructorName=${txConstructorName}, callerName=${callerName}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Get transaction record via consensus node: transactionId=${transactionId}, txConstructorName=${txConstructorName}, callerName=${callerName}`, + ); + } const transactionRecord = await new TransactionRecordQuery() .setTransactionId(transactionId) diff --git a/packages/relay/src/lib/config/hbarSpendingPlanConfigService.ts b/packages/relay/src/lib/config/hbarSpendingPlanConfigService.ts index 0ea851d1a9..7d2be689ce 100644 --- a/packages/relay/src/lib/config/hbarSpendingPlanConfigService.ts +++ b/packages/relay/src/lib/config/hbarSpendingPlanConfigService.ts @@ -108,7 +108,9 @@ export class HbarSpendingPlanConfigService { private loadSpendingPlansConfig(): SpendingPlanConfig[] { const configPath = findConfig(this.SPENDING_PLANS_CONFIG_FILE); if (!configPath || !fs.existsSync(configPath)) { - this.logger.trace(`Configuration file not found at path "${configPath ?? this.SPENDING_PLANS_CONFIG_FILE}"`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`Configuration file not found at path "${configPath ?? this.SPENDING_PLANS_CONFIG_FILE}"`); + } return []; } try { @@ -205,9 +207,11 @@ export class HbarSpendingPlanConfigService { requestDetails: RequestDetails, ): Promise { for (const planConfig of spendingPlanConfigs) { - this.logger.trace( - `Updating associations for HBAR spending plan '${planConfig.name}' with ID ${planConfig.id}...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `Updating associations for HBAR spending plan '${planConfig.name}' with ID ${planConfig.id}...`, + ); + } await this.deleteObsoleteEthAddressAssociations(planConfig, requestDetails); await this.deleteObsoleteIpAddressAssociations(planConfig, requestDetails); await this.updateEthAddressAssociations(planConfig, requestDetails); diff --git a/packages/relay/src/lib/db/repositories/hbarLimiter/ethAddressHbarSpendingPlanRepository.ts b/packages/relay/src/lib/db/repositories/hbarLimiter/ethAddressHbarSpendingPlanRepository.ts index 41076ca2b0..2ca2341dd7 100644 --- a/packages/relay/src/lib/db/repositories/hbarLimiter/ethAddressHbarSpendingPlanRepository.ts +++ b/packages/relay/src/lib/db/repositories/hbarLimiter/ethAddressHbarSpendingPlanRepository.ts @@ -94,9 +94,11 @@ export class EthAddressHbarSpendingPlanRepository { for (const key of keys) { const addressPlan = await this.cache.getAsync(key, callingMethod, requestDetails); if (addressPlan?.planId === planId) { - this.logger.trace( - `${requestDetails.formattedRequestId} Removing ETH address ${addressPlan.ethAddress} from HbarSpendingPlan with ID ${planId}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Removing ETH address ${addressPlan.ethAddress} from HbarSpendingPlan with ID ${planId}`, + ); + } await this.cache.delete(key, callingMethod, requestDetails); } } @@ -115,9 +117,11 @@ export class EthAddressHbarSpendingPlanRepository { if (!addressPlan) { throw new EthAddressHbarSpendingPlanNotFoundError(ethAddress); } - this.logger.trace( - `${requestDetails.formattedRequestId} Retrieved link between ETH address ${ethAddress} and HbarSpendingPlan with ID ${addressPlan.planId}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Retrieved link between ETH address ${ethAddress} and HbarSpendingPlan with ID ${addressPlan.planId}`, + ); + } return new EthAddressHbarSpendingPlan(addressPlan); } @@ -132,9 +136,11 @@ export class EthAddressHbarSpendingPlanRepository { async save(addressPlan: IEthAddressHbarSpendingPlan, requestDetails: RequestDetails, ttl: number): Promise { const key = this.getKey(addressPlan.ethAddress); await this.cache.set(key, addressPlan, 'save', requestDetails, ttl); - this.logger.trace( - `${requestDetails.formattedRequestId} Linked ETH address ${addressPlan.ethAddress} to HbarSpendingPlan with ID ${addressPlan.planId}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Linked ETH address ${addressPlan.ethAddress} to HbarSpendingPlan with ID ${addressPlan.planId}`, + ); + } } /** @@ -151,7 +157,9 @@ export class EthAddressHbarSpendingPlanRepository { const errorMessage = ethAddressPlan ? `Removed ETH address ${ethAddress} from HbarSpendingPlan with ID ${ethAddressPlan.planId}` : `Trying to remove ETH address ${ethAddress}, which is not linked to a spending plan`; - this.logger.trace(`${requestDetails.formattedRequestId} ${errorMessage}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} ${errorMessage}`); + } } /** diff --git a/packages/relay/src/lib/db/repositories/hbarLimiter/hbarSpendingPlanRepository.ts b/packages/relay/src/lib/db/repositories/hbarLimiter/hbarSpendingPlanRepository.ts index 71b7184afe..829e4f362c 100644 --- a/packages/relay/src/lib/db/repositories/hbarLimiter/hbarSpendingPlanRepository.ts +++ b/packages/relay/src/lib/db/repositories/hbarLimiter/hbarSpendingPlanRepository.ts @@ -61,7 +61,9 @@ export class HbarSpendingPlanRepository { if (!plan) { throw new HbarSpendingPlanNotFoundError(id); } - this.logger.trace(`${requestDetails.formattedRequestId} Retrieved subscription with ID ${id}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} Retrieved subscription with ID ${id}`); + } return { ...plan, createdAt: new Date(plan.createdAt), @@ -105,14 +107,18 @@ export class HbarSpendingPlanRepository { spendingHistory: [], amountSpent: 0, }; - this.logger.trace(`${requestDetails.formattedRequestId} Creating HbarSpendingPlan with ID ${plan.id}...`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} Creating HbarSpendingPlan with ID ${plan.id}...`); + } const key = this.getKey(plan.id); await this.cache.set(key, plan, 'create', requestDetails, ttl); return new HbarSpendingPlan(plan); } async delete(id: string, requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} Deleting HbarSpendingPlan with ID ${id}...`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} Deleting HbarSpendingPlan with ID ${id}...`); + } const key = this.getKey(id); await this.cache.delete(key, 'delete', requestDetails); } @@ -139,9 +145,11 @@ export class HbarSpendingPlanRepository { async getSpendingHistory(id: string, requestDetails: RequestDetails): Promise { await this.checkExistsAndActive(id, requestDetails); - this.logger.trace( - `${requestDetails.formattedRequestId} Retrieving spending history for HbarSpendingPlan with ID ${id}...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Retrieving spending history for HbarSpendingPlan with ID ${id}...`, + ); + } const key = this.getSpendingHistoryKey(id); const spendingHistory = await this.cache.lRange( key, @@ -163,9 +171,11 @@ export class HbarSpendingPlanRepository { async addAmountToSpendingHistory(id: string, amount: number, requestDetails: RequestDetails): Promise { await this.checkExistsAndActive(id, requestDetails); - this.logger.trace( - `${requestDetails.formattedRequestId} Adding ${amount} to spending history for HbarSpendingPlan with ID ${id}...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Adding ${amount} to spending history for HbarSpendingPlan with ID ${id}...`, + ); + } const key = this.getSpendingHistoryKey(id); const entry: IHbarSpendingRecord = { amount, timestamp: new Date() }; return this.cache.rPush(key, entry, 'addAmountToSpendingHistory', requestDetails); @@ -180,9 +190,11 @@ export class HbarSpendingPlanRepository { async getAmountSpent(id: string, requestDetails: RequestDetails): Promise { await this.checkExistsAndActive(id, requestDetails); - this.logger.trace( - `${requestDetails.formattedRequestId} Retrieving amountSpent for HbarSpendingPlan with ID ${id}...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Retrieving amountSpent for HbarSpendingPlan with ID ${id}...`, + ); + } const key = this.getAmountSpentKey(id); return this.cache .getAsync(key, 'getAmountSpent', requestDetails) @@ -194,15 +206,19 @@ export class HbarSpendingPlanRepository { * @returns {Promise} - A promise that resolves when the operation is complete. */ async resetAmountSpentOfAllPlans(requestDetails: RequestDetails): Promise { - this.logger.trace( - `${requestDetails.formattedRequestId} Resetting the \`amountSpent\` entries for all HbarSpendingPlans...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Resetting the \`amountSpent\` entries for all HbarSpendingPlans...`, + ); + } const callerMethod = this.resetAmountSpentOfAllPlans.name; const keys = await this.cache.keys(this.getAmountSpentKey('*'), callerMethod, requestDetails); await Promise.all(keys.map((key) => this.cache.delete(key, callerMethod, requestDetails))); - this.logger.trace( - `${requestDetails.formattedRequestId} Successfully reset ${keys.length} "amountSpent" entries for HbarSpendingPlans.`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Successfully reset ${keys.length} "amountSpent" entries for HbarSpendingPlans.`, + ); + } } /** @@ -218,14 +234,18 @@ export class HbarSpendingPlanRepository { const key = this.getAmountSpentKey(id); if (!(await this.cache.getAsync(key, 'addToAmountSpent', requestDetails))) { - this.logger.trace( - `${requestDetails.formattedRequestId} No spending yet for HbarSpendingPlan with ID ${id}, setting amountSpent to ${amount}...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} No spending yet for HbarSpendingPlan with ID ${id}, setting amountSpent to ${amount}...`, + ); + } await this.cache.set(key, amount, 'addToAmountSpent', requestDetails, ttl); } else { - this.logger.trace( - `${requestDetails.formattedRequestId} Adding ${amount} to amountSpent for HbarSpendingPlan with ID ${id}...`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Adding ${amount} to amountSpent for HbarSpendingPlan with ID ${id}...`, + ); + } await this.cache.incrBy(key, amount, 'addToAmountSpent', requestDetails); } } diff --git a/packages/relay/src/lib/db/repositories/hbarLimiter/ipAddressHbarSpendingPlanRepository.ts b/packages/relay/src/lib/db/repositories/hbarLimiter/ipAddressHbarSpendingPlanRepository.ts index 5e6892b1f5..fc2705746b 100644 --- a/packages/relay/src/lib/db/repositories/hbarLimiter/ipAddressHbarSpendingPlanRepository.ts +++ b/packages/relay/src/lib/db/repositories/hbarLimiter/ipAddressHbarSpendingPlanRepository.ts @@ -94,9 +94,11 @@ export class IPAddressHbarSpendingPlanRepository { for (const key of keys) { const addressPlan = await this.cache.getAsync(key, callingMethod, requestDetails); if (addressPlan?.planId === planId) { - this.logger.trace( - `${requestDetails.formattedRequestId} Removing IP address from HbarSpendingPlan with ID ${planId}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Removing IP address from HbarSpendingPlan with ID ${planId}`, + ); + } await this.cache.delete(key, callingMethod, requestDetails); } } @@ -115,9 +117,11 @@ export class IPAddressHbarSpendingPlanRepository { if (!addressPlan) { throw new IPAddressHbarSpendingPlanNotFoundError(ipAddress); } - this.logger.trace( - `${requestDetails.formattedRequestId} Retrieved link between IP address and HbarSpendingPlan with ID ${addressPlan.planId}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Retrieved link between IP address and HbarSpendingPlan with ID ${addressPlan.planId}`, + ); + } return new IPAddressHbarSpendingPlan(addressPlan); } @@ -132,9 +136,11 @@ export class IPAddressHbarSpendingPlanRepository { async save(addressPlan: IIPAddressHbarSpendingPlan, requestDetails: RequestDetails, ttl: number): Promise { const key = this.getKey(addressPlan.ipAddress); await this.cache.set(key, addressPlan, 'save', requestDetails, ttl); - this.logger.trace( - `${requestDetails.formattedRequestId} Linked new IP address to HbarSpendingPlan with ID ${addressPlan.planId}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Linked new IP address to HbarSpendingPlan with ID ${addressPlan.planId}`, + ); + } } /** @@ -151,7 +157,9 @@ export class IPAddressHbarSpendingPlanRepository { const errorMessage = ipAddressSpendingPlan ? `Removed IP address from HbarSpendingPlan with ID ${ipAddressSpendingPlan.planId}` : `Trying to remove an IP address, which is not linked to a spending plan`; - this.logger.trace(`${requestDetails.formattedRequestId} ${errorMessage}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} ${errorMessage}`); + } } /** diff --git a/packages/relay/src/lib/eth.ts b/packages/relay/src/lib/eth.ts index 1735fa0b34..3f63d67b55 100644 --- a/packages/relay/src/lib/eth.ts +++ b/packages/relay/src/lib/eth.ts @@ -306,7 +306,9 @@ export class EthImpl implements Eth { * with the behavior of Infura. */ accounts(requestDetails: RequestDetails): never[] { - this.logger.trace(`${requestDetails.formattedRequestId} accounts()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} accounts()`); + } return EthImpl.accounts; } @@ -332,9 +334,11 @@ export class EthImpl implements Eth { ? constants.DEFAULT_FEE_HISTORY_MAX_RESULTS : Number(process.env.FEE_HISTORY_MAX_RESULTS); - this.logger.trace( - `${requestIdPrefix} feeHistory(blockCount=${blockCount}, newestBlock=${newestBlock}, rewardPercentiles=${rewardPercentiles})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} feeHistory(blockCount=${blockCount}, newestBlock=${newestBlock}, rewardPercentiles=${rewardPercentiles})`, + ); + } try { const latestBlockNumber = await this.translateBlockTag(EthImpl.blockLatest, requestDetails); @@ -487,9 +491,11 @@ export class EthImpl implements Eth { } if (_.isNil(networkFees)) { - this.logger.debug( - `${requestDetails.formattedRequestId} Mirror Node returned no network fees. Fallback to consensus node.`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestDetails.formattedRequestId} Mirror Node returned no network fees. Fallback to consensus node.`, + ); + } networkFees = { fees: [ { @@ -517,7 +523,9 @@ export class EthImpl implements Eth { * Gets the most recent block number. */ async blockNumber(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} blockNumber()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} blockNumber()`); + } return await this.common.getLatestBlockNumber(requestDetails); } @@ -525,7 +533,9 @@ export class EthImpl implements Eth { * Gets the most recent block number and timestamp.to which represents the block finality. */ async blockNumberTimestamp(caller: string, requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} blockNumber()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} blockNumber()`); + } const cacheKey = `${constants.CACHE_KEY.ETH_BLOCK_NUMBER}`; @@ -550,7 +560,9 @@ export class EthImpl implements Eth { * `CHAIN_ID`. */ chainId(requestDetails: RequestDetails): string { - this.logger.trace(`${requestDetails.formattedRequestId} chainId()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} chainId()`); + } return this.chain; } @@ -573,9 +585,11 @@ export class EthImpl implements Eth { .inc(); } - this.logger.trace( - `${requestIdPrefix} estimateGas(transaction=${JSON.stringify(transaction)}, _blockParam=${_blockParam})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} estimateGas(transaction=${JSON.stringify(transaction)}, _blockParam=${_blockParam})`, + ); + } try { const response = await this.estimateGasFromMirrorNode(transaction, requestDetails); @@ -742,7 +756,9 @@ export class EthImpl implements Eth { * @throws Will throw an error if unable to retrieve the gas price. */ async gasPrice(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} eth_gasPrice`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} eth_gasPrice`); + } try { let gasPrice: number | undefined = await this.cacheService.getAsync( constants.CACHE_KEY.GAS_PRICE, @@ -772,7 +788,9 @@ export class EthImpl implements Eth { * Gets whether this "Ethereum client" is a miner. We don't mine, so this always returns false. */ async mining(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} mining()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} mining()`); + } return false; } @@ -780,7 +798,9 @@ export class EthImpl implements Eth { * TODO Needs docs, or be removed? */ async submitWork(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} submitWork()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} submitWork()`); + } return false; } @@ -788,7 +808,9 @@ export class EthImpl implements Eth { * TODO Needs docs, or be removed? */ async syncing(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} syncing()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} syncing()`); + } return false; } @@ -796,7 +818,9 @@ export class EthImpl implements Eth { * Always returns null. There are no uncles in Hedera. */ async getUncleByBlockHashAndIndex(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} getUncleByBlockHashAndIndex()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} getUncleByBlockHashAndIndex()`); + } return null; } @@ -804,7 +828,9 @@ export class EthImpl implements Eth { * Always returns null. There are no uncles in Hedera. */ async getUncleByBlockNumberAndIndex(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} getUncleByBlockNumberAndIndex()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} getUncleByBlockNumberAndIndex()`); + } return null; } @@ -812,7 +838,9 @@ export class EthImpl implements Eth { * Always returns '0x0'. There are no uncles in Hedera. */ async getUncleCountByBlockHash(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} getUncleCountByBlockHash()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} getUncleCountByBlockHash()`); + } return EthImpl.zeroHex; } @@ -820,7 +848,9 @@ export class EthImpl implements Eth { * Always returns '0x0'. There are no uncles in Hedera. */ async getUncleCountByBlockNumber(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} getUncleCountByBlockNumber()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} getUncleCountByBlockNumber()`); + } return EthImpl.zeroHex; } @@ -828,7 +858,9 @@ export class EthImpl implements Eth { * TODO Needs docs, or be removed? */ async hashrate(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} hashrate()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} hashrate()`); + } return EthImpl.zeroHex; } @@ -836,7 +868,9 @@ export class EthImpl implements Eth { * Always returns UNSUPPORTED_METHOD error. */ getWork(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} getWork()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} getWork()`); + } return predefined.UNSUPPORTED_METHOD; } @@ -844,32 +878,44 @@ export class EthImpl implements Eth { * Unsupported methods always return UNSUPPORTED_METHOD error. */ submitHashrate(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} submitHashrate()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} submitHashrate()`); + } return predefined.UNSUPPORTED_METHOD; } signTransaction(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} signTransaction()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} signTransaction()`); + } return predefined.UNSUPPORTED_METHOD; } sign(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} sign()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} sign()`); + } return predefined.UNSUPPORTED_METHOD; } sendTransaction(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} sendTransaction()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} sendTransaction()`); + } return predefined.UNSUPPORTED_METHOD; } protocolVersion(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} protocolVersion()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} protocolVersion()`); + } return predefined.UNSUPPORTED_METHOD; } coinbase(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} coinbase()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} coinbase()`); + } return predefined.UNSUPPORTED_METHOD; } @@ -888,9 +934,11 @@ export class EthImpl implements Eth { blockNumberOrTagOrHash?: string | null, ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace( - `${requestIdPrefix} getStorageAt(address=${address}, slot=${slot}, blockNumberOrOrHashTag=${blockNumberOrTagOrHash})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} getStorageAt(address=${address}, slot=${slot}, blockNumberOrOrHashTag=${blockNumberOrTagOrHash})`, + ); + } let result = EthImpl.zeroHex32Byte; // if contract or slot not found then return 32 byte 0 @@ -944,7 +992,11 @@ export class EthImpl implements Eth { ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; const latestBlockTolerance = 1; - this.logger.trace(`${requestIdPrefix} getBalance(account=${account}, blockNumberOrTag=${blockNumberOrTagOrHash})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} getBalance(account=${account}, blockNumberOrTag=${blockNumberOrTagOrHash})`, + ); + } let latestBlock: LatestBlockNumberTimestamp | null | undefined; // this check is required, because some tools like Metamask pass for parameter latest block, with a number (ex 0x30ea) @@ -955,7 +1007,11 @@ export class EthImpl implements Eth { const blockNumberCached = await this.cacheService.getAsync(cacheKey, EthImpl.ethGetBalance, requestDetails); if (blockNumberCached) { - this.logger.trace(`${requestIdPrefix} returning cached value ${cacheKey}:${JSON.stringify(blockNumberCached)}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} returning cached value ${cacheKey}:${JSON.stringify(blockNumberCached)}`, + ); + } latestBlock = { blockNumber: blockNumberCached, timeStampTo: '0' }; } else { latestBlock = await this.blockNumberTimestamp(EthImpl.ethGetBalance, requestDetails); @@ -985,7 +1041,9 @@ export class EthImpl implements Eth { const cacheKey = `${constants.CACHE_KEY.ETH_GET_BALANCE}-${account}-${blockNumberOrTagOrHash}`; let cachedBalance = await this.cacheService.getAsync(cacheKey, EthImpl.ethGetBalance, requestDetails); if (cachedBalance && this.shouldUseCacheForBalance(blockNumberOrTagOrHash)) { - this.logger.trace(`${requestIdPrefix} returning cached value ${cacheKey}:${JSON.stringify(cachedBalance)}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} returning cached value ${cacheKey}:${JSON.stringify(cachedBalance)}`); + } return cachedBalance; } @@ -1069,17 +1127,21 @@ export class EthImpl implements Eth { } if (!balanceFound) { - this.logger.debug( - `${requestIdPrefix} Unable to find account ${account} in block ${JSON.stringify( - blockNumber, - )}(${blockNumberOrTagOrHash}), returning 0x0 balance`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Unable to find account ${account} in block ${JSON.stringify( + blockNumber, + )}(${blockNumberOrTagOrHash}), returning 0x0 balance`, + ); + } return EthImpl.zeroHex; } // save in cache the current balance for the account and blockNumberOrTag cachedBalance = numberTo0x(weibars); - this.logger.trace(`${requestIdPrefix} Value cached balance ${cachedBalance}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} Value cached balance ${cachedBalance}`); + } await this.cacheService.set( cacheKey, cachedBalance, @@ -1111,14 +1173,18 @@ export class EthImpl implements Eth { `The value passed is not a valid blockHash/blockNumber/blockTag value: ${blockNumber}`, ); } - this.logger.trace(`${requestIdPrefix} getCode(address=${address}, blockNumber=${blockNumber})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} getCode(address=${address}, blockNumber=${blockNumber})`); + } // check for static precompile cases first before consulting nodes // this also account for environments where system entities were not yet exposed to the mirror node if (address === EthImpl.iHTSAddress) { - this.logger.trace( - `${requestIdPrefix} HTS precompile case, return ${EthImpl.invalidEVMInstruction} for byte code`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} HTS precompile case, return ${EthImpl.invalidEVMInstruction} for byte code`, + ); + } return EthImpl.invalidEVMInstruction; } @@ -1139,7 +1205,9 @@ export class EthImpl implements Eth { ]); if (result) { if (result?.type === constants.TYPE_TOKEN) { - this.logger.trace(`${requestIdPrefix} Token redirect case, return redirectBytecode`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} Token redirect case, return redirectBytecode`); + } return EthImpl.redirectBytecodeAddressReplace(address); } else if (result?.type === constants.TYPE_CONTRACT) { if (result?.entity.runtime_bytecode !== EthImpl.emptyHex) { @@ -1168,9 +1236,11 @@ export class EthImpl implements Eth { if (e instanceof SDKClientError) { // handle INVALID_CONTRACT_ID or CONTRACT_DELETED if (e.isInvalidContractId() || e.isContractDeleted()) { - this.logger.debug( - `${requestIdPrefix} Unable to find code for contract ${address} in block "${blockNumber}", returning 0x0, err code: ${e.statusCode}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Unable to find code for contract ${address} in block "${blockNumber}", returning 0x0, err code: ${e.statusCode}`, + ); + } return EthImpl.emptyHex; } @@ -1184,9 +1254,11 @@ export class EthImpl implements Eth { e.status._code === constants.PRECHECK_STATUS_ERROR_STATUS_CODES.INVALID_CONTRACT_ID || e.status._code === constants.PRECHECK_STATUS_ERROR_STATUS_CODES.CONTRACT_DELETED ) { - this.logger.debug( - `${requestIdPrefix} Unable to find code for contract ${address} in block "${blockNumber}", returning 0x0, err code: ${e.message}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Unable to find code for contract ${address} in block "${blockNumber}", returning 0x0, err code: ${e.message}`, + ); + } return EthImpl.emptyHex; } @@ -1212,7 +1284,9 @@ export class EthImpl implements Eth { */ async getBlockByHash(hash: string, showDetails: boolean, requestDetails: RequestDetails): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} getBlockByHash(hash=${hash}, showDetails=${showDetails})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} getBlockByHash(hash=${hash}, showDetails=${showDetails})`); + } const cacheKey = `${constants.CACHE_KEY.ETH_GET_BLOCK_BY_HASH}_${hash}_${showDetails}`; let block = await this.cacheService.getAsync(cacheKey, EthImpl.ethGetBlockByHash, requestDetails); @@ -1238,7 +1312,9 @@ export class EthImpl implements Eth { requestDetails: RequestDetails, ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} getBlockByNumber(blockNum=${blockNumOrTag}, showDetails=${showDetails})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} getBlockByNumber(blockNum=${blockNumOrTag}, showDetails=${showDetails})`); + } const cacheKey = `${constants.CACHE_KEY.ETH_GET_BLOCK_BY_NUMBER}_${blockNumOrTag}_${showDetails}`; let block = await this.cacheService.getAsync(cacheKey, EthImpl.ethGetBlockByNumber, requestDetails); @@ -1266,7 +1342,9 @@ export class EthImpl implements Eth { */ async getBlockTransactionCountByHash(hash: string, requestDetails: RequestDetails): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} getBlockTransactionCountByHash(hash=${hash}, showDetails=%o)`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} getBlockTransactionCountByHash(hash=${hash}, showDetails=%o)`); + } const cacheKey = `${constants.CACHE_KEY.ETH_GET_TRANSACTION_COUNT_BY_HASH}_${hash}`; const cachedResponse = await this.cacheService.getAsync( @@ -1275,9 +1353,11 @@ export class EthImpl implements Eth { requestDetails, ); if (cachedResponse) { - this.logger.debug( - `${requestIdPrefix} getBlockTransactionCountByHash returned cached response: ${cachedResponse}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} getBlockTransactionCountByHash returned cached response: ${cachedResponse}`, + ); + } return cachedResponse; } @@ -1302,7 +1382,11 @@ export class EthImpl implements Eth { requestDetails: RequestDetails, ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} getBlockTransactionCountByNumber(blockNum=${blockNumOrTag}, showDetails=%o)`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} getBlockTransactionCountByNumber(blockNum=${blockNumOrTag}, showDetails=%o)`, + ); + } const blockNum = await this.translateBlockTag(blockNumOrTag, requestDetails); const cacheKey = `${constants.CACHE_KEY.ETH_GET_TRANSACTION_COUNT_BY_NUMBER}_${blockNum}`; @@ -1312,9 +1396,11 @@ export class EthImpl implements Eth { requestDetails, ); if (cachedResponse) { - this.logger.debug( - `${requestIdPrefix} getBlockTransactionCountByNumber returned cached response: ${cachedResponse}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} getBlockTransactionCountByNumber returned cached response: ${cachedResponse}`, + ); + } return cachedResponse; } @@ -1345,9 +1431,11 @@ export class EthImpl implements Eth { requestDetails: RequestDetails, ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace( - `${requestIdPrefix} getTransactionByBlockHashAndIndex(hash=${blockHash}, index=${transactionIndex})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} getTransactionByBlockHashAndIndex(hash=${blockHash}, index=${transactionIndex})`, + ); + } try { return await this.getTransactionByBlockHashOrBlockNumAndIndex( @@ -1376,9 +1464,11 @@ export class EthImpl implements Eth { requestDetails: RequestDetails, ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace( - `${requestIdPrefix} getTransactionByBlockNumberAndIndex(blockNum=${blockNumOrTag}, index=${transactionIndex})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} getTransactionByBlockNumberAndIndex(blockNum=${blockNumOrTag}, index=${transactionIndex})`, + ); + } const blockNum = await this.translateBlockTag(blockNumOrTag, requestDetails); try { @@ -1411,13 +1501,17 @@ export class EthImpl implements Eth { requestDetails: RequestDetails, ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} getTransactionCount(address=${address}, blockNumOrTag=${blockNumOrTag})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} getTransactionCount(address=${address}, blockNumOrTag=${blockNumOrTag})`); + } // cache considerations for high load const cacheKey = `eth_getTransactionCount_${address}_${blockNumOrTag}`; let nonceCount = await this.cacheService.getAsync(cacheKey, EthImpl.ethGetTransactionCount, requestDetails); if (nonceCount) { - this.logger.trace(`${requestIdPrefix} returning cached value ${cacheKey}:${JSON.stringify(nonceCount)}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} returning cached value ${cacheKey}:${JSON.stringify(nonceCount)}`); + } return nonceCount; } @@ -1465,9 +1559,11 @@ export class EthImpl implements Eth { const parsedTx = Precheck.parseTxIfNeeded(transaction); interactingEntity = parsedTx.to?.toString() || ''; originatingAddress = parsedTx.from?.toString() || ''; - this.logger.trace( - `${requestDetails.formattedRequestId} sendRawTransaction(from=${originatingAddress}, to=${interactingEntity}, transaction=${transaction})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} sendRawTransaction(from=${originatingAddress}, to=${interactingEntity}, transaction=${transaction})`, + ); + } await this.precheck.sendRawTransactionCheck(parsedTx, networkGasPriceInWeiBars, requestDetails); return parsedTx; @@ -1510,11 +1606,13 @@ export class EthImpl implements Eth { break; } - this.logger.trace( - `${ - requestDetails.formattedRequestId - } Repeating retry to poll for updated account nonce. Count ${i} of ${mirrorNodeGetContractResultRetries}. Waiting ${this.mirrorNodeClient.getMirrorNodeRetryDelay()} ms before initiating a new request`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${ + requestDetails.formattedRequestId + } Repeating retry to poll for updated account nonce. Count ${i} of ${mirrorNodeGetContractResultRetries}. Waiting ${this.mirrorNodeClient.getMirrorNodeRetryDelay()} ms before initiating a new request`, + ); + } await new Promise((r) => setTimeout(r, this.mirrorNodeClient.getMirrorNodeRetryDelay())); } @@ -1654,7 +1752,9 @@ export class EthImpl implements Eth { ); // log call data size const callDataSize = callData ? callData.length : 0; - this.logger.trace(`${requestIdPrefix} call data size: ${callDataSize}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} call data size: ${callDataSize}`); + } // metrics for selector if (callDataSize >= constants.FUNCTION_SELECTOR_CHAR_LENGTH) { this.ethExecutionsCounter @@ -1692,7 +1792,9 @@ export class EthImpl implements Eth { result = await this.callMirrorNode(call, gas, call.value, blockNumberOrTag, requestDetails); } - this.logger.debug(`${requestIdPrefix} eth_call response: ${JSON.stringify(result)}`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} eth_call response: ${JSON.stringify(result)}`); + } return result; } catch (e: any) { @@ -1796,14 +1898,16 @@ export class EthImpl implements Eth { const requestIdPrefix = requestDetails.formattedRequestId; let callData: IContractCallRequest = {}; try { - this.logger.debug( - `${requestIdPrefix} Making eth_call on contract ${call.to} with gas ${gas} and call data "${call.data}" from "${call.from}" at blockBlockNumberOrTag: "${block}" using mirror-node.`, - call.to, - gas, - call.data, - call.from, - block, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Making eth_call on contract ${call.to} with gas ${gas} and call data "${call.data}" from "${call.from}" at blockBlockNumberOrTag: "${block}" using mirror-node.`, + call.to, + gas, + call.data, + call.from, + block, + ); + } callData = { ...call, ...(gas !== null ? { gas } : {}), // Add gas only if it's not null @@ -1830,9 +1934,11 @@ export class EthImpl implements Eth { } if (e.isContractReverted()) { - this.logger.trace( - `${requestIdPrefix} mirror node eth_call request encountered contract revert. message: ${e.message}, details: ${e.detail}, data: ${e.data}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} mirror node eth_call request encountered contract revert. message: ${e.message}, details: ${e.detail}, data: ${e.data}`, + ); + } return predefined.CONTRACT_REVERT(e.detail || e.message, e.data); } @@ -1841,11 +1947,13 @@ export class EthImpl implements Eth { if (e.isNotSupported() || e.isNotSupportedSystemContractOperaton()) { const errorTypeMessage = e.isNotSupported() || e.isNotSupportedSystemContractOperaton() ? 'Unsupported' : 'Unhandled'; - this.logger.trace( - `${requestIdPrefix} ${errorTypeMessage} mirror node eth_call request, retrying with consensus node. details: ${JSON.stringify( - callData, - )} with error: "${e.message}"`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} ${errorTypeMessage} mirror node eth_call request, retrying with consensus node. details: ${JSON.stringify( + callData, + )} with error: "${e.message}"`, + ); + } return await this.callConsensusNode(call, gas, requestDetails); } } @@ -1874,13 +1982,15 @@ export class EthImpl implements Eth { gas = Number.parseInt(this.defaultGas); } - this.logger.debug( - `${requestIdPrefix} Making eth_call on contract ${call.to} with gas ${gas} and call data "${call.data}" from "${call.from}" using consensus-node.`, - call.to, - gas, - call.data, - call.from, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Making eth_call on contract ${call.to} with gas ${gas} and call data "${call.data}" from "${call.from}" using consensus-node.`, + call.to, + gas, + call.data, + call.from, + ); + } // If "From" is distinct from blank, we check is a valid account if (call.from) { @@ -1904,7 +2014,9 @@ export class EthImpl implements Eth { const cachedResponse = await this.cacheService.getAsync(cacheKey, EthImpl.ethCall, requestDetails); if (cachedResponse != undefined) { - this.logger.debug(`${requestIdPrefix} eth_call returned cached response: ${cachedResponse}`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} eth_call returned cached response: ${cachedResponse}`); + } return cachedResponse; } @@ -1986,7 +2098,9 @@ export class EthImpl implements Eth { */ async getTransactionByHash(hash: string, requestDetails: RequestDetails): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} getTransactionByHash(hash=${hash})`, hash); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} getTransactionByHash(hash=${hash})`, hash); + } const contractResult = await this.mirrorNodeClient.getContractResultWithRetry(hash, requestDetails); if (contractResult === null || contractResult.hash === undefined) { @@ -2001,7 +2115,9 @@ export class EthImpl implements Eth { // no tx found if (!syntheticLogs.length) { - this.logger.trace(`${requestIdPrefix} no tx for ${hash}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} no tx for ${hash}`); + } return null; } @@ -2033,14 +2149,18 @@ export class EthImpl implements Eth { */ async getTransactionReceipt(hash: string, requestDetails: RequestDetails): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} getTransactionReceipt(${hash})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} getTransactionReceipt(${hash})`); + } const cacheKey = `${constants.CACHE_KEY.ETH_GET_TRANSACTION_RECEIPT}_${hash}`; const cachedResponse = await this.cacheService.getAsync(cacheKey, EthImpl.ethGetTransactionReceipt, requestDetails); if (cachedResponse) { - this.logger.debug( - `${requestIdPrefix} getTransactionReceipt returned cached response: ${JSON.stringify(cachedResponse)}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} getTransactionReceipt returned cached response: ${JSON.stringify(cachedResponse)}`, + ); + } return cachedResponse; } @@ -2057,7 +2177,9 @@ export class EthImpl implements Eth { // no tx found if (!syntheticLogs.length) { - this.logger.trace(`${requestIdPrefix} no receipt for ${hash}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} no receipt for ${hash}`); + } return null; } @@ -2080,7 +2202,9 @@ export class EthImpl implements Eth { type: null, // null from HAPI transactions }; - this.logger.trace(`${requestIdPrefix} receipt for ${hash} found in block ${receipt.blockNumber}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} receipt for ${hash} found in block ${receipt.blockNumber}`); + } await this.cacheService.set( cacheKey, @@ -2131,7 +2255,9 @@ export class EthImpl implements Eth { : prepend0x(ASCIIToHex(receiptResponse.error_message)); } - this.logger.trace(`${requestIdPrefix} receipt for ${hash} found in block ${receipt.blockNumber}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} receipt for ${hash} found in block ${receipt.blockNumber}`); + } await this.cacheService.set( cacheKey, @@ -2218,9 +2344,11 @@ export class EthImpl implements Eth { // With values over the gas limit, the call will fail with BUSY error so we cap it at 15_000_000 const gas = Number.parseInt(gasString); if (gas > constants.MAX_GAS_PER_SEC) { - this.logger.trace( - `${requestDetails.formattedRequestId} eth_call gas amount (${gas}) exceeds network limit, capping gas to ${constants.MAX_GAS_PER_SEC}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} eth_call gas amount (${gas}) exceeds network limit, capping gas to ${constants.MAX_GAS_PER_SEC}`, + ); + } return constants.MAX_GAS_PER_SEC; } @@ -2249,9 +2377,11 @@ export class EthImpl implements Eth { }); } - this.logger.trace( - `${requestDetails.formattedRequestId} Synthetic transaction hashes will be populated in the block response`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Synthetic transaction hashes will be populated in the block response`, + ); + } return transactionsArray; } @@ -2506,7 +2636,9 @@ export class EthImpl implements Eth { } async maxPriorityFeePerGas(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} maxPriorityFeePerGas()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} maxPriorityFeePerGas()`); + } return EthImpl.zeroHex; } diff --git a/packages/relay/src/lib/hbarlimiter/index.ts b/packages/relay/src/lib/hbarlimiter/index.ts index c4ae1a7d98..e48cd654a5 100644 --- a/packages/relay/src/lib/hbarlimiter/index.ts +++ b/packages/relay/src/lib/hbarlimiter/index.ts @@ -47,7 +47,9 @@ export default class HbarLimit { this.remainingBudget = this.total; this.reset = currentDateNow + this.duration; - this.logger.trace(`remainingBudget=${this.remainingBudget} tℏ, resetTimestamp=${this.reset}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`remainingBudget=${this.remainingBudget} tℏ, resetTimestamp=${this.reset}`); + } const metricCounterName = 'rpc_relay_hbar_rate_limit'; register.removeSingleMetric(metricCounterName); @@ -96,9 +98,11 @@ export default class HbarLimit { // check if the caller is a whitelisted caller if (this.isAccountWhiteListed(originalCallerAddress)) { - this.logger.trace( - `${requestIdPrefix} HBAR rate limit bypassed - the caller is a whitelisted account: originalCallerAddress=${originalCallerAddress}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} HBAR rate limit bypassed - the caller is a whitelisted account: originalCallerAddress=${originalCallerAddress}`, + ); + } return false; } @@ -113,9 +117,11 @@ export default class HbarLimit { ); return true; } else { - this.logger.trace( - `${requestIdPrefix} HBAR rate limit not reached: remainingBudget=${this.remainingBudget}, total=${this.total}, resetTimestamp=${this.reset}.`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} HBAR rate limit not reached: remainingBudget=${this.remainingBudget}, total=${this.total}, resetTimestamp=${this.reset}.`, + ); + } return false; } } @@ -141,9 +147,11 @@ export default class HbarLimit { requestDetails: RequestDetails, ): boolean { if (this.isAccountWhiteListed(originalCallerAddress)) { - this.logger.trace( - `${requestDetails.formattedRequestId} Request bypasses the preemptive limit check - the caller is a whitelisted account: originalCallerAddress=${originalCallerAddress}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Request bypasses the preemptive limit check - the caller is a whitelisted account: originalCallerAddress=${originalCallerAddress}`, + ); + } return false; } @@ -160,9 +168,11 @@ export default class HbarLimit { return true; } - this.logger.trace( - `${requestDetails.formattedRequestId} Request passes the preemptive limit check - the remaining HBAR budget is enough to accommodate the estimated transaction fee: remainingBudget=${this.remainingBudget}, total=${this.total}, resetTimestamp=${this.reset}, callDataSize=${callDataSize}, estimatedTxFee=${estimatedTxFee}, exchangeRateInCents=${currentNetworkExchangeRateInCents}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Request passes the preemptive limit check - the remaining HBAR budget is enough to accommodate the estimated transaction fee: remainingBudget=${this.remainingBudget}, total=${this.total}, resetTimestamp=${this.reset}, callDataSize=${callDataSize}, estimatedTxFee=${estimatedTxFee}, exchangeRateInCents=${currentNetworkExchangeRateInCents}`, + ); + } return false; } @@ -180,9 +190,11 @@ export default class HbarLimit { this.remainingBudget -= cost; this.hbarLimitRemainingGauge.set(this.remainingBudget); - this.logger.trace( - `${requestDetails.formattedRequestId} HBAR rate limit expense update: cost=${cost}, remainingBudget=${this.remainingBudget}, resetTimestamp=${this.reset}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} HBAR rate limit expense update: cost=${cost}, remainingBudget=${this.remainingBudget}, resetTimestamp=${this.reset}`, + ); + } } /** @@ -268,8 +280,10 @@ export default class HbarLimit { private resetLimiter(currentDateNow: number, requestDetails: RequestDetails) { this.reset = currentDateNow + this.duration; this.remainingBudget = this.total; - this.logger.trace( - `${requestDetails.formattedRequestId} HBAR Rate Limit reset: remainingBudget= ${this.remainingBudget}, newResetTimestamp= ${this.reset}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} HBAR Rate Limit reset: remainingBudget= ${this.remainingBudget}, newResetTimestamp= ${this.reset}`, + ); + } } } diff --git a/packages/relay/src/lib/poller.ts b/packages/relay/src/lib/poller.ts index 36439bc39d..ed98a3e635 100644 --- a/packages/relay/src/lib/poller.ts +++ b/packages/relay/src/lib/poller.ts @@ -73,7 +73,9 @@ export class Poller { public poll() { this.polls.forEach(async (poll) => { try { - this.logger.debug(`${LOGGER_PREFIX} Fetching data for tag: ${poll.tag}`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${LOGGER_PREFIX} Fetching data for tag: ${poll.tag}`); + } const { event, filters } = JSON.parse(poll.tag); let data; @@ -103,13 +105,17 @@ export class Poller { if (Array.isArray(data)) { if (data.length) { - this.logger.trace(`${LOGGER_PREFIX} Received ${data.length} results from tag: ${poll.tag}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${LOGGER_PREFIX} Received ${data.length} results from tag: ${poll.tag}`); + } data.forEach((d) => { poll.callback(d); }); } } else { - this.logger.trace(`${LOGGER_PREFIX} Received 1 result from tag: ${poll.tag}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${LOGGER_PREFIX} Received 1 result from tag: ${poll.tag}`); + } poll.callback(data); } } catch (error) { diff --git a/packages/relay/src/lib/precheck.ts b/packages/relay/src/lib/precheck.ts index f44c1d3d51..f7052aa750 100644 --- a/packages/relay/src/lib/precheck.ts +++ b/packages/relay/src/lib/precheck.ts @@ -96,13 +96,15 @@ export class Precheck { async verifyAccount(tx: Transaction, requestDetails: RequestDetails): Promise { const accountInfo = await this.mirrorNodeClient.getAccount(tx.from!, requestDetails); if (accountInfo == null) { - this.logger.trace( - `${requestDetails.formattedRequestId} Failed to retrieve address '${ - tx.from - }' account details from mirror node on verify account precheck for sendRawTransaction(transaction=${JSON.stringify( - tx, - )})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Failed to retrieve address '${ + tx.from + }' account details from mirror node on verify account precheck for sendRawTransaction(transaction=${JSON.stringify( + tx, + )})`, + ); + } throw predefined.RESOURCE_NOT_FOUND(`address '${tx.from}'.`); } @@ -116,9 +118,11 @@ export class Precheck { * @param {RequestDetails} requestDetails - The request details for logging and tracking. */ nonce(tx: Transaction, accountInfoNonce: number, requestDetails: RequestDetails): void { - this.logger.trace( - `${requestDetails.formattedRequestId} Nonce precheck for sendRawTransaction(tx.nonce=${tx.nonce}, accountInfoNonce=${accountInfoNonce})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Nonce precheck for sendRawTransaction(tx.nonce=${tx.nonce}, accountInfoNonce=${accountInfoNonce})`, + ); + } if (accountInfoNonce > tx.nonce) { throw predefined.NONCE_TOO_LOW(tx.nonce, accountInfoNonce); @@ -134,11 +138,13 @@ export class Precheck { const txChainId = prepend0x(Number(tx.chainId).toString(16)); const passes = this.isLegacyUnprotectedEtx(tx) || txChainId === this.chain; if (!passes) { - this.logger.trace( - `${requestDetails.formattedRequestId} Failed chainId precheck for sendRawTransaction(transaction=%s, chainId=%s)`, - JSON.stringify(tx), - txChainId, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Failed chainId precheck for sendRawTransaction(transaction=%s, chainId=%s)`, + JSON.stringify(tx), + txChainId, + ); + } throw predefined.UNSUPPORTED_CHAIN_ID(txChainId, this.chain); } } @@ -181,12 +187,14 @@ export class Precheck { } } - this.logger.trace( - `${requestDetails.formattedRequestId} Failed gas price precheck for sendRawTransaction(transaction=%s, gasPrice=%s, requiredGasPrice=%s)`, - JSON.stringify(tx), - txGasPrice, - networkGasPrice, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Failed gas price precheck for sendRawTransaction(transaction=%s, gasPrice=%s, requiredGasPrice=%s)`, + JSON.stringify(tx), + txGasPrice, + networkGasPrice, + ); + } throw predefined.GAS_PRICE_TOO_LOW(txGasPrice, networkGasPrice); } } @@ -215,13 +223,15 @@ export class Precheck { const txTotalValue = tx.value + txGas * tx.gasLimit; if (account == null) { - this.logger.trace( - `${ - requestDetails.formattedRequestId - } Failed to retrieve account details from mirror node on balance precheck for sendRawTransaction(transaction=${JSON.stringify( - tx, - )}, totalValue=${txTotalValue})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${ + requestDetails.formattedRequestId + } Failed to retrieve account details from mirror node on balance precheck for sendRawTransaction(transaction=${JSON.stringify( + tx, + )}, totalValue=${txTotalValue})`, + ); + } throw predefined.RESOURCE_NOT_FOUND(`tx.from '${tx.from}'.`); } @@ -230,12 +240,14 @@ export class Precheck { tinybars = BigInt(account.balance.balance.toString()) * BigInt(constants.TINYBAR_TO_WEIBAR_COEF); result.passes = tinybars >= txTotalValue; } catch (error: any) { - this.logger.trace( - `${requestDetails.formattedRequestId} Error on balance precheck for sendRawTransaction(transaction=%s, totalValue=%s, error=%s)`, - JSON.stringify(tx), - txTotalValue, - error.message, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Error on balance precheck for sendRawTransaction(transaction=%s, totalValue=%s, error=%s)`, + JSON.stringify(tx), + txTotalValue, + error.message, + ); + } if (error instanceof JsonRpcError) { // preserve original error throw error; @@ -245,12 +257,14 @@ export class Precheck { } if (!result.passes) { - this.logger.trace( - `${requestDetails.formattedRequestId} Failed balance precheck for sendRawTransaction(transaction=%s, totalValue=%s, accountTinyBarBalance=%s)`, - JSON.stringify(tx), - txTotalValue, - tinybars, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Failed balance precheck for sendRawTransaction(transaction=%s, totalValue=%s, accountTinyBarBalance=%s)`, + JSON.stringify(tx), + txTotalValue, + tinybars, + ); + } throw predefined.INSUFFICIENT_ACCOUNT_BALANCE; } } @@ -267,20 +281,24 @@ export class Precheck { const intrinsicGasCost = Precheck.transactionIntrinsicGasCost(tx.data); if (gasLimit > constants.MAX_GAS_PER_SEC) { - this.logger.trace( - `${requestDetails.formattedRequestId} ${failBaseLog} Gas Limit was too high: %s, block gas limit: %s`, - JSON.stringify(tx), - gasLimit, - constants.MAX_GAS_PER_SEC, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} ${failBaseLog} Gas Limit was too high: %s, block gas limit: %s`, + JSON.stringify(tx), + gasLimit, + constants.MAX_GAS_PER_SEC, + ); + } throw predefined.GAS_LIMIT_TOO_HIGH(gasLimit, constants.MAX_GAS_PER_SEC); } else if (gasLimit < intrinsicGasCost) { - this.logger.trace( - `${requestDetails.formattedRequestId} ${failBaseLog} Gas Limit was too low: %s, intrinsic gas cost: %s`, - JSON.stringify(tx), - gasLimit, - intrinsicGasCost, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} ${failBaseLog} Gas Limit was too low: %s, intrinsic gas cost: %s`, + JSON.stringify(tx), + gasLimit, + intrinsicGasCost, + ); + } throw predefined.GAS_LIMIT_TOO_LOW(gasLimit, intrinsicGasCost); } } @@ -348,11 +366,13 @@ export class Precheck { transactionType(tx: Transaction, requestDetails: RequestDetails) { // Blob transactions are not supported as per HIP 866 if (tx.type === 3) { - this.logger.trace( - `${requestDetails.formattedRequestId} Transaction with type=${ - tx.type - } is unsupported for sendRawTransaction(transaction=${JSON.stringify(tx)})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Transaction with type=${ + tx.type + } is unsupported for sendRawTransaction(transaction=${JSON.stringify(tx)})`, + ); + } throw predefined.UNSUPPORTED_TRANSACTION_TYPE; } } diff --git a/packages/relay/src/lib/services/debugService/index.ts b/packages/relay/src/lib/services/debugService/index.ts index 92a6db0ad8..3964d0358c 100644 --- a/packages/relay/src/lib/services/debugService/index.ts +++ b/packages/relay/src/lib/services/debugService/index.ts @@ -101,7 +101,9 @@ export class DebugService implements IDebugService { tracerConfig: ITracerConfig, requestDetails: RequestDetails, ): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} debug_traceTransaction(${transactionIdOrHash})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} debug_traceTransaction(${transactionIdOrHash})`); + } try { DebugService.requireDebugAPIEnabled(); if (tracer === TracerType.CallTracer) { diff --git a/packages/relay/src/lib/services/ethService/ethCommonService/index.ts b/packages/relay/src/lib/services/ethService/ethCommonService/index.ts index 3e8ff7d084..4756710202 100644 --- a/packages/relay/src/lib/services/ethService/ethCommonService/index.ts +++ b/packages/relay/src/lib/services/ethService/ethCommonService/index.ts @@ -215,9 +215,13 @@ export class CommonService implements ICommonService { ); if (blockNumberCached) { - this.logger.trace( - `${requestDetails.formattedRequestId} returning cached value ${cacheKey}:${JSON.stringify(blockNumberCached)}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} returning cached value ${cacheKey}:${JSON.stringify( + blockNumberCached, + )}`, + ); + } return blockNumberCached; } diff --git a/packages/relay/src/lib/services/ethService/ethFilterService/index.ts b/packages/relay/src/lib/services/ethService/ethFilterService/index.ts index df586cf989..9f1e730251 100644 --- a/packages/relay/src/lib/services/ethService/ethFilterService/index.ts +++ b/packages/relay/src/lib/services/ethService/ethFilterService/index.ts @@ -93,7 +93,9 @@ export class FilterService implements IFilterService { requestDetails, constants.FILTER.TTL, ); - this.logger.trace(`${requestDetails.formattedRequestId} created filter with TYPE=${type}, params: ${params}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} created filter with TYPE=${type}, params: ${params}`); + } return filterId; } @@ -122,9 +124,11 @@ export class FilterService implements IFilterService { topics?: any[], ): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace( - `${requestIdPrefix} newFilter(fromBlock=${fromBlock}, toBlock=${toBlock}, address=${address}, topics=${topics})`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} newFilter(fromBlock=${fromBlock}, toBlock=${toBlock}, address=${address}, topics=${topics})`, + ); + } try { FilterService.requireFiltersEnabled(); @@ -151,7 +155,9 @@ export class FilterService implements IFilterService { async newBlockFilter(requestDetails: RequestDetails): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} newBlockFilter()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} newBlockFilter()`); + } try { FilterService.requireFiltersEnabled(); return await this.createFilter( @@ -168,7 +174,9 @@ export class FilterService implements IFilterService { public async uninstallFilter(filterId: string, requestDetails: RequestDetails): Promise { const requestIdPrefix = requestDetails.formattedRequestId; - this.logger.trace(`${requestIdPrefix} uninstallFilter(${filterId})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} uninstallFilter(${filterId})`); + } FilterService.requireFiltersEnabled(); const cacheKey = `${constants.CACHE_KEY.FILTERID}_${filterId}`; @@ -183,12 +191,16 @@ export class FilterService implements IFilterService { } public newPendingTransactionFilter(requestDetails: RequestDetails): JsonRpcError { - this.logger.trace(`${requestDetails.formattedRequestId} newPendingTransactionFilter()`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} newPendingTransactionFilter()`); + } return predefined.UNSUPPORTED_METHOD; } public async getFilterLogs(filterId: string, requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} getFilterLogs(${filterId})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} getFilterLogs(${filterId})`); + } FilterService.requireFiltersEnabled(); const cacheKey = `${constants.CACHE_KEY.FILTERID}_${filterId}`; @@ -208,7 +220,9 @@ export class FilterService implements IFilterService { } public async getFilterChanges(filterId: string, requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} getFilterChanges(${filterId})`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} getFilterChanges(${filterId})`); + } FilterService.requireFiltersEnabled(); const cacheKey = `${constants.CACHE_KEY.FILTERID}_${filterId}`; diff --git a/packages/relay/src/lib/services/hbarLimitService/index.ts b/packages/relay/src/lib/services/hbarLimitService/index.ts index 0596abb3d6..b4c1e28fad 100644 --- a/packages/relay/src/lib/services/hbarLimitService/index.ts +++ b/packages/relay/src/lib/services/hbarLimitService/index.ts @@ -144,14 +144,18 @@ export class HbarLimitService implements IHbarLimitService { * @returns {Promise} - A promise that resolves when the operation is complete. */ async resetLimiter(requestDetails: RequestDetails): Promise { - this.logger.trace(`${requestDetails.formattedRequestId} Resetting HBAR rate limiter...`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} Resetting HBAR rate limiter...`); + } await this.hbarSpendingPlanRepository.resetAmountSpentOfAllPlans(requestDetails); this.resetBudget(); this.resetTemporaryMetrics(); this.reset = this.getResetTimestamp(); - this.logger.trace( - `${requestDetails.formattedRequestId} HBAR Rate Limit reset: remainingBudget=${this.remainingBudget}, newResetTimestamp=${this.reset}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} HBAR Rate Limit reset: remainingBudget=${this.remainingBudget}, newResetTimestamp=${this.reset}`, + ); + } } /** @@ -179,7 +183,9 @@ export class HbarLimitService implements IHbarLimitService { return false; } const user = `(ethAddress=${ethAddress})`; - this.logger.trace(`${requestDetails.formattedRequestId} Checking if ${user} should be limited...`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestDetails.formattedRequestId} Checking if ${user} should be limited...`); + } let spendingPlan = await this.getSpendingPlan(ethAddress, requestDetails); if (!spendingPlan) { // Create a basic spending plan if none exists for the eth address or ip address @@ -190,11 +196,15 @@ export class HbarLimitService implements IHbarLimitService { const exceedsLimit = spendingLimit.lte(spendingPlan.amountSpent) || spendingLimit.lt(spendingPlan.amountSpent + estimatedTxFee); - this.logger.trace( - `${requestDetails.formattedRequestId} ${user} ${exceedsLimit ? 'should' : 'should not'} be limited: amountSpent=${ - spendingPlan.amountSpent - }, estimatedTxFee=${estimatedTxFee} tℏ, spendingLimit=${spendingLimit.toString()} tℏ`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} ${user} ${ + exceedsLimit ? 'should' : 'should not' + } be limited: amountSpent=${ + spendingPlan.amountSpent + }, estimatedTxFee=${estimatedTxFee} tℏ, spendingLimit=${spendingLimit.toString()} tℏ`, + ); + } return exceedsLimit; } @@ -217,11 +227,13 @@ export class HbarLimitService implements IHbarLimitService { spendingPlan = await this.createBasicSpendingPlan(ethAddress, requestDetails); } - this.logger.trace( - `${requestDetails.formattedRequestId} Adding expense of ${cost} to spending plan with ID ${ - spendingPlan.id - }, new amountSpent=${spendingPlan.amountSpent + cost}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Adding expense of ${cost} to spending plan with ID ${ + spendingPlan.id + }, new amountSpent=${spendingPlan.amountSpent + cost}`, + ); + } // Check if the spending plan is being used for the first time today if (spendingPlan.amountSpent === 0) { @@ -235,9 +247,11 @@ export class HbarLimitService implements IHbarLimitService { // Done asynchronously in the background this.updateAverageAmountSpentPerSubscriptionTier(spendingPlan.subscriptionTier, requestDetails).then(); - this.logger.trace( - `${requestDetails.formattedRequestId} HBAR rate limit expense update: cost=${cost} tℏ, remainingBudget=${this.remainingBudget}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} HBAR rate limit expense update: cost=${cost} tℏ, remainingBudget=${this.remainingBudget}`, + ); + } } /** @@ -265,9 +279,11 @@ export class HbarLimitService implements IHbarLimitService { ); return true; } else { - this.logger.trace( - `${requestDetails.formattedRequestId} HBAR rate limit not reached: remainingBudget=${this.remainingBudget}, totalBudget=${this.totalBudget}, estimatedTxFee=${estimatedTxFee} tℏ, resetTimestamp=${this.reset}.`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} HBAR rate limit not reached: remainingBudget=${this.remainingBudget}, totalBudget=${this.totalBudget}, estimatedTxFee=${estimatedTxFee} tℏ, resetTimestamp=${this.reset}.`, + ); + } return false; } } @@ -429,9 +445,11 @@ export class HbarLimitService implements IHbarLimitService { this.limitDuration, ); if (ethAddress) { - this.logger.trace( - `${requestDetails.formattedRequestId} Linking spending plan with ID ${spendingPlan.id} to eth address ${ethAddress}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Linking spending plan with ID ${spendingPlan.id} to eth address ${ethAddress}`, + ); + } await this.ethAddressHbarSpendingPlanRepository.save( { ethAddress, planId: spendingPlan.id }, requestDetails, @@ -439,9 +457,11 @@ export class HbarLimitService implements IHbarLimitService { ); } if (ipAddress) { - this.logger.trace( - `${requestDetails.formattedRequestId} Linking spending plan with ID ${spendingPlan.id} to ip address ${ipAddress}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Linking spending plan with ID ${spendingPlan.id} to ip address ${ipAddress}`, + ); + } await this.ipAddressHbarSpendingPlanRepository.save( { ipAddress, planId: spendingPlan.id }, requestDetails, diff --git a/packages/relay/src/lib/services/metricService/metricService.ts b/packages/relay/src/lib/services/metricService/metricService.ts index 0d5807c03f..a45d3ecd63 100644 --- a/packages/relay/src/lib/services/metricService/metricService.ts +++ b/packages/relay/src/lib/services/metricService/metricService.ts @@ -212,9 +212,11 @@ export default class MetricService { status, requestDetails, }: IExecuteQueryEventPayload): void => { - this.logger.trace( - `${requestDetails.formattedRequestId} Capturing HBAR charged: executionMode=${executionMode} transactionId=${transactionId}, txConstructorName=${txConstructorName}, callerName=${callerName}, cost=${cost} tinybars`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestDetails.formattedRequestId} Capturing HBAR charged: executionMode=${executionMode} transactionId=${transactionId}, txConstructorName=${txConstructorName}, callerName=${callerName}, cost=${cost} tinybars`, + ); + } this.hbarLimiter.addExpense(cost, Date.now(), requestDetails); this.captureMetrics(executionMode, txConstructorName, status, cost, gasUsed, callerName, interactingEntity); diff --git a/packages/relay/src/lib/subscriptionController.ts b/packages/relay/src/lib/subscriptionController.ts index e306366357..4ce27db83a 100644 --- a/packages/relay/src/lib/subscriptionController.ts +++ b/packages/relay/src/lib/subscriptionController.ts @@ -108,7 +108,9 @@ export class SubscriptionController implements Subs { // Check if the connection is already subscribed to this event const existingSub = this.subscriptions[tag].find((sub) => sub.connection.id === connection.id); if (existingSub) { - this.logger.debug(`Connection ${connection.id}: Attempting to subscribe to ${tag}; already subscribed`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`Connection ${connection.id}: Attempting to subscribe to ${tag}; already subscribed`); + } return existingSub.subscriptionId; } } @@ -142,7 +144,11 @@ export class SubscriptionController implements Subs { this.subscriptions[tag] = subs.filter((sub) => { const match = sub.connection.id === id && (!subId || subId === sub.subscriptionId); if (match) { - this.logger.debug(`Connection ${sub.connection.id}. Unsubscribing subId: ${sub.subscriptionId}; tag: ${tag}`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `Connection ${sub.connection.id}. Unsubscribing subId: ${sub.subscriptionId}; tag: ${tag}`, + ); + } sub.endTimer(); subCount++; } @@ -151,7 +157,9 @@ export class SubscriptionController implements Subs { }); if (!this.subscriptions[tag].length) { - this.logger.debug(`No subscribers for ${tag}. Removing from list.`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`No subscribers for ${tag}. Removing from list.`); + } delete this.subscriptions[tag]; this.poller.remove(tag); } @@ -172,9 +180,11 @@ export class SubscriptionController implements Subs { // If the hash exists in the cache then the data has recently been sent to the subscriber if (!this.cache.get(hash)) { this.cache.set(hash, true); - this.logger.debug( - `Sending data from tag: ${tag} to subscriptionId: ${sub.subscriptionId}, connectionId: ${sub.connection.id}, data: ${subscriptionData}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `Sending data from tag: ${tag} to subscriptionId: ${sub.subscriptionId}, connectionId: ${sub.connection.id}, data: ${subscriptionData}`, + ); + } this.resultsSentToSubscribersCounter.labels('sub.subscriptionId', tag).inc(); sub.connection.send( JSON.stringify({ diff --git a/packages/relay/tests/redisInMemoryServer.ts b/packages/relay/tests/redisInMemoryServer.ts index 8520cc7206..7ab4372a8d 100644 --- a/packages/relay/tests/redisInMemoryServer.ts +++ b/packages/relay/tests/redisInMemoryServer.ts @@ -53,7 +53,9 @@ export class RedisInMemoryServer { } async start(): Promise { - this.logger.trace('Starting Redis in-memory server....'); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace('Starting Redis in-memory server....'); + } const started = await this.inMemoryRedisServer.start(); if (started) { const host = await this.getHost(); @@ -74,7 +76,9 @@ export class RedisInMemoryServer { } async stop(): Promise { - this.logger.trace('Stopping Redis in-memory server....'); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace('Stopping Redis in-memory server....'); + } const stopped = await this.inMemoryRedisServer.stop(); if (stopped) { this.logger.info('Stopped Redis in-memory server successfully.'); @@ -87,7 +91,11 @@ export class RedisInMemoryServer { try { // Ensure that the instance is running -> throws error if instance cannot be started const instanceData = await this.inMemoryRedisServer.ensureInstance(); - this.logger.debug(`Redis in-memory server health check passed, server is running on port ${instanceData.port}.`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `Redis in-memory server health check passed, server is running on port ${instanceData.port}.`, + ); + } } catch (error) { this.logger.warn(`Redis in-memory server health check failed: ${error}`); } diff --git a/packages/server/src/server.ts b/packages/server/src/server.ts index db557c0613..c07c42fc26 100644 --- a/packages/server/src/server.ts +++ b/packages/server/src/server.ts @@ -203,18 +203,22 @@ const logAndHandleResponse = async (methodName: string, methodParams: any[], met try { const methodValidations = Validator.METHODS[methodName]; if (methodValidations) { - logger.debug( - `${requestDetails.formattedRequestId} Validating method parameters for ${methodName}, params: ${JSON.stringify( - methodParams, - )}`, - ); + if (logger.isLevelEnabled('debug')) { + logger.debug( + `${ + requestDetails.formattedRequestId + } Validating method parameters for ${methodName}, params: ${JSON.stringify(methodParams)}`, + ); + } Validator.validateParams(methodParams, methodValidations); } const response = await methodFunction(requestDetails); if (response instanceof JsonRpcError) { // log error only if it is not a contract revert, otherwise log it as debug if (response.code === predefined.CONTRACT_REVERT().code) { - logger.debug(`${requestDetails.formattedRequestId} ${response.message}`); + if (logger.isLevelEnabled('debug')) { + logger.debug(`${requestDetails.formattedRequestId} ${response.message}`); + } } else { logger.error(`${requestDetails.formattedRequestId} ${response.message}`); } diff --git a/packages/server/tests/clients/metricsClient.ts b/packages/server/tests/clients/metricsClient.ts index ecd1cd8054..cc8d4da8af 100644 --- a/packages/server/tests/clients/metricsClient.ts +++ b/packages/server/tests/clients/metricsClient.ts @@ -67,7 +67,9 @@ export default class MetricsClient { */ async get(metric: string, requestId?: string) { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); - this.logger.debug(`${requestIdPrefix} [GET] Read all metrics from ${this.relayUrl}/metrics`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} [GET] Read all metrics from ${this.relayUrl}/metrics`); + } const allMetrics = (await this.client.get('')).data; const allMetricsArray = allMetrics.split('\n'); const matchPattern = `${metric} `; diff --git a/packages/server/tests/clients/mirrorClient.ts b/packages/server/tests/clients/mirrorClient.ts index 51565a03a9..f28b18c1fc 100644 --- a/packages/server/tests/clients/mirrorClient.ts +++ b/packages/server/tests/clients/mirrorClient.ts @@ -65,7 +65,9 @@ export default class MirrorClient { async get(path: string, requestId?: string) { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); - this.logger.debug(`${requestIdPrefix} [GET] MirrorNode ${path} endpoint`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} [GET] MirrorNode ${path} endpoint`); + } return (await this.client.get(path)).data; } } diff --git a/packages/server/tests/clients/relayClient.ts b/packages/server/tests/clients/relayClient.ts index 7b3bbbb6fe..a8f7e19c6c 100644 --- a/packages/server/tests/clients/relayClient.ts +++ b/packages/server/tests/clients/relayClient.ts @@ -43,11 +43,13 @@ export default class RelayClient { async call(methodName: string, params: any[], requestId?: string) { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); const result = await this.provider.send(methodName, params); - this.logger.trace( - `${requestIdPrefix} [POST] to relay '${methodName}' with params [${JSON.stringify( - params, - )}] returned ${JSON.stringify(result)}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} [POST] to relay '${methodName}' with params [${JSON.stringify( + params, + )}] returned ${JSON.stringify(result)}`, + ); + } return result; } @@ -86,9 +88,11 @@ export default class RelayClient { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); try { const res = await this.call(methodName, params, requestId); - this.logger.trace( - `${requestIdPrefix} [POST] to relay '${methodName}' with params [${params}] returned ${JSON.stringify(res)}`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} [POST] to relay '${methodName}' with params [${params}] returned ${JSON.stringify(res)}`, + ); + } Assertions.expectedError(); } catch (e: any) { if (expectedRpcError.message.includes('execution reverted')) { @@ -128,7 +132,9 @@ export default class RelayClient { */ async getBalance(address: ethers.AddressLike, block: BlockTag = 'latest', requestId?: string) { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); - this.logger.debug(`${requestIdPrefix} [POST] to relay eth_getBalance for address ${address}]`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} [POST] to relay eth_getBalance for address ${address}]`); + } return this.provider.getBalance(address, block); } @@ -139,7 +145,9 @@ export default class RelayClient { */ async getAccountNonce(evmAddress: string, requestId?: string): Promise { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); - this.logger.debug(`${requestIdPrefix} [POST] to relay for eth_getTransactionCount for address ${evmAddress}`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} [POST] to relay for eth_getTransactionCount for address ${evmAddress}`); + } const nonce = await this.provider.send('eth_getTransactionCount', [evmAddress, 'latest']); return Number(nonce); } @@ -153,7 +161,9 @@ export default class RelayClient { */ async sendRawTransaction(signedTx, requestId?: string): Promise { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); - this.logger.debug(`${requestIdPrefix} [POST] to relay for eth_sendRawTransaction`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} [POST] to relay for eth_sendRawTransaction`); + } return this.provider.send('eth_sendRawTransaction', [signedTx]); } diff --git a/packages/server/tests/clients/servicesClient.ts b/packages/server/tests/clients/servicesClient.ts index 90441ed638..49dfdb9950 100644 --- a/packages/server/tests/clients/servicesClient.ts +++ b/packages/server/tests/clients/servicesClient.ts @@ -126,9 +126,11 @@ export default class ServicesClient { ); const address = wallet.address; - this.logger.trace( - `${requestIdPrefix} Create new Eth compatible account w alias: ${address} and balance ~${initialBalance} HBar`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} Create new Eth compatible account w alias: ${address} and balance ~${initialBalance} HBar`, + ); + } const aliasCreationResponse = await this.executeTransaction( new TransferTransaction() @@ -203,7 +205,9 @@ export default class ServicesClient { async createToken(initialSupply: number = 1000, requestId?: string) { const requestIdPrefix = Utils.formatRequestIdMessage(requestId); const symbol = Math.random().toString(36).slice(2, 6).toUpperCase(); - this.logger.trace(`${requestIdPrefix} symbol = ${symbol}`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} symbol = ${symbol}`); + } const resp = await this.executeAndGetTransactionReceipt( new TokenCreateTransaction() .setTokenName(`relay-acceptance token ${symbol}`) @@ -215,7 +219,9 @@ export default class ServicesClient { requestId, ); - this.logger.trace(`${requestIdPrefix} get token id from receipt`); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace(`${requestIdPrefix} get token id from receipt`); + } const tokenId = resp?.tokenId; this.logger.info(`${requestIdPrefix} token id = ${tokenId?.toString()}`); return tokenId!; @@ -231,9 +237,11 @@ export default class ServicesClient { requestId, ); - this.logger.debug( - `${requestIdPrefix} Associated account ${this._thisAccountId()} with token ${tokenId.toString()}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Associated account ${this._thisAccountId()} with token ${tokenId.toString()}`, + ); + } } async transferToken(tokenId: string | TokenId, recipient: AccountId, amount = 10, requestId?: string) { @@ -246,15 +254,19 @@ export default class ServicesClient { requestId, ); - this.logger.debug( - `${requestIdPrefix} Sent 10 tokens from account ${this._thisAccountId()} to account ${recipient.toString()} on token ${tokenId.toString()}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Sent 10 tokens from account ${this._thisAccountId()} to account ${recipient.toString()} on token ${tokenId.toString()}`, + ); + } const balances = await this.executeQuery(new AccountBalanceQuery().setAccountId(recipient), requestId); - this.logger.debug( - `${requestIdPrefix} Token balances for ${recipient.toString()} are ${balances?.tokens?.toString()}`, - ); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug( + `${requestIdPrefix} Token balances for ${recipient.toString()} are ${balances?.tokens?.toString()}`, + ); + } return receipt; } @@ -386,9 +398,11 @@ export default class ServicesClient { // Create a KeyList of both keys and specify that only 1 is required for signing transactions const keyList = new KeyList(keys, 1); - this.logger.trace( - `${requestIdPrefix} Create new Eth compatible account w ContractId key: ${contractId}, privateKey: ${privateKey}, alias: ${publicKey.toEvmAddress()} and balance ~${initialBalance} hb`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} Create new Eth compatible account w ContractId key: ${contractId}, privateKey: ${privateKey}, alias: ${publicKey.toEvmAddress()} and balance ~${initialBalance} hb`, + ); + } const accountCreateTx = await new AccountCreateTransaction() .setInitialBalance(new Hbar(initialBalance)) @@ -414,9 +428,11 @@ export default class ServicesClient { const publicKey = privateKey.publicKey; const aliasAccountId = publicKey.toAccountId(0, 0); - this.logger.trace( - `${requestIdPrefix} Create new Eth compatible account w alias: ${aliasAccountId.toString()} and balance ~${initialBalance} hb`, - ); + if (this.logger.isLevelEnabled('trace')) { + this.logger.trace( + `${requestIdPrefix} Create new Eth compatible account w alias: ${aliasAccountId.toString()} and balance ~${initialBalance} hb`, + ); + } const aliasCreationResponse = await this.executeTransaction( new TransferTransaction() @@ -426,7 +442,9 @@ export default class ServicesClient { requestId, ); - this.logger.debug(`${requestIdPrefix} Get ${aliasAccountId.toString()} receipt`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} Get ${aliasAccountId.toString()} receipt`); + } await aliasCreationResponse?.getReceipt(this.client); return this.getAliasAccountInfo(aliasAccountId, privateKey, provider, requestId); @@ -711,7 +729,9 @@ export default class ServicesClient { const rec = await tokenTransfer.getReceipt(this.client); this.logger.info(`${requestIdPrefix} ${amount} of HTS Token ${tokenId} can be spent by ${accountId}`); - this.logger.debug(`${requestIdPrefix} ${rec}`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`${requestIdPrefix} ${rec}`); + } } catch (e) { this.logger.error(e, `${requestIdPrefix} TransferTransaction failed`); } diff --git a/packages/server/tests/helpers/assertions.ts b/packages/server/tests/helpers/assertions.ts index afa0a90326..7615df9082 100644 --- a/packages/server/tests/helpers/assertions.ts +++ b/packages/server/tests/helpers/assertions.ts @@ -464,9 +464,11 @@ export default class Assertions { * @param tolerance */ static expectWithinTolerance(expected: number, actual: number, tolerance: number) { - global.logger.debug(`Expected: ${expected} ±${tolerance}%`); - global.logger.debug(`Actual: ${actual}`); - global.logger.debug(`Actual delta: ${(actual - expected) / 100}%`); + if (global.logger.isLevelEnabled('debug')) { + global.logger.debug(`Expected: ${expected} ±${tolerance}%`); + global.logger.debug(`Actual: ${actual}`); + global.logger.debug(`Actual delta: ${(actual - expected) / 100}%`); + } const delta = tolerance * expected; expect(actual).to.be.approximately(expected, delta); } diff --git a/packages/server/tests/helpers/utils.ts b/packages/server/tests/helpers/utils.ts index 91c33c42c1..934ac5b73d 100644 --- a/packages/server/tests/helpers/utils.ts +++ b/packages/server/tests/helpers/utils.ts @@ -335,9 +335,11 @@ export class Utils { requestDetails.requestId, initialAmountInTinyBar, ); - global.logger.trace( - `${requestDetails.formattedRequestId} Create new Eth compatible account w alias: ${account.address} and balance ~${initialAmountInTinyBar} wei`, - ); + if (global.logger.isLevelEnabled('trace')) { + global.logger.trace( + `${requestDetails.formattedRequestId} Create new Eth compatible account w alias: ${account.address} and balance ~${initialAmountInTinyBar} wei`, + ); + } accounts.push(account); } return accounts; diff --git a/packages/ws-server/src/controllers/index.ts b/packages/ws-server/src/controllers/index.ts index 480628a25d..285f19da17 100644 --- a/packages/ws-server/src/controllers/index.ts +++ b/packages/ws-server/src/controllers/index.ts @@ -71,7 +71,9 @@ const handleSendingRequestsToRelay = async ({ logger, requestDetails, }: ISharedParams): Promise => { - logger.trace(`${requestDetails.formattedLogPrefix}: Submitting request=${JSON.stringify(request)} to relay.`); + if (logger.isLevelEnabled('trace')) { + logger.trace(`${requestDetails.formattedLogPrefix}: Submitting request=${JSON.stringify(request)} to relay.`); + } try { const resolvedParams = resolveParams(method, params); const [service, methodName] = method.split('_'); @@ -100,11 +102,13 @@ const handleSendingRequestsToRelay = async ({ } if (!txRes) { - logger.trace( - `${requestDetails.formattedLogPrefix}: Fail to retrieve result for request=${JSON.stringify( - request, - )}. Result=${txRes}`, - ); + if (logger.isLevelEnabled('trace')) { + logger.trace( + `${requestDetails.formattedLogPrefix}: Fail to retrieve result for request=${JSON.stringify( + request, + )}. Result=${txRes}`, + ); + } } return jsonResp(request.id, null, txRes); diff --git a/packages/ws-server/src/metrics/connectionLimiter.ts b/packages/ws-server/src/metrics/connectionLimiter.ts index 2daff2846e..8bd7df1b0d 100644 --- a/packages/ws-server/src/metrics/connectionLimiter.ts +++ b/packages/ws-server/src/metrics/connectionLimiter.ts @@ -196,7 +196,9 @@ export default class ConnectionLimiter { websocket.inactivityTTL = setTimeout(() => { if (websocket.readyState !== 3) { // 3 = CLOSED, Avoid closing already closed connections - this.logger.debug(`Closing connection ${websocket.id} due to reaching TTL (${maxInactivityTTL}ms)`); + if (this.logger.isLevelEnabled('debug')) { + this.logger.debug(`Closing connection ${websocket.id} due to reaching TTL (${maxInactivityTTL}ms)`); + } try { this.inactivityTTLCounter.inc(); websocket.send( diff --git a/packages/ws-server/src/utils/utils.ts b/packages/ws-server/src/utils/utils.ts index 32759ba090..0d96820a1a 100644 --- a/packages/ws-server/src/utils/utils.ts +++ b/packages/ws-server/src/utils/utils.ts @@ -83,11 +83,13 @@ export const sendToClient = ( logger: Logger, requestDetails: RequestDetails, ) => { - logger.trace( - `${requestDetails.formattedLogPrefix}: Sending result=${JSON.stringify( - response, - )} to client for request=${JSON.stringify(request)}`, - ); + if (logger.isLevelEnabled('trace')) { + logger.trace( + `${requestDetails.formattedLogPrefix}: Sending result=${JSON.stringify( + response, + )} to client for request=${JSON.stringify(request)}`, + ); + } connection.send(JSON.stringify(response)); connection.limiter.resetInactivityTTLTimer(connection); diff --git a/packages/ws-server/src/webSocketServer.ts b/packages/ws-server/src/webSocketServer.ts index bb0c9791f2..99fee0808d 100644 --- a/packages/ws-server/src/webSocketServer.ts +++ b/packages/ws-server/src/webSocketServer.ts @@ -124,7 +124,9 @@ app.ws.use(async (ctx: Koa.Context) => { // check if request is a batch request (array) or a signle request (JSON) if (Array.isArray(request)) { - logger.trace(`${requestDetails.formattedLogPrefix}: Receive batch request=${JSON.stringify(request)}`); + if (logger.isLevelEnabled('trace')) { + logger.trace(`${requestDetails.formattedLogPrefix}: Receive batch request=${JSON.stringify(request)}`); + } // Increment metrics for batch_requests wsMetricRegistry.getCounter('methodsCounter').labels(WS_CONSTANTS.BATCH_REQUEST_METHOD_NAME).inc(); @@ -163,7 +165,9 @@ app.ws.use(async (ctx: Koa.Context) => { // send to client sendToClient(ctx.websocket, request, responses, logger, requestDetails); } else { - logger.trace(`${requestDetails.formattedLogPrefix}: Receive single request=${JSON.stringify(request)}`); + if (logger.isLevelEnabled('trace')) { + logger.trace(`${requestDetails.formattedLogPrefix}: Receive single request=${JSON.stringify(request)}`); + } // process requests const response = await getRequestResult(