From 5ee006f5d04c9ef1a8ccc2c57d8bb28dfa8253ab Mon Sep 17 00:00:00 2001 From: rodrigopavezi Date: Wed, 2 Oct 2024 08:38:19 -0300 Subject: [PATCH 1/4] fix: enhance logging for request node --- packages/request-node/package.json | 2 ++ packages/request-node/src/request/ipfsAdd.ts | 20 +++++++++++++--- .../src/request/persistTransaction.ts | 24 ++++++++++++++++--- packages/request-node/src/requestNode.ts | 4 ++++ yarn.lock | 11 +++++++-- 5 files changed, 53 insertions(+), 8 deletions(-) diff --git a/packages/request-node/package.json b/packages/request-node/package.json index b39b9dbf46..b969206efa 100644 --- a/packages/request-node/package.json +++ b/packages/request-node/package.json @@ -58,6 +58,7 @@ "graphql-request": "6.1.0", "http-shutdown": "1.2.2", "http-status-codes": "2.1.4", + "morgan": "^1.10.0", "shelljs": "0.8.5", "tslib": "2.5.0", "yargs": "17.6.2" @@ -66,6 +67,7 @@ "@types/cors": "2.8.9", "@types/express": "4.17.17", "@types/jest": "29.5.6", + "@types/morgan": "^1.9.9", "@types/node": "18.11.9", "@types/supertest": "2.0.10", "@types/yargs": "17.0.14", diff --git a/packages/request-node/src/request/ipfsAdd.ts b/packages/request-node/src/request/ipfsAdd.ts index 7160c62fa3..c583aac992 100644 --- a/packages/request-node/src/request/ipfsAdd.ts +++ b/packages/request-node/src/request/ipfsAdd.ts @@ -26,7 +26,10 @@ export default class IpfsAddHandler { // Set the timeout from the value from config and convert seconds to milliseconds /* eslint-disable no-magic-numbers */ - clientRequest.setTimeout(getPersistTransactionTimeout() * 1000); + clientRequest.setTimeout(getPersistTransactionTimeout() * 1000, () => { + this.logger.error('ipfs add timeout'); + serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('ipfs add timeout'); + }); // Verifies if data send from post are correct // clientRequest.body is expected to contain data for data-acces layer: @@ -48,12 +51,23 @@ export default class IpfsAddHandler { JSON.stringify(clientRequest.body.data), ); - this.logger.debug(`ipfsAdd successfully completed`, ['metric', 'successRate']); + this.logger.debug( + `ipfsAdd successfully completed ${JSON.stringify({ + ipfsHash: dataAccessResponse.ipfsHash, + ipfsSize: dataAccessResponse.ipfsSize, + })}`, + ['metric', 'successRate'], + ); serverResponse.status(StatusCodes.OK).send(dataAccessResponse); } catch (e) { this.logger.error(`ipfsAdd error: ${e}`); - this.logger.debug(`ipfsAdd fail`, ['metric', 'successRate']); + this.logger.debug( + `ipfsAdd fail ${JSON.stringify({ + data: clientRequest.body.data, + })}`, + ['metric', 'successRate'], + ); serverResponse.status(StatusCodes.INTERNAL_SERVER_ERROR).send(e); } diff --git a/packages/request-node/src/request/persistTransaction.ts b/packages/request-node/src/request/persistTransaction.ts index ca16b8864e..eb50fabf35 100644 --- a/packages/request-node/src/request/persistTransaction.ts +++ b/packages/request-node/src/request/persistTransaction.ts @@ -32,7 +32,10 @@ export default class PersistTransactionHandler { // Set the timeout from the value from config and convert seconds to milliseconds /* eslint-disable no-magic-numbers */ - clientRequest.setTimeout(getPersistTransactionTimeout() * 1000); + clientRequest.setTimeout(getPersistTransactionTimeout() * 1000, () => { + this.logger.error('persistTransaction timeout'); + serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('persistTransaction timeout'); + }); // Verifies if data send from post are correct // clientRequest.body is expected to contain data for data-acces layer: @@ -83,12 +86,27 @@ export default class PersistTransactionHandler { )}`); }); - this.logger.debug(`persistTransaction successfully completed`, ['metric', 'successRate']); + this.logger.debug( + `persistTransaction successfully completed ${JSON.stringify({ + transactionHash, + channelId: clientRequest.body.channelId, + topics: clientRequest.body.topics, + transactionData: clientRequest.body.transactionData, + })}`, + ['metric', 'successRate'], + ); serverResponse.status(StatusCodes.OK).send(dataAccessResponse); } catch (e) { this.logger.error(`persistTransaction error: ${e}`); - this.logger.debug(`persistTransaction fail`, ['metric', 'successRate']); + this.logger.debug( + `persistTransaction fail ${JSON.stringify({ + channelId: clientRequest.body.channelId, + topics: clientRequest.body.topics, + transactionData: clientRequest.body.transactionData, + })}`, + ['metric', 'successRate'], + ); serverResponse.status(StatusCodes.INTERNAL_SERVER_ERROR).send(e); } diff --git a/packages/request-node/src/requestNode.ts b/packages/request-node/src/requestNode.ts index 0346e74592..52dc724b58 100644 --- a/packages/request-node/src/requestNode.ts +++ b/packages/request-node/src/requestNode.ts @@ -11,6 +11,7 @@ import PersistTransactionHandler from './request/persistTransaction'; import GetChannelsByTopicHandler from './request/getChannelsByTopic'; import GetStatusHandler from './request/getStatus'; import IpfsAddHandler from './request/ipfsAdd'; +import morgan from 'morgan'; // eslint-disable-next-line @typescript-eslint/no-var-requires const packageJson = require('../package.json'); @@ -133,6 +134,9 @@ export class RequestNode { // Enable all CORS requests this.express.use(cors()); + // Enable logging of all requests + this.express.use(morgan('combined')); + // Set the Request Node version to the header this.express.use((_, res, next) => { res.header(REQUEST_NODE_VERSION_HEADER, this.requestNodeVersion); diff --git a/yarn.lock b/yarn.lock index 25e032bf0f..ffa415edb7 100644 --- a/yarn.lock +++ b/yarn.lock @@ -5319,6 +5319,13 @@ resolved "https://registry.npmjs.org/@types/mocha/-/mocha-8.2.3.tgz" integrity sha512-ekGvFhFgrc2zYQoX4JeZPmVzZxw6Dtllga7iGHzfbYIYkAMUx/sAFP2GdFpLff+vdHXu5fl7WX9AT+TtqYcsyw== +"@types/morgan@^1.9.9": + version "1.9.9" + resolved "https://registry.yarnpkg.com/@types/morgan/-/morgan-1.9.9.tgz#d60dec3979e16c203a000159daa07d3fb7270d7f" + integrity sha512-iRYSDKVaC6FkGSpEVVIvrRGw0DfJMiQzIn3qr2G5B3C//AWkulhXgaBd7tS9/J79GWSYMTHGs7PfI5b3Y8m+RQ== + dependencies: + "@types/node" "*" + "@types/multicoin-address-validator@0.5.0": version "0.5.0" resolved "https://registry.npmjs.org/@types/multicoin-address-validator/-/multicoin-address-validator-0.5.0.tgz" @@ -16876,9 +16883,9 @@ module-error@^1.0.1, module-error@^1.0.2: resolved "https://registry.npmjs.org/module-error/-/module-error-1.0.2.tgz" integrity sha512-0yuvsqSCv8LbaOKhnsQ/T5JhyFlCYLPXK3U2sgV10zoKQwzs/MyfuQUOZQ1V/6OCOJsK/TRgNVrPuPDqtdMFtA== -morgan@^1.9.1: +morgan@^1.10.0, morgan@^1.9.1: version "1.10.0" - resolved "https://registry.npmjs.org/morgan/-/morgan-1.10.0.tgz" + resolved "https://registry.yarnpkg.com/morgan/-/morgan-1.10.0.tgz#091778abc1fc47cd3509824653dae1faab6b17d7" integrity sha512-AbegBVI4sh6El+1gNwvD5YIck7nSA36weD7xvIxG4in80j/UoK8AEGaWnnz8v1GxonMCltmlNs5ZKbGvl9b1XQ== dependencies: basic-auth "~2.0.1" From 2436a4faa9e97a69f5e87dc755eedb8dfcdcca71 Mon Sep 17 00:00:00 2001 From: rodrigopavezi Date: Wed, 2 Oct 2024 09:49:20 -0300 Subject: [PATCH 2/4] fix: lock morgan version --- packages/request-node/package.json | 4 ++-- yarn.lock | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-) diff --git a/packages/request-node/package.json b/packages/request-node/package.json index b969206efa..9d831e19e9 100644 --- a/packages/request-node/package.json +++ b/packages/request-node/package.json @@ -58,7 +58,7 @@ "graphql-request": "6.1.0", "http-shutdown": "1.2.2", "http-status-codes": "2.1.4", - "morgan": "^1.10.0", + "morgan": "1.10.0", "shelljs": "0.8.5", "tslib": "2.5.0", "yargs": "17.6.2" @@ -67,7 +67,7 @@ "@types/cors": "2.8.9", "@types/express": "4.17.17", "@types/jest": "29.5.6", - "@types/morgan": "^1.9.9", + "@types/morgan": "1.9.9", "@types/node": "18.11.9", "@types/supertest": "2.0.10", "@types/yargs": "17.0.14", diff --git a/yarn.lock b/yarn.lock index ffa415edb7..4c6bf438fb 100644 --- a/yarn.lock +++ b/yarn.lock @@ -5319,7 +5319,7 @@ resolved "https://registry.npmjs.org/@types/mocha/-/mocha-8.2.3.tgz" integrity sha512-ekGvFhFgrc2zYQoX4JeZPmVzZxw6Dtllga7iGHzfbYIYkAMUx/sAFP2GdFpLff+vdHXu5fl7WX9AT+TtqYcsyw== -"@types/morgan@^1.9.9": +"@types/morgan@1.9.9": version "1.9.9" resolved "https://registry.yarnpkg.com/@types/morgan/-/morgan-1.9.9.tgz#d60dec3979e16c203a000159daa07d3fb7270d7f" integrity sha512-iRYSDKVaC6FkGSpEVVIvrRGw0DfJMiQzIn3qr2G5B3C//AWkulhXgaBd7tS9/J79GWSYMTHGs7PfI5b3Y8m+RQ== @@ -16883,7 +16883,7 @@ module-error@^1.0.1, module-error@^1.0.2: resolved "https://registry.npmjs.org/module-error/-/module-error-1.0.2.tgz" integrity sha512-0yuvsqSCv8LbaOKhnsQ/T5JhyFlCYLPXK3U2sgV10zoKQwzs/MyfuQUOZQ1V/6OCOJsK/TRgNVrPuPDqtdMFtA== -morgan@^1.10.0, morgan@^1.9.1: +morgan@1.10.0, morgan@^1.9.1: version "1.10.0" resolved "https://registry.yarnpkg.com/morgan/-/morgan-1.10.0.tgz#091778abc1fc47cd3509824653dae1faab6b17d7" integrity sha512-AbegBVI4sh6El+1gNwvD5YIck7nSA36weD7xvIxG4in80j/UoK8AEGaWnnz8v1GxonMCltmlNs5ZKbGvl9b1XQ== From cda06df52a64de8f9f49110dc0532fa0f7b753c9 Mon Sep 17 00:00:00 2001 From: rodrigopavezi Date: Thu, 3 Oct 2024 08:46:33 -0300 Subject: [PATCH 3/4] fix: address review issues --- packages/request-node/src/request/ipfsAdd.ts | 11 +++--- .../src/request/persistTransaction.ts | 35 +++++++++++-------- 2 files changed, 27 insertions(+), 19 deletions(-) diff --git a/packages/request-node/src/request/ipfsAdd.ts b/packages/request-node/src/request/ipfsAdd.ts index c583aac992..104155d35d 100644 --- a/packages/request-node/src/request/ipfsAdd.ts +++ b/packages/request-node/src/request/ipfsAdd.ts @@ -27,8 +27,10 @@ export default class IpfsAddHandler { // Set the timeout from the value from config and convert seconds to milliseconds /* eslint-disable no-magic-numbers */ clientRequest.setTimeout(getPersistTransactionTimeout() * 1000, () => { - this.logger.error('ipfs add timeout'); - serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('ipfs add timeout'); + this.logger.error(`ipfsAdd timeout. clientRequest.body.data: ${clientRequest.body.data}`, [ + 'timeout', + ]); + serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('ipfsAdd timeout'); }); // Verifies if data send from post are correct @@ -61,12 +63,11 @@ export default class IpfsAddHandler { serverResponse.status(StatusCodes.OK).send(dataAccessResponse); } catch (e) { - this.logger.error(`ipfsAdd error: ${e}`); - this.logger.debug( + this.logger.error( `ipfsAdd fail ${JSON.stringify({ + error: e, data: clientRequest.body.data, })}`, - ['metric', 'successRate'], ); serverResponse.status(StatusCodes.INTERNAL_SERVER_ERROR).send(e); diff --git a/packages/request-node/src/request/persistTransaction.ts b/packages/request-node/src/request/persistTransaction.ts index eb50fabf35..83db414ef7 100644 --- a/packages/request-node/src/request/persistTransaction.ts +++ b/packages/request-node/src/request/persistTransaction.ts @@ -30,10 +30,20 @@ export default class PersistTransactionHandler { // Retrieves data access layer let dataAccessResponse: DataAccessTypes.IReturnPersistTransaction; + const transactionHash: MultiFormatTypes.HashTypes.IHash = normalizeKeccak256Hash( + clientRequest.body.transactionData, + ); + // Set the timeout from the value from config and convert seconds to milliseconds /* eslint-disable no-magic-numbers */ clientRequest.setTimeout(getPersistTransactionTimeout() * 1000, () => { - this.logger.error('persistTransaction timeout'); + this.logger.error( + `persistTransaction timeout ${JSON.stringify({ + transactionHash, + channelId: clientRequest.body.channelId, + })}`, + ['timeout'], + ); serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('persistTransaction timeout'); }); @@ -50,10 +60,6 @@ export default class PersistTransactionHandler { return; } try { - const transactionHash: MultiFormatTypes.HashTypes.IHash = normalizeKeccak256Hash( - clientRequest.body.transactionData, - ); - this.logger.debug( `Persisting Transaction: ${JSON.stringify({ transactionHash, @@ -70,10 +76,13 @@ export default class PersistTransactionHandler { ); dataAccessResponse.on('confirmed', async () => { - this.logger.info(`Transaction confirmed: ${transactionHash.value}`, [ - 'metric', - 'successRate', - ]); + this.logger.info( + `Transaction confirmed: ${JSON.stringify({ + transactionHash, + channelId: clientRequest.body.channelId, + })}`, + ['metric', 'successRate'], + ); }); // when the transaction fails, log an error @@ -90,22 +99,20 @@ export default class PersistTransactionHandler { `persistTransaction successfully completed ${JSON.stringify({ transactionHash, channelId: clientRequest.body.channelId, - topics: clientRequest.body.topics, - transactionData: clientRequest.body.transactionData, })}`, ['metric', 'successRate'], ); serverResponse.status(StatusCodes.OK).send(dataAccessResponse); } catch (e) { - this.logger.error(`persistTransaction error: ${e}`); - this.logger.debug( + this.logger.error( `persistTransaction fail ${JSON.stringify({ + error: e, + transactionHash, channelId: clientRequest.body.channelId, topics: clientRequest.body.topics, transactionData: clientRequest.body.transactionData, })}`, - ['metric', 'successRate'], ); serverResponse.status(StatusCodes.INTERNAL_SERVER_ERROR).send(e); From 96ccf7e96fad1413073c8b6b217a651e90a49f77 Mon Sep 17 00:00:00 2001 From: rodrigopavezi Date: Thu, 3 Oct 2024 12:24:50 -0300 Subject: [PATCH 4/4] fix: move things around to make sure variables are available for logging --- packages/request-node/src/request/ipfsAdd.ts | 18 ++++++------- .../src/request/persistTransaction.ts | 25 ++++++++++--------- 2 files changed, 22 insertions(+), 21 deletions(-) diff --git a/packages/request-node/src/request/ipfsAdd.ts b/packages/request-node/src/request/ipfsAdd.ts index 104155d35d..214afff822 100644 --- a/packages/request-node/src/request/ipfsAdd.ts +++ b/packages/request-node/src/request/ipfsAdd.ts @@ -24,15 +24,6 @@ export default class IpfsAddHandler { // Retrieves data access layer let dataAccessResponse; - // Set the timeout from the value from config and convert seconds to milliseconds - /* eslint-disable no-magic-numbers */ - clientRequest.setTimeout(getPersistTransactionTimeout() * 1000, () => { - this.logger.error(`ipfsAdd timeout. clientRequest.body.data: ${clientRequest.body.data}`, [ - 'timeout', - ]); - serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('ipfsAdd timeout'); - }); - // Verifies if data send from post are correct // clientRequest.body is expected to contain data for data-acces layer: // transactionData: data of the transaction @@ -48,6 +39,15 @@ export default class IpfsAddHandler { return; } + // Set the timeout from the value from config and convert seconds to milliseconds + /* eslint-disable no-magic-numbers */ + clientRequest.setTimeout(getPersistTransactionTimeout() * 1000, () => { + this.logger.error(`ipfsAdd timeout. clientRequest.body.data: ${clientRequest.body.data}`, [ + 'timeout', + ]); + serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('ipfsAdd timeout'); + }); + try { dataAccessResponse = await this.ipfsStorage.ipfsAdd( JSON.stringify(clientRequest.body.data), diff --git a/packages/request-node/src/request/persistTransaction.ts b/packages/request-node/src/request/persistTransaction.ts index 83db414ef7..25305978ce 100644 --- a/packages/request-node/src/request/persistTransaction.ts +++ b/packages/request-node/src/request/persistTransaction.ts @@ -30,6 +30,19 @@ export default class PersistTransactionHandler { // Retrieves data access layer let dataAccessResponse: DataAccessTypes.IReturnPersistTransaction; + // Verifies if data send from post are correct + // clientRequest.body is expected to contain data for data-acces layer: + // transactionData: data of the transaction + // topics (optional): arbitrary strings that reference the transaction + if ( + !clientRequest.body || + !clientRequest.body.transactionData || + !clientRequest.body.channelId + ) { + serverResponse.status(StatusCodes.UNPROCESSABLE_ENTITY).send('Incorrect data'); + return; + } + const transactionHash: MultiFormatTypes.HashTypes.IHash = normalizeKeccak256Hash( clientRequest.body.transactionData, ); @@ -47,18 +60,6 @@ export default class PersistTransactionHandler { serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('persistTransaction timeout'); }); - // Verifies if data send from post are correct - // clientRequest.body is expected to contain data for data-acces layer: - // transactionData: data of the transaction - // topics (optional): arbitrary strings that reference the transaction - if ( - !clientRequest.body || - !clientRequest.body.transactionData || - !clientRequest.body.channelId - ) { - serverResponse.status(StatusCodes.UNPROCESSABLE_ENTITY).send('Incorrect data'); - return; - } try { this.logger.debug( `Persisting Transaction: ${JSON.stringify({