Expand gateway request logging in AWS, GCP, and airnode-client (#1526)

* Replace bodyParser with express as express.json available since 4.16.0 * Expand gateway request logging in AWS, GCP, and airnode-client * Use debug rather than info, remove unnecessary logs * Leverage logger metadata instead of using strings
api3dao · Nov 21, 2022 · ee3e4cd · ee3e4cd
1 parent 6b0ae76
commit ee3e4cd
Show file tree

Hide file tree

Showing 5 changed files with 77 additions and 6 deletions.
diff --git a/.changeset/spicy-ligers-raise.md b/.changeset/spicy-ligers-raise.md
@@ -0,0 +1,6 @@
+---
+'@api3/airnode-deployer': minor
+'@api3/airnode-node': minor
+---
+
+Expand gateway request logging
diff --git a/packages/airnode-deployer/src/handlers/aws/index.ts b/packages/airnode-deployer/src/handlers/aws/index.ts
@@ -117,6 +117,8 @@ export async function processHttpRequest(
     level: parsedConfig.nodeSettings.logLevel,
   });
 
+  logger.debug(`HTTP gateway request received`);
+
   // Check if the request origin header is allowed in the config
   const originVerification = verifyRequestOrigin(
     (parsedConfig.nodeSettings.httpGateway as EnabledGateway).corsOrigins,
@@ -125,11 +127,13 @@ export async function processHttpRequest(
   // Respond to preflight requests
   if (event.httpMethod === 'OPTIONS') {
     if (!originVerification.success) {
+      logger.error(`HTTP gateway request origin verification error`);
       return { statusCode: 400, body: JSON.stringify(originVerification.error) };
     }
 
     return { statusCode: 204, headers: originVerification.headers, body: '' };
   }
+  logger.debug(`HTTP gateway request passed origin verification`);
 
   // The shape of the body is guaranteed by the openAPI spec
   const rawParameters = (JSON.parse(event.body!) as ProcessHttpRequestBody).parameters;
@@ -139,16 +143,20 @@ export async function processHttpRequest(
   const verificationResult = verifyHttpRequest(parsedConfig, rawParameters, rawEndpointId);
   if (!verificationResult.success) {
     const { statusCode, error } = verificationResult;
+    logger.error(`HTTP gateway request verification error`);
     return { statusCode, headers: originVerification.headers, body: JSON.stringify(error) };
   }
   const { parameters, endpointId } = verificationResult;
 
   addMetadata({ 'Endpoint-ID': endpointId });
+  logger.debug(`HTTP gateway request passed request verification`);
   const [err, result] = await handlers.processHttpRequest(parsedConfig, endpointId, parameters);
   if (err) {
     // Returning 500 because failure here means something went wrong internally with a valid request
+    logger.error(`HTTP gateway request processing error`);
     return { statusCode: 500, headers: originVerification.headers, body: JSON.stringify({ message: err.toString() }) };
   }
+  logger.debug(`HTTP gateway request processed successfully`);
 
   // We do not want the user to see {"success": true, "data": <actual_data>}, but the actual data itself
   return { statusCode: 200, headers: originVerification.headers, body: JSON.stringify(result!.data) };
@@ -168,6 +176,8 @@ export async function processHttpSignedDataRequest(
     level: parsedConfig.nodeSettings.logLevel,
   });
 
+  logger.debug(`HTTP signed data gateway request received`);
+
   // Check if the request origin header is allowed in the config
   const originVerification = verifyRequestOrigin(
     (parsedConfig.nodeSettings.httpSignedDataGateway as EnabledGateway).corsOrigins,
@@ -176,11 +186,13 @@ export async function processHttpSignedDataRequest(
   // Respond to preflight requests
   if (event.httpMethod === 'OPTIONS') {
     if (!originVerification.success) {
+      logger.error(`HTTP signed data gateway request origin verification error`);
       return { statusCode: 400, body: JSON.stringify(originVerification.error) };
     }
 
     return { statusCode: 204, headers: originVerification.headers, body: '' };
   }
+  logger.debug(`HTTP signed data gateway request passed origin verification`);
 
   // The shape of the body is guaranteed by the openAPI spec
   const rawEncodedParameters = (JSON.parse(event.body!) as ProcessHttpSignedDataRequestBody).encodedParameters;
@@ -189,17 +201,21 @@ export async function processHttpSignedDataRequest(
 
   const verificationResult = verifyHttpSignedDataRequest(parsedConfig, rawEncodedParameters, rawEndpointId);
   if (!verificationResult.success) {
+    logger.error(`HTTP signed data gateway request verification error`);
     const { statusCode, error } = verificationResult;
     return { statusCode, headers: originVerification.headers, body: JSON.stringify(error) };
   }
   const { encodedParameters, endpointId } = verificationResult;
 
   addMetadata({ 'Endpoint-ID': endpointId });
+  logger.debug(`HTTP signed data gateway request passed request verification`);
   const [err, result] = await handlers.processHttpSignedDataRequest(parsedConfig, endpointId, encodedParameters);
   if (err) {
     // Returning 500 because failure here means something went wrong internally with a valid request
+    logger.error(`HTTP signed data gateway request processing error`);
     return { statusCode: 500, headers: originVerification.headers, body: JSON.stringify({ message: err.toString() }) };
   }
+  logger.debug(`HTTP signed data gateway request processed successfully`);
 
   // We do not want the user to see {"success": true, "data": <actual_data>}, but the actual data itself
   return { statusCode: 200, headers: originVerification.headers, body: JSON.stringify(result!.data) };

diff --git a/packages/airnode-deployer/src/handlers/gcp/index.ts b/packages/airnode-deployer/src/handlers/gcp/index.ts
@@ -120,6 +120,8 @@ export async function processHttpRequest(req: Request, res: Response) {
     level: parsedConfig.nodeSettings.logLevel,
   });
 
+  logger.debug(`HTTP gateway request received`);
+
   // Check if the request origin header is allowed in the config
   const originVerification = verifyRequestOrigin(
     (parsedConfig.nodeSettings.httpGateway as EnabledGateway).corsOrigins,
@@ -128,6 +130,7 @@ export async function processHttpRequest(req: Request, res: Response) {
   // Respond to preflight requests
   if (req.method === 'OPTIONS') {
     if (!originVerification.success) {
+      logger.error(`HTTP gateway request origin verification error`);
       res.status(400).send(originVerification.error);
       return;
     }
@@ -137,34 +140,41 @@ export async function processHttpRequest(req: Request, res: Response) {
   }
   // Set headers for the responses
   res.set(originVerification.headers);
+  logger.debug(`HTTP gateway request passed origin verification`);
 
   const parsedBody = httpRequestBodySchema.safeParse(req.body);
   if (!parsedBody.success) {
     // This error and status code is returned by AWS gateway when the request does not match the openAPI
     // specification. We want the same error to be returned by the GCP gateway.
+    logger.error(`HTTP gateway request invalid request body`);
     res.status(400).send({ message: 'Invalid request body' });
     return;
   }
   const { parameters: rawParameters } = parsedBody.data;
 
   // Guaranteed to exist by the openAPI schema
   const { endpointId: rawEndpointId } = req.query;
+  logger.debug(`HTTP gateway request passed request body parsing`);
 
   const verificationResult = verifyHttpRequest(parsedConfig, rawParameters, rawEndpointId as string);
   if (!verificationResult.success) {
     const { statusCode, error } = verificationResult;
+    logger.error(`HTTP gateway request verification error`);
     res.status(statusCode).send(error);
     return;
   }
   const { parameters, endpointId } = verificationResult;
 
   addMetadata({ 'Endpoint-ID': endpointId });
+  logger.debug(`HTTP gateway request passed request verification`);
   const [err, result] = await handlers.processHttpRequest(parsedConfig, endpointId, parameters);
   if (err) {
     // Returning 500 because failure here means something went wrong internally with a valid request
+    logger.error(`HTTP gateway request processing error`);
     res.status(500).send({ message: err.toString() });
     return;
   }
+  logger.debug(`HTTP gateway request processed successfully`);
 
   // We do not want the user to see {"success": true, "data": <actual_data>}, but the actual data itself
   res.status(200).send(result!.data);
@@ -183,6 +193,8 @@ export async function processHttpSignedDataRequest(req: Request, res: Response)
     level: parsedConfig.nodeSettings.logLevel,
   });
 
+  logger.debug(`HTTP signed data gateway request received`);
+
   // Check if the request origin header is allowed in the config
   const originVerification = verifyRequestOrigin(
     (parsedConfig.nodeSettings.httpSignedDataGateway as EnabledGateway).corsOrigins,
@@ -191,6 +203,7 @@ export async function processHttpSignedDataRequest(req: Request, res: Response)
   // Respond to preflight requests
   if (req.method === 'OPTIONS') {
     if (!originVerification.success) {
+      logger.error(`HTTP signed data gateway request origin verification error`);
       res.status(400).send(originVerification.error);
       return;
     }
@@ -200,38 +213,45 @@ export async function processHttpSignedDataRequest(req: Request, res: Response)
   }
   // Set headers for the responses
   res.set(originVerification.headers);
+  logger.debug(`HTTP signed data gateway request passed origin verification`);
 
   const parsedBody = httpSignedDataBodySchema.safeParse(req.body);
   if (!parsedBody.success) {
     // This error and status code is returned by AWS gateway when the request does not match the openAPI
     // specification. We want the same error to be returned by the GCP gateway.
+    logger.error(`HTTP signed data gateway request invalid request body`);
     res.status(400).send({ message: 'Invalid request body' });
     return;
   }
   const { encodedParameters: rawEncodedParameters } = parsedBody.data;
 
   // Guaranteed to exist by the openAPI schema
   const { endpointId: rawEndpointId } = req.query;
+  logger.debug(`HTTP signed data gateway request passed request body parsing`);
 
   const verificationResult = verifyHttpSignedDataRequest(parsedConfig, rawEncodedParameters, rawEndpointId as string);
   if (!verificationResult.success) {
     const { statusCode, error } = verificationResult;
+    logger.error(`HTTP signed data gateway request verification error`);
     res.status(statusCode).send(error);
     return;
   }
   const { encodedParameters, endpointId } = verificationResult;
 
   addMetadata({ 'Endpoint-ID': endpointId });
+  logger.debug(`HTTP signed data gateway request passed request verification`);
   const [err, result] = await handlers.processHttpSignedDataRequest(
     parsedConfig,
     endpointId as string,
     encodedParameters
   );
   if (err) {
     // Returning 500 because failure here means something went wrong internally with a valid request
+    logger.error(`HTTP signed data gateway request processing error`);
     res.status(500).send({ message: err.toString() });
     return;
   }
+  logger.debug(`HTTP signed data gateway request processed successfully`);
 
   // We do not want the user to see {"success": true, "data": <actual_data>}, but the actual data itself
   res.status(200).send(result!.data);

diff --git a/packages/airnode-node/package.json b/packages/airnode-node/package.json
@@ -32,7 +32,6 @@
     "@api3/ois": "1.2.0",
     "@api3/promise-utils": "^0.3.0",
     "aws-sdk": "^2.1243.0",
-    "body-parser": "^1.20.1",
     "dotenv": "^16.0.3",
     "ethers": "^5.7.2",
     "express": "^4.18.2",

diff --git a/packages/airnode-node/src/workers/local-gateways/server.ts b/packages/airnode-node/src/workers/local-gateways/server.ts
@@ -1,7 +1,7 @@
-import { logger } from '@api3/airnode-utilities';
+import { randomUUID } from 'crypto';
+import { addMetadata, logger, setLogOptions } from '@api3/airnode-utilities';
 import express, { Request, Response } from 'express';
 import { z } from 'zod';
-import bodyParser from 'body-parser';
 import { verifyHttpRequest, verifyHttpSignedDataRequest, verifyRequestOrigin } from './validation';
 import { Config, EnabledGateway, LocalProvider } from '../../config';
 import { processHttpRequest, processHttpSignedDataRequest } from '../../handlers';
@@ -35,21 +35,28 @@ export function startGatewayServer(config: Config, enabledGateways: GatewayName[
   }
 
   const app = express();
-  app.use(bodyParser.json());
+  app.use(express.json());
   const cloudProviderSettings = config.nodeSettings.cloudProvider as LocalProvider;
   const port = cloudProviderSettings.gatewayServerPort ?? DEFAULT_PORT;
 
   if (enabledGateways.includes('httpSignedDataGateway')) {
     const httpSignedDataGatewayPath = `${HTTP_SIGNED_DATA_BASE_PATH}/${DEFAULT_PATH_KEY}/:endpointId`;
     const httpSignedDataRequestHandler = async function (req: Request, res: Response) {
-      logger.log(`Received request for http signed data`);
+      setLogOptions({
+        format: config.nodeSettings.logFormat,
+        level: config.nodeSettings.logLevel,
+        meta: { requestId: randomUUID() },
+      });
+
+      logger.debug(`HTTP signed data gateway request received`);
 
       const originVerification = verifyRequestOrigin(
         (config.nodeSettings.httpSignedDataGateway as EnabledGateway).corsOrigins,
         req.headers.origin
       );
       if (req.method === 'OPTIONS') {
         if (!originVerification.success) {
+          logger.error(`HTTP signed data gateway request origin verification error`);
           res.status(400).send(originVerification.error);
           return;
         }
@@ -62,31 +69,39 @@ export function startGatewayServer(config: Config, enabledGateways: GatewayName[
       // flighted, none of the origin headers are applied, but the request goes through. This ensures that non browser
       // requests work as expected.
       res.set(originVerification.headers);
+      logger.debug(`HTTP signed data gateway request passed origin verification`);
 
       const parsedBody = httpSignedDataBodySchema.safeParse(req.body);
       if (!parsedBody.success) {
         // This error and status code is returned by AWS gateway when the request does not match the openAPI
         // specification.
+        logger.error(`HTTP signed data gateway request invalid request body`);
         res.status(400).send({ message: 'Invalid request body' });
         return;
       }
       const { encodedParameters: rawEncodedParameters } = parsedBody.data;
 
       const rawEndpointId = req.params.endpointId;
+      logger.debug(`HTTP signed data gateway request passed request body parsing`);
       const verificationResult = verifyHttpSignedDataRequest(config, rawEncodedParameters, rawEndpointId);
       if (!verificationResult.success) {
         const { statusCode, error } = verificationResult;
+        logger.error(`HTTP signed data gateway request verification error`);
         res.status(statusCode).send(error);
         return;
       }
       const { encodedParameters, endpointId } = verificationResult;
+      addMetadata({ 'Endpoint-ID': endpointId });
+      logger.debug(`HTTP signed data gateway request passed request verification`);
 
       const [err, result] = await processHttpSignedDataRequest(config, endpointId, encodedParameters);
       if (err) {
         // Returning 500 because failure here means something went wrong internally with a valid request
+        logger.error(`HTTP signed data gateway request processing error`);
         res.status(500).send({ message: err.toString() });
         return;
       }
+      logger.debug(`HTTP signed data gateway request processed successfully`);
 
       // We do not want the user to see {"success": true, "data": <actual_data>}, but the actual data itself
       res.status(200).send(result!.data);
@@ -103,7 +118,13 @@ export function startGatewayServer(config: Config, enabledGateways: GatewayName[
   if (enabledGateways.includes('httpGateway')) {
     const httpGatewayPath = `${HTTP_BASE_PATH}/${DEFAULT_PATH_KEY}/:endpointId`;
     const httpRequestHandler = async function (req: Request, res: Response) {
-      logger.log(`Received request for http data`);
+      setLogOptions({
+        format: config.nodeSettings.logFormat,
+        level: config.nodeSettings.logLevel,
+        meta: { requestId: randomUUID() },
+      });
+
+      logger.debug(`HTTP gateway request received`);
 
       const originVerification = verifyRequestOrigin(
         (config.nodeSettings.httpGateway as EnabledGateway).corsOrigins,
@@ -112,6 +133,7 @@ export function startGatewayServer(config: Config, enabledGateways: GatewayName[
 
       if (req.method === 'OPTIONS') {
         if (!originVerification.success) {
+          logger.error(`HTTP gateway request origin verification error`);
           res.status(400).send(originVerification.error);
           return;
         }
@@ -124,31 +146,39 @@ export function startGatewayServer(config: Config, enabledGateways: GatewayName[
       // flighted, none of the origin headers are applied, but the request goes through. This ensures that non browser
       // requests work as expected.
       res.set(originVerification.headers);
+      logger.debug(`HTTP gateway request passed origin verification`);
 
       const parsedBody = httpRequestBodySchema.safeParse(req.body);
       if (!parsedBody.success) {
         // This error and status code is returned by AWS gateway when the request does not match the openAPI
         // specification.
+        logger.error(`HTTP gateway request invalid request body`);
         res.status(400).send({ message: 'Invalid request body' });
         return;
       }
       const { parameters: rawParameters } = parsedBody.data;
 
       const rawEndpointId = req.params.endpointId;
+      logger.debug(`HTTP gateway request passed request body parsing`);
       const verificationResult = verifyHttpRequest(config, rawParameters, rawEndpointId);
       if (!verificationResult.success) {
         const { statusCode, error } = verificationResult;
+        logger.error(`HTTP gateway request verification error`);
         res.status(statusCode).send(error);
         return;
       }
       const { parameters, endpointId } = verificationResult;
+      addMetadata({ 'Endpoint-ID': endpointId });
+      logger.debug(`HTTP gateway request passed request verification`);
 
       const [err, result] = await processHttpRequest(config, endpointId, parameters);
       if (err) {
         // Returning 500 because failure here means something went wrong internally with a valid request
+        logger.error(`HTTP gateway request processing error`);
         res.status(500).send({ message: err.toString() });
         return;
       }
+      logger.debug(`HTTP gateway request processed successfully`);
 
       // We do not want the user to see {"success": true, "data": <actual_data>}, but the actual data itself
       res.status(200).send(result!.data);