feature/IO-3029-Enhanced-Logging-File-Based: Adjust XML and JSON log to always upload

Signed-off-by: Dave Richer <dave@imexsystems.ca>

.gitattributes

@@ -0,0 +1 @@
+* text eol=lf

docker-compose.yml

@@ -74,7 +74,7 @@ services:
     volumes:
       - /var/run/docker.sock:/var/run/docker.sock
     environment:
-      - SERVICES=ses,secretsmanager,cloudwatch,logs
+      - SERVICES=s3,ses,secretsmanager,cloudwatch,logs
       - DEBUG=0
       - AWS_ACCESS_KEY_ID=test
       - AWS_SECRET_ACCESS_KEY=test
@@ -115,7 +115,8 @@ services:
         aws --endpoint-url=http://localstack:4566 ses verify-domain-identity --domain imex.online --region ca-central-1
         aws --endpoint-url=http://localstack:4566 ses verify-email-identity --email-address noreply@imex.online --region ca-central-1
         aws --endpoint-url=http://localstack:4566 secretsmanager create-secret --name CHATTER_PRIVATE_KEY --secret-string file:///tmp/certs/id_rsa
-        aws --endpoint-url=http://localstack:4566 logs create-log-group --log-group-name development --region ca-central-1
+        aws --endpoint-url=http://localstack:4566 logs create-log-group --log-group-name development --region ca-central-1     
+        aws --endpoint-url=http://localstack:4566 s3api create-bucket --bucket imex-large-log --create-bucket-configuration LocationConstraint=ca-central-1
       "
   # Node App: The Main IMEX API
   node-app:

package.json

@@ -21,6 +21,7 @@
   "dependencies": {
     "@aws-sdk/client-cloudwatch-logs": "^3.679.0",
     "@aws-sdk/client-elasticache": "^3.675.0",
+    "@aws-sdk/client-s3": "^3.689.0",
     "@aws-sdk/client-secrets-manager": "^3.675.0",
     "@aws-sdk/client-ses": "^3.675.0",
     "@aws-sdk/credential-provider-node": "^3.675.0",

server.js

@@ -21,7 +21,7 @@ const { applyRedisHelpers } = require("./server/utils/redisHelpers");
 const { applyIOHelpers } = require("./server/utils/ioHelpers");
 const { redisSocketEvents } = require("./server/web-sockets/redisSocketEvents");
 const { ElastiCacheClient, DescribeCacheClustersCommand } = require("@aws-sdk/client-elasticache");
-const { default: InstanceManager } = require("./server/utils/instanceMgr");
+const { InstanceRegion } = require("./server/utils/instanceMgr");
 
 const CLUSTER_RETRY_BASE_DELAY = 100;
 const CLUSTER_RETRY_MAX_DELAY = 5000;
@@ -114,10 +114,7 @@ const applyRoutes = ({ app }) => {
  */
 const getRedisNodesFromAWS = async () => {
   const client = new ElastiCacheClient({
-    region: InstanceManager({
+    region: InstanceRegion()
-      imex: "ca-central-1",
-      rome: "us-east-2"
-    })
   });
 
   const params = {

server/email/mailer.js

@@ -1,6 +1,6 @@
 const { isString, isEmpty } = require("lodash");
 const { defaultProvider } = require("@aws-sdk/credential-provider-node");
-const { default: InstanceManager } = require("../utils/instanceMgr");
+const { InstanceRegion } = require("../utils/instanceMgr");
 const aws = require("@aws-sdk/client-ses");
 const nodemailer = require("nodemailer");
 const logger = require("../utils/logger");
@@ -10,12 +10,7 @@ const isLocal = isString(process.env?.LOCALSTACK_HOSTNAME) && !isEmpty(process.e
 const sesConfig = {
   apiVersion: "latest",
   credentials: defaultProvider(),
-  region: isLocal
+  region: InstanceRegion()
-    ? "ca-central-1"
-    : InstanceManager({
-        imex: "ca-central-1",
-        rome: "us-east-2"
-      })
 };
 
 if (isLocal) {

server/intellipay/intellipay.js

@@ -17,12 +17,10 @@ require("dotenv").config({
 const domain = process.env.NODE_ENV ? "secure" : "test";
 
 const { SecretsManagerClient, GetSecretValueCommand } = require("@aws-sdk/client-secrets-manager");
+const { InstanceRegion } = require("../utils/instanceMgr");
 
 const client = new SecretsManagerClient({
-  region: InstanceManager({
+  region: InstanceRegion()
-    imex: "ca-central-1",
-    rome: "us-east-2"
-  })
 });
 
 const gqlClient = require("../graphql-client/graphql-client").client;

server/routes/miscellaneousRoutes.js

@@ -15,7 +15,7 @@ const { canvastest } = require("../render/canvas-handler");
 const { alertCheck } = require("../alerts/alertcheck");
 
 //Test route to ensure Express is responding.
-router.get("/test", async function (req, res) {
+router.get("/test", eventAuthorizationMiddleware, async function (req, res) {
   const commit = require("child_process").execSync("git rev-parse --short HEAD");
   // console.log(app.get('trust proxy'));
   // console.log("remoteAddress", req.socket.remoteAddress);
@@ -32,6 +32,32 @@ router.get("/test", async function (req, res) {
   res.status(200).send(`OK - ${commit}`);
 });
 
+router.get("/test-logs", eventAuthorizationMiddleware, (req, res) => {
+  const { logger } = req;
+  // // Test 1: Log with a message that exceeds the size limit, triggering an upload to S3.
+  const largeMessage = "A".repeat(256 * 1024 + 1); // Message larger than the log size limit
+  logger.log(largeMessage, "error", "user123", null, { detail: "large log entry" });
+
+  // Test 2: Log with a message that is within the size limit, should log directly using winston.
+  const smallMessage = "A small log message";
+  logger.log(smallMessage, "info", "user123", null, { detail: "small log entry" });
+
+  // Test 3: Log with the `upload` flag set to `true`, forcing the log to be uploaded to S3.
+  logger.log(
+    "This log will be uploaded to S3 regardless of size",
+    "warning",
+    "user123",
+    null,
+    { detail: "upload log" },
+    true
+  );
+
+  // Test 4: Log with a message that doesn't exceed the size limit and doesn't require an upload.
+  logger.log("Normal log entry", "debug", "user123", { id: 4 }, { detail: "normal log entry" });
+
+  return res.status(500).send("Logs tested.");
+});
+
 // Search
 router.post("/search", validateFirebaseIdTokenMiddleware, withUserGraphQLClientMiddleware, os.search);
 router.post("/opensearch", eventAuthorizationMiddleware, os.handler);

server/utils/instanceMgr.js

@@ -44,4 +44,10 @@ function InstanceManager({ args, instance, debug, executeFunction, rome, promana
   return propToReturn === undefined ? null : propToReturn;
 }
 
+exports.InstanceRegion = () =>
+  InstanceManager({
+    imex: "ca-central-1",
+    rome: "us-east-2"
+  });
+
 exports.default = InstanceManager;

server/utils/logger.js

@@ -9,6 +9,9 @@ const winston = require("winston");
 const WinstonCloudWatch = require("winston-cloudwatch");
 const { isString, isEmpty } = require("lodash");
 const { networkInterfaces, hostname } = require("node:os");
+const { uploadFileToS3 } = require("./s3");
+const { v4 } = require("uuid");
+const { InstanceRegion } = require("./instanceMgr");
 
 const LOG_LEVELS = {
   error: { level: 0, name: "error" },
@@ -20,6 +23,30 @@ const LOG_LEVELS = {
   silly: { level: 6, name: "silly" }
 };
 
+const LOG_LENGTH_LIMIT = 256 * 1024; // 256KB
+
+const S3_BUCKET_NAME = InstanceManager({
+  imex: "imex-large-log",
+  rome: "rome-large-log"
+});
+
+const region = InstanceRegion();
+
+const estimateLogSize = (logEntry) => {
+  let estimatedSize = 0;
+  for (const key in logEntry) {
+    if (logEntry.hasOwnProperty(key)) {
+      const value = logEntry[key];
+      if (value === undefined || value === null) {
+        estimatedSize += key.length; // Only count the key length if value is undefined or null
+      } else {
+        estimatedSize += key.length + (typeof value === "string" ? value.length : JSON.stringify(value).length);
+      }
+    }
+  }
+  return estimatedSize;
+};
+
 const normalizeLevel = (level) => (level ? level.toLowerCase() : LOG_LEVELS.debug.name);
 
 const createLogger = () => {
@@ -30,10 +57,7 @@ const createLogger = () => {
     const winstonCloudwatchTransportDefaults = {
       logGroupName: logGroupName,
       awsOptions: {
-        region: InstanceManager({
+        region
-          imex: "ca-central-1",
-          rome: "us-east-2"
-        })
       },
       jsonMessage: true
     };
@@ -124,15 +148,66 @@ const createLogger = () => {
       );
     }
 
-    const log = (message, type, user, record, meta) => {
+    const log = (message, type, user, record, meta, upload) => {
-      winstonLogger.log({
+      const logEntry = {
         level: normalizeLevel(type),
         message,
         user,
         record,
         hostname: internalHostname,
         meta
-      });
+      };
+
+      const uploadLogToS3 = (logEntry, message, type, user) => {
+        const uniqueId = v4();
+        const dateTimeString = new Date().toISOString().replace(/:/g, "-");
+        const envName = process.env?.NODE_ENV ? process.env.NODE_ENV : "";
+        const logStreamName = `${envName}-${internalHostname}-${dateTimeString}-${uniqueId}.json`;
+        const logString = JSON.stringify(logEntry);
+        const webPath = isLocal
+          ? `https://${S3_BUCKET_NAME}.s3.localhost.localstack.cloud:4566/${logStreamName}`
+          : `https://${S3_BUCKET_NAME}.s3.${region}.amazonaws.com/${logStreamName}`;
+
+        uploadFileToS3({ bucketName: S3_BUCKET_NAME, key: logStreamName, content: logString })
+          .then(() => {
+            log("A log file has been uploaded to S3", "info", "S3", null, {
+              logStreamName,
+              webPath,
+              message: message?.slice(0, 200),
+              type,
+              user
+            });
+          })
+          .catch((err) => {
+            log("Error in S3 Upload", "error", "S3", null, {
+              logStreamName,
+              webPath,
+              message: message?.slice(0, 100),
+              type,
+              user,
+              errorMessage: err?.message?.slice(0, 100)
+            });
+          });
+      };
+
+      const checkAndUploadLog = () => {
+        const estimatedSize = estimateLogSize(logEntry);
+
+        if (estimatedSize > LOG_LENGTH_LIMIT * 0.9 || estimatedSize > LOG_LENGTH_LIMIT) {
+          uploadLogToS3(logEntry, message, type, user);
+          return true;
+        }
+        return false;
+      };
+      // Upload log immediately if upload is true, otherwise check the log size.
+      if (upload) {
+        uploadLogToS3(logEntry, message, type, user);
+        return;
+      }
+
+      if (checkAndUploadLog()) return;
+
+      winstonLogger.log(logEntry);
     };
 
     return {

server/utils/s3.js

@@ -0,0 +1,109 @@
+const {
+  S3Client,
+  PutObjectCommand,
+  GetObjectCommand,
+  ListObjectsV2Command,
+  DeleteObjectCommand,
+  CopyObjectCommand
+} = require("@aws-sdk/client-s3");
+const { defaultProvider } = require("@aws-sdk/credential-provider-node");
+const { InstanceRegion } = require("./instanceMgr");
+const { isString, isEmpty } = require("lodash");
+
+const createS3Client = () => {
+  const S3Options = {
+    region: InstanceRegion(),
+    credentials: defaultProvider()
+  };
+
+  const isLocal = isString(process.env?.LOCALSTACK_HOSTNAME) && !isEmpty(process.env?.LOCALSTACK_HOSTNAME);
+
+  if (isLocal) {
+    S3Options.endpoint = `http://${process.env.LOCALSTACK_HOSTNAME}:4566`;
+    S3Options.forcePathStyle = true; // Needed for LocalStack to avoid bucket name as hostname
+  }
+
+  const s3Client = new S3Client(S3Options);
+
+  /**
+   * Uploads a file to the specified S3 bucket and key.
+   */
+  const uploadFileToS3 = async ({ bucketName, key, content, contentType }) => {
+    const params = {
+      Bucket: bucketName,
+      Key: key,
+      Body: content,
+      ContentType: contentType ?? "application/json"
+    };
+    const command = new PutObjectCommand(params);
+    return await s3Client.send(command);
+  };
+
+  /**
+   * Downloads a file from the specified S3 bucket and key.
+   */
+  const downloadFileFromS3 = async ({ bucketName, key }) => {
+    const params = { Bucket: bucketName, Key: key };
+    const command = new GetObjectCommand(params);
+    const data = await s3Client.send(command);
+    return data.Body;
+  };
+
+  /**
+   * Lists objects in the specified S3 bucket.
+   */
+  const listFilesInS3Bucket = async (bucketName, prefix = "") => {
+    const params = { Bucket: bucketName, Prefix: prefix };
+    const command = new ListObjectsV2Command(params);
+    const data = await s3Client.send(command);
+    return data.Contents || [];
+  };
+
+  /**
+   * Deletes a file from the specified S3 bucket and key.
+   */
+  const deleteFileFromS3 = async ({ bucketName, key }) => {
+    const params = { Bucket: bucketName, Key: key };
+    const command = new DeleteObjectCommand(params);
+    return await s3Client.send(command);
+  };
+
+  /**
+   * Copies a file within S3 from a source bucket/key to a destination bucket/key.
+   */
+  const copyFileInS3 = async ({ sourceBucket, sourceKey, destinationBucket, destinationKey }) => {
+    const params = {
+      CopySource: `/${sourceBucket}/${sourceKey}`,
+      Bucket: destinationBucket,
+      Key: destinationKey
+    };
+    const command = new CopyObjectCommand(params);
+    return await s3Client.send(command);
+  };
+
+  /**
+   * Checks if a file exists in the specified S3 bucket and key.
+   */
+  const fileExistsInS3 = async ({ bucketName, key }) => {
+    try {
+      await downloadFileFromS3({ bucketName, key });
+      return true;
+    } catch (error) {
+      if (error.name === "NoSuchKey" || error.name === "NotFound") {
+        return false;
+      }
+      throw error;
+    }
+  };
+
+  return {
+    uploadFileToS3,
+    downloadFileFromS3,
+    listFilesInS3Bucket,
+    deleteFileFromS3,
+    copyFileInS3,
+    fileExistsInS3
+  };
+};
+
+module.exports = createS3Client();

server/web-sockets/web-socket.js

@@ -155,10 +155,17 @@ function createJsonEvent(socket, level, message, json) {
       message
     });
   }
-  logger.log("ws-log-event-json", level, socket.user.email, socket.recordid, {
+  logger.log(
-    wsmessage: message,
+    "ws-log-event-json",
-    json
+    level,
-  });
+    socket.user.email,
+    socket.recordid,
+    {
+      wsmessage: message,
+      json
+    },
+    true
+  );
 
   if (socket.logEvents && isArray(socket.logEvents)) {
     socket.logEvents.push({
@@ -189,7 +196,8 @@ function createXmlEvent(socket, xml, message, isError = false) {
     {
       wsmessage: message,
       xml
-    }
+    },
+    true
   );
 
   if (socket.logEvents && isArray(socket.logEvents)) {