Merge pull request #1146 from Infisical/pino

Replace winston with pino logging

backend/package.json

@@ -6,7 +6,7 @@
     "@godaddy/terminus": "^4.12.0",
     "@node-saml/passport-saml": "^4.0.4",
     "@octokit/rest": "^19.0.5",
-    "@sentry/node": "^7.49.0",
+    "@sentry/node": "^7.77.0",
     "@sentry/tracing": "^7.48.0",
     "@types/crypto-js": "^4.1.1",
     "@types/libsodium-wrappers": "^0.7.10",
@@ -42,6 +42,8 @@
     "passport-github": "^1.1.0",
     "passport-gitlab2": "^5.0.0",
     "passport-google-oauth20": "^2.0.0",
+    "pino": "^8.16.1",
+    "pino-http": "^8.5.1",
     "posthog-node": "^2.6.0",
     "probot": "^12.3.1",
     "query-string": "^7.1.3",
@@ -52,8 +54,6 @@
     "tweetnacl-util": "^0.15.1",
     "typescript": "^4.9.3",
     "utility-types": "^3.10.0",
-    "winston": "^3.8.2",
-    "winston-loki": "^6.0.6",
     "zod": "^3.22.3"
   },
   "overrides": {
@@ -66,7 +66,7 @@
   "main": "src/index.js",
   "scripts": {
     "start": "node build/index.js",
-    "dev": "nodemon",
+    "dev": "nodemon index.js | pino-pretty --colorize",
     "swagger-autogen": "node ./swagger/index.ts",
     "build": "rimraf ./build && tsc && cp -R ./src/templates ./build && cp -R ./src/data ./build",
     "lint": "eslint . --ext .ts",
@@ -104,6 +104,7 @@
     "@types/nodemailer": "^6.4.6",
     "@types/passport": "^1.0.12",
     "@types/picomatch": "^2.3.0",
+    "@types/pino": "^7.0.5",
     "@types/supertest": "^2.0.12",
     "@types/swagger-jsdoc": "^6.0.1",
     "@types/swagger-ui-express": "^4.1.3",
@@ -117,6 +118,7 @@
     "jest-junit": "^15.0.0",
     "nodemon": "^2.0.19",
     "npm": "^8.19.3",
+    "pino-pretty": "^10.2.3",
     "smee-client": "^1.2.3",
     "supertest": "^6.3.3",
     "swagger-autogen": "^2.23.5",

backend/src/helpers/database.ts

@@ -1,5 +1,5 @@
 import mongoose from "mongoose";
-import { getLogger } from "../utils/logger";
+import { logger } from "../utils/logging";
 
 /**
  * Initialize database connection
@@ -18,10 +18,10 @@ export const initDatabaseHelper = async ({
         // allow empty strings to pass the required validator
         mongoose.Schema.Types.String.checkRequired(v => typeof v === "string");
 
-        (await getLogger("database")).info("Database connection established");
+        logger.info("Database connection established");
 
     } catch (err) {
-        (await getLogger("database")).error(`Unable to establish Database connection due to the error.\n${err}`);
+        logger.error(err, "Unable to establish database connection");
     }
 
     return mongoose.connection;

backend/src/index.ts

@@ -5,6 +5,8 @@ import express from "express";
 require("express-async-errors");
 import helmet from "helmet";
 import cors from "cors";
+import { logger } from "./utils/logging";
+import httpLogger from "pino-http";
 import { DatabaseService } from "./services";
 import { EELicenseService, GithubSecretScanningService } from "./ee/services";
 import { setUpHealthEndpoint } from "./services/health";
@@ -73,7 +75,7 @@ import {
   workspaces as v3WorkspacesRouter
 } from "./routes/v3";
 import { healthCheck } from "./routes/status";
-import { getLogger } from "./utils/logger";
+// import { getLogger } from "./utils/logger";
 import { RouteNotFoundError } from "./utils/errors";
 import { requestErrorHandler } from "./middleware/requestErrorHandler";
 import {
@@ -94,12 +96,20 @@ import path from "path";
 let handler: null | any = null;
 
 const main = async () => {
+  const port = await getPort();
+
   await setup();
 
   await EELicenseService.initGlobalFeatureSet();
 
   const app = express();
   app.enable("trust proxy");
+
+  app.use(httpLogger({
+    logger,
+    autoLogging: false
+  }));
+
   app.use(express.json());
   app.use(express.urlencoded({ extended: false }));
   app.use(cookieParser());
@@ -164,7 +174,7 @@ const main = async () => {
     const nextApp = new NextServer({
       dev: false,
       dir: nextJsBuildPath,
-      port: await getPort(),
+      port,
       conf,
       hostname: "local",
       customServer: false
@@ -255,8 +265,8 @@ const main = async () => {
 
   app.use(requestErrorHandler);
 
-  const server = app.listen(await getPort(), async () => {
-    (await getLogger("backend-main")).info(`Server started listening at port ${await getPort()}`);
+  const server = app.listen(port, async () => {
+    logger.info(`Server started listening at port ${port}`);
   });
 
   // await createTestUserForDevelopment();

backend/src/middleware/requestErrorHandler.ts

@@ -2,49 +2,45 @@ import * as Sentry from "@sentry/node";
 import { ErrorRequestHandler } from "express";
 import { TokenExpiredError } from "jsonwebtoken";
 import { InternalServerError, UnauthorizedRequestError } from "../utils/errors";
-import { getLogger } from "../utils/logger";
-import RequestError from "../utils/requestError";
+import { logger } from "../utils/logging";
+import RequestError, { mapToPinoLogLevel } from "../utils/requestError";
 import { ForbiddenError } from "@casl/ability";
 
 export const requestErrorHandler: ErrorRequestHandler = async (
-  error: RequestError | Error,
+  err: RequestError | Error,
   req,
   res,
   next
 ) => {
   if (res.headersSent) return next();
 
-  const logAndCaptureException = async (error: RequestError) => {
-    (await getLogger("backend-main")).log(
-      (<RequestError>error).levelName.toLowerCase(),
-      `${error.stack}\n${error.message}`
-    );
-
-    //* Set Sentry user identification if req.user is populated
-    if (req.user !== undefined && req.user !== null) {
-      Sentry.setUser({ email: (req.user as any).email });
-    }
-
-    Sentry.captureException(error);
-  };
+  let error: RequestError;
+
+  switch (true) {
+    case err instanceof TokenExpiredError:
+      error = UnauthorizedRequestError({ stack: err.stack, message: "Token expired" });
+      break;
+    case err instanceof ForbiddenError:
+      error = UnauthorizedRequestError({ context: { exception: err.message }, stack: err.stack })
+      break;
+    case err instanceof RequestError:
+      error = err as RequestError;
+      break;
+    default:
+      error = InternalServerError({ context: { exception: err.message }, stack: err.stack });
+      break;
+  }
 
-  if (error instanceof RequestError) {
-    if (error instanceof TokenExpiredError) {
-      error = UnauthorizedRequestError({ stack: error.stack, message: "Token expired" });
-    }
-    await logAndCaptureException((<RequestError>error));
-  } else {
-    if (error instanceof ForbiddenError) {
-      error = UnauthorizedRequestError({ context: { exception: error.message }, stack: error.stack })
-    } else {
-      error = InternalServerError({ context: { exception: error.message }, stack: error.stack });
-    }
+  logger[mapToPinoLogLevel(error.level)](error);
 
-    await logAndCaptureException((<RequestError>error));
+  if (req.user) {
+    Sentry.setUser({ email: (req.user as any).email });
   }
 
+  Sentry.captureException(error);
+
   delete (<any>error).stacktrace // remove stack trace from being sent to client
-  res.status((<RequestError>error).statusCode).json(error);
+  res.status((<RequestError>error).statusCode).json(error); // revise json part here
 
   next();
 };

backend/src/services/TelemetryService.ts

@@ -1,5 +1,5 @@
 import { PostHog } from "posthog-node";
-import { getLogger } from "../utils/logger";
+import { logger } from "../utils/logging";
 import { AuthData } from "../interfaces/middleware";
 import {
   getNodeEnv,
@@ -22,13 +22,13 @@ class Telemetry {
    * Logs telemetry enable/disable notice.
    */
   static logTelemetryMessage = async () => {
+
     if(!(await getTelemetryEnabled())){
-      (await getLogger("backend-main")).info([
-        "",
+      [
         "To improve, Infisical collects telemetry data about general usage.",
         "This helps us understand how the product is doing and guide our product development to create the best possible platform; it also helps us demonstrate growth as we support Infisical as open-source software.",
         "To opt into telemetry, you can set `TELEMETRY_ENABLED=true` within the environment variables.",
-      ].join("\n"))
+      ].forEach(line => logger.info(line));
     }
   }
 

backend/src/services/health.ts

@@ -1,10 +1,10 @@
 import mongoose from "mongoose";
 import { createTerminus } from "@godaddy/terminus";
-import { getLogger } from "../utils/logger";
+import { logger } from "../utils/logging";
 
 export const setUpHealthEndpoint = <T>(server: T) => {
   const onSignal = async () => {
-    (await getLogger("backend-main")).info("Server is starting clean-up");
+    logger.info("Server is starting clean-up");
     return Promise.all([
       new Promise((resolve) => {
         if (mongoose.connection && mongoose.connection.readyState == 1) {

backend/src/services/smtp.ts

@@ -16,7 +16,7 @@ import {
   getSmtpSecure,
   getSmtpUsername,
 } from "../config";
-import { getLogger } from "../utils/logger";
+import { logger } from "../utils/logging";
 
 export const initSmtp = async () => {
   const mailOpts: SMTPConnection.Options = {
@@ -84,15 +84,14 @@ export const initSmtp = async () => {
     .then(async () => {
       Sentry.setUser(null);
       Sentry.captureMessage("SMTP - Successfully connected");
-      (await getLogger("backend-main")).info(
-        "SMTP - Successfully connected"
-      );
+      logger.info("SMTP - Successfully connected");
     })
     .catch(async (err) => {
       Sentry.setUser(null);
       Sentry.captureException(
         `SMTP - Failed to connect to ${await getSmtpHost()}:${await getSmtpPort()} \n\t${err}`
       );
+      logger.error(err, `SMTP - Failed to connect to ${await getSmtpHost()}:${await getSmtpPort()}`);
     });
 
   return transporter;

backend/src/utils/errors.ts

@@ -29,7 +29,7 @@ export const UnauthorizedRequestError = (error?: Partial<RequestErrorContext>) =
 });
 
 export const ForbiddenRequestError = (error?: Partial<RequestErrorContext>) => new RequestError({
-    logLevel: error?.logLevel ?? LogLevel.INFO,
+    logLevel: error?.logLevel ?? LogLevel.WARN,
     statusCode: error?.statusCode ?? 403,
     type: error?.type ?? "forbidden",
     message: error?.message ?? "You are not allowed to access this resource",

backend/src/utils/logging/index.ts

@@ -0,0 +1 @@
+export { logger } from "./logger";

backend/src/utils/logging/logger.ts

@@ -0,0 +1,15 @@
+import pino from "pino";
+
+export const logger = pino({
+  level: process.env.PINO_LOG_LEVEL || "trace",
+  timestamp: pino.stdTimeFunctions.isoTime,
+  formatters: {
+    bindings: (bindings) => {
+        return {
+            pid: bindings.pid,
+            hostname: bindings.hostname
+            // node_version: process.version
+        };
+    },
+  }
+});