refactor: add debug-level lib for granular log leveling (#419)

* refactor: add debug-level lib for granular log leveling

* refactor: adapt to new log content format

* feat(logging): add logs for improving observability

* refactor(pg): rename query binding variables for clarity

Author: clostao

auth/.env.test

@@ -1,3 +1,4 @@
 JWT_SECRET=test
 JWT_SECRET_ALGORITHM=HS256
-API_SECRET=test
+API_SECRET=test
+DEBUG_LEVEL=error

auth/package.json

@@ -9,7 +9,7 @@
     "build": "tsc",
     "dev": "nodemon src/index.ts",
     "migrate": "db-migrate -t auth_migrations",
-    "test": "node --experimental-vm-modules ../node_modules/jest/bin/jest.js --runInBand --coverage",
+    "test": "NODE_OPTIONS='--max-old-space-size=4096' node --experimental-vm-modules ../node_modules/jest/bin/jest.js --runInBand --coverage --forceExit",
     "lint": "eslint .",
     "lambda:build": "yarn build && ../node_modules/.bin/esbuild src/lambda.ts --bundle --platform=node --target=node18 --outfile=build/index.js"
   },
@@ -23,6 +23,7 @@
     "cors": "^2.8.5",
     "db-migrate": "^0.11.14",
     "db-migrate-pg": "^1.5.2",
+    "debug-level": "^4.1.1",
     "dotenv": "^16.4.7",
     "esbuild": "^0.25.0",
     "express": "^4.21.2",
@@ -31,14 +32,18 @@
     "serverless-http": "^3.2.0",
     "siwe": "^3.0.0",
     "typescript": "^5.7.3",
-    "uuid": "^11.0.5",
-    "winston": "^3.17.0"
+    "uuid": "^11.0.5"
   },
   "devDependencies": {
     "@testcontainers/postgresql": "^10.14.0",
     "@testcontainers/rabbitmq": "^10.17.2",
+    "@types/amqplib": "^0.10.6",
+    "@types/aws-sdk": "^2.7.0",
     "@types/cors": "^2.8.17",
+    "@types/express": "^5.0.0",
     "@types/jest": "^29.5.14",
+    "@types/multer": "^1.4.12",
+    "@types/uuid": "^9.0.0",
     "db-migrate-plugin-typescript": "^2.0.0",
     "eslint": "^8.57.1",
     "eslint-config-prettier": "^9.1.0",

auth/src/controllers/user.ts

@@ -1,4 +1,4 @@
-import { Router } from 'express'
+import { Router, Request, Response } from 'express'
 import {
   handleAdminAuth,
   handleAuth,
@@ -9,11 +9,13 @@ import { UsersUseCases } from '../useCases/index.js'
 import { ApiKeysUseCases } from '../useCases/apikeys.js'
 import { UserRole } from '@auto-drive/models'
 import { CustomJWTAuth } from '../services/authManager/providers/custom.js'
-import { logger } from '../drivers/logger.js'
+import { createLogger } from '../drivers/logger.js'
+
+const logger = createLogger('controllers:user')
 
 const userController = Router()
 
-userController.post('/@me/onboard', async (req, res) => {
+userController.post('/@me/onboard', async (req: Request, res: Response) => {
   const user = await handleAuthIgnoreOnboarding(req, res)
   if (!user) {
     return
@@ -23,14 +25,14 @@ userController.post('/@me/onboard', async (req, res) => {
     const onboardedUser = await UsersUseCases.onboardUser(user)
     res.json(onboardedUser)
   } catch (error) {
-    console.error(error)
+    logger.error(error)
     res.status(500).json({
       error: 'Failed to onboard user',
     })
   }
 })
 
-userController.post('/@me/accessToken', async (req, res) => {
+userController.post('/@me/accessToken', async (req: Request, res: Response) => {
   const user = await handleAuthIgnoreOnboarding(req, res)
   if (!user) {
     return
@@ -48,42 +50,49 @@ userController.post('/@me/accessToken', async (req, res) => {
     .json({ accessToken })
 })
 
-userController.post('/@me/refreshToken', async (req, res) => {
-  try {
-    const refreshToken = req.headers.cookie?.match(/refreshToken=([^;]+)/)?.[1]
-    if (!refreshToken) {
-      res.status(401).json({
-        error: 'Unauthorized',
-      })
+userController.post(
+  '/@me/refreshToken',
+  async (req: Request, res: Response) => {
+    try {
+      const refreshToken =
+        req.headers.cookie?.match(/refreshToken=([^;]+)/)?.[1]
+      if (!refreshToken) {
+        res.status(401).json({
+          error: 'Unauthorized',
+        })
+        return
+      }
+
+      const accessToken = await refreshAccessToken(refreshToken)
+
+      res.json({ accessToken })
+    } catch (error) {
+      logger.error(error)
+      res.status(500).json({ error: 'Failed to refresh access token' })
       return
     }
+  },
+)
 
-    const accessToken = await refreshAccessToken(refreshToken)
-
-    res.json({ accessToken })
-  } catch (error) {
-    console.error(error)
-    res.status(500).json({ error: 'Failed to refresh access token' })
-    return
-  }
-})
-
-userController.delete('/@me/invalidateToken', async (req, res) => {
-  const token = req.body.token
+userController.delete(
+  '/@me/invalidateToken',
+  async (req: Request, res: Response) => {
+    const token = req.body.token
 
-  if (typeof token !== 'string') {
-    res.status(400).json({
-      error: 'Missing or invalid attribute `token` in body',
-    })
-    return
-  }
+    if (typeof token !== 'string') {
+      res.status(400).json({
+        error: 'Missing or invalid attribute `token` in body',
+      })
+      return
+    }
 
-  await CustomJWTAuth.invalidateRefreshToken(token)
+    await CustomJWTAuth.invalidateRefreshToken(token)
 
-  res.sendStatus(200)
-})
+    res.sendStatus(200)
+  },
+)
 
-userController.get('/@me', async (req, res) => {
+userController.get('/@me', async (req: Request, res: Response) => {
   const user = await handleAuthIgnoreOnboarding(req, res)
   if (!user) {
     logger.warn('User not found')
@@ -95,15 +104,15 @@ userController.get('/@me', async (req, res) => {
 
     res.json(userInfo)
   } catch (error) {
-    console.error(error)
+    logger.error(error)
     res.status(500).json({
       error: 'Failed to get user info',
     })
     return
   }
 })
 
-userController.get('/@me/apiKeys', async (req, res) => {
+userController.get('/@me/apiKeys', async (req: Request, res: Response) => {
   const user = await handleAuth(req, res)
   if (!user) {
     return
@@ -114,55 +123,61 @@ userController.get('/@me/apiKeys', async (req, res) => {
 
     res.json(apiKeys)
   } catch (error) {
-    console.error(error)
+    logger.error(error)
     res.status(500).json({
       error: 'Failed to get API keys',
     })
     return
   }
 })
 
-userController.post('/@me/apiKeys/create', async (req, res) => {
-  const user = await handleAuth(req, res)
-  if (!user) {
-    return
-  }
+userController.post(
+  '/@me/apiKeys/create',
+  async (req: Request, res: Response) => {
+    const user = await handleAuth(req, res)
+    if (!user) {
+      return
+    }
 
-  try {
-    const apiKey = await ApiKeysUseCases.createApiKey(user)
+    try {
+      const apiKey = await ApiKeysUseCases.createApiKey(user)
 
-    res.json(apiKey)
-  } catch (error) {
-    console.error(error)
-    res.status(500).json({
-      error: 'Failed to create API key',
-    })
-    return
-  }
-})
-
-userController.delete('/@me/apiKeys/:id', async (req, res) => {
-  const user = await handleAuth(req, res)
-  if (!user) {
-    return
-  }
+      res.json(apiKey)
+    } catch (error) {
+      logger.error(error)
+      res.status(500).json({
+        error: 'Failed to create API key',
+      })
+      return
+    }
+  },
+)
+
+userController.delete(
+  '/@me/apiKeys/:id',
+  async (req: Request, res: Response) => {
+    const user = await handleAuth(req, res)
+    if (!user) {
+      return
+    }
 
-  const { id } = req.params
+    const { id } = req.params
 
-  try {
-    await ApiKeysUseCases.deleteApiKey(user, id)
+    try {
+      await ApiKeysUseCases.deleteApiKey(user, id)
 
-    res.sendStatus(200)
-  } catch (error) {
-    console.error(error)
-    res.status(500).json({
-      error: 'Failed to delete API key',
-    })
-    return
-  }
-})
+      res.sendStatus(200)
+    } catch (error) {
+      logger.error(error)
+      res.status(500).json({
+        error: 'Failed to delete API key',
+      })
+      return
+    }
+  },
+)
 
-userController.post('/admin/add', async (req, res) => {
+userController.post('/admin/add', async (req: Request, res: Response) => {
   const user = await handleAuth(req, res)
   if (!user) {
     return
@@ -182,15 +197,15 @@ userController.post('/admin/add', async (req, res) => {
 
     res.sendStatus(200)
   } catch (error) {
-    console.error(error)
+    logger.error(error)
     res.status(500).json({
       error: 'Failed to add user to admins',
     })
     return
   }
 })
 
-userController.post('/admin/remove', async (req, res) => {
+userController.post('/admin/remove', async (req: Request, res: Response) => {
   const user = await handleAuth(req, res)
   if (!user) {
     return
@@ -210,15 +225,15 @@ userController.post('/admin/remove', async (req, res) => {
 
     res.sendStatus(200)
   } catch (error) {
-    console.error(error)
+    logger.error(error)
     res.status(500).json({
       error: 'Failed to remove user from admins',
     })
     return
   }
 })
 
-userController.get('/list', async (req, res) => {
+userController.get('/list', async (req: Request, res: Response) => {
   const user = await handleAuth(req, res)
   if (!user) {
     return
@@ -248,15 +263,15 @@ userController.get('/list', async (req, res) => {
 
     res.json(result)
   } catch (error) {
-    console.error(error)
+    logger.error(error)
     res.status(500).json({
       error: 'Failed to get user list',
     })
     return
   }
 })
 
-userController.get('/:publicId', async (req, res) => {
+userController.get('/:publicId', async (req: Request, res: Response) => {
   const { publicId } = req.params
 
   const isAdmin = await handleAdminAuth(req, res)

auth/src/drivers/logger.ts

@@ -1,7 +1,6 @@
-import { createLogger, format, transports } from 'winston'
-import { config } from '../config.js'
+import { Log } from 'debug-level'
 
-type Any =
+export type Any =
   | object
   | string
   | number
@@ -12,29 +11,32 @@ type Any =
   | unknown
 
 export interface Logger {
-  info: (...message: Any[]) => Promise<void>
-  error: (...message: Any[]) => Promise<void>
-  warn: (...message: Any[]) => Promise<void>
-  debug: (...message: Any[]) => Promise<void>
+  info: (...message: Any[]) => void
+  error: (...message: Any[]) => void
+  warn: (...message: Any[]) => void
+  debug: (...message: Any[]) => void
+  trace: (...message: Any[]) => void
 }
 
-const winstonLogger = createLogger({
-  level: config.logLevel,
-  format: format.combine(format.timestamp(), format.json()),
-  transports: [new transports.Console()],
-})
-
-export const logger: Logger = {
-  info: async (...message: Any[]) => {
-    winstonLogger.info(message.join(' '))
-  },
-  error: async (...message: Any[]) => {
-    winstonLogger.error(message.join(' '))
-  },
-  warn: async (...message: Any[]) => {
-    winstonLogger.warn(message.join(' '))
-  },
-  debug: async (...message: Any[]) => {
-    winstonLogger.debug(message.join(' '))
-  },
+function wrapLog(log: Log): Logger {
+  return {
+    info: (...message: Any[]) => {
+      log.info(...message)
+    },
+    error: (...message: Any[]) => {
+      log.error(...message)
+    },
+    warn: (...message: Any[]) => {
+      log.warn(...message)
+    },
+    debug: (...message: Any[]) => {
+      log.debug(...message)
+    },
+    trace: (...message: Any[]) => {
+      log.trace(...message)
+    },
+  }
 }
+
+export const createLogger = (namespace: string): Logger =>
+  wrapLog(new Log(namespace))