fix: enhance logging for request node

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",

packages/request-node/src/request/ipfsAdd.ts

@@ -24,10 +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);
-
  // Verifies if data send from post are correct
  // clientRequest.body is expected to contain data for data-acces layer:
  // transactionData: data of the transaction
@@ -43,17 +39,36 @@ 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),
  );
 
- 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.error(
+ `ipfsAdd fail ${JSON.stringify({
+ error: e,
+ data: clientRequest.body.data,
+ })}`,
+ );
 
  serverResponse.status(StatusCodes.INTERNAL_SERVER_ERROR).send(e);
  }

packages/request-node/src/request/persistTransaction.ts

@@ -30,10 +30,6 @@ export default class PersistTransactionHandler {
  // Retrieves data access layer
  let dataAccessResponse: DataAccessTypes.IReturnPersistTransaction;
 
- // Set the timeout from the value from config and convert seconds to milliseconds
- /* eslint-disable no-magic-numbers */
- clientRequest.setTimeout(getPersistTransactionTimeout() * 1000);
-
  // Verifies if data send from post are correct
  // clientRequest.body is expected to contain data for data-acces layer:
  // transactionData: data of the transaction
@@ -46,11 +42,25 @@ export default class PersistTransactionHandler {
  serverResponse.status(StatusCodes.UNPROCESSABLE_ENTITY).send('Incorrect data');
  return;
  }
- try {
- const transactionHash: MultiFormatTypes.HashTypes.IHash = normalizeKeccak256Hash(
- clientRequest.body.transactionData,
+
+ 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 ${JSON.stringify({
+ transactionHash,
+ channelId: clientRequest.body.channelId,
+ })}`,
+ ['timeout'],
  );
+ serverResponse.status(StatusCodes.GATEWAY_TIMEOUT).send('persistTransaction timeout');
+ });
 
+ try {
  this.logger.debug(
  `Persisting Transaction: ${JSON.stringify({
  transactionHash,
@@ -67,10 +77,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
@@ -83,12 +96,25 @@ 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,
+ })}`,
+ ['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.error(
+ `persistTransaction fail ${JSON.stringify({
+ error: e,
+ transactionHash,
+ channelId: clientRequest.body.channelId,
+ topics: clientRequest.body.topics,
+ transactionData: clientRequest.body.transactionData,
+ })}`,
+ );
 
  serverResponse.status(StatusCodes.INTERNAL_SERVER_ERROR).send(e);
  }

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);

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"