From 45e99fe934482bed2a635cabddbf4ca24c8253cb Mon Sep 17 00:00:00 2001 From: Vedant1515 Date: Tue, 31 Mar 2026 23:48:25 +1100 Subject: [PATCH] BE06 - Implement centralized structured logging system --- controller/appointmentController.js | 13 +- controller/authController.js | 19 +- controller/chatbotController.js | 17 +- controller/homeServiceController.js | 17 +- controller/imageClassificationController.js | 5 +- controller/loginController.js | 13 +- controller/medicalPredictionController.js | 3 +- controller/notificationController.js | 15 +- controller/uploadController.js | 3 +- controller/userPreferencesController.js | 5 +- middleware/requestLogger.js | 83 +++++++ middleware/structuredErrorHandler.js | 79 ++++++ package-lock.json | 252 +++++++++++++++++++- package.json | 1 + server.js | 28 +-- utils/logger.js | 163 +++++++++++++ 16 files changed, 649 insertions(+), 67 deletions(-) create mode 100644 middleware/requestLogger.js create mode 100644 middleware/structuredErrorHandler.js create mode 100644 utils/logger.js diff --git a/controller/appointmentController.js b/controller/appointmentController.js index 854b96d9..9ea0dad8 100644 --- a/controller/appointmentController.js +++ b/controller/appointmentController.js @@ -1,5 +1,6 @@ const {addAppointment, addAppointmentModelV2, updateAppointmentModel, deleteAppointmentById} = require('../model/appointmentModel.js'); const {getAllAppointments, getAllAppointmentsV2 } = require('../model/getAppointments.js'); +const logger = require('../utils/logger'); const { validationResult } = require('express-validator'); @@ -20,7 +21,7 @@ const saveAppointment = async (req, res) => { // Respond with success message if appointment data is successfully saved res.status(201).json({ message: 'Appointment saved successfully' });//, appointmentId: result.id } catch (error) { - console.error('Error saving appointment:', error); + logger.error('Error saving appointment', { error: error.message, userId }); res.status(500).json({ error: 'Internal server error' }); } }; @@ -65,7 +66,7 @@ const saveAppointmentV2 = async (req, res) => { appointment, }); } catch (error) { - console.error("Error saving appointment:", error); + logger.error('Error saving appointment (V2)', { error: error.message, userId }); res.status(500).json({ error: "Internal server error" }); } }; @@ -114,7 +115,7 @@ const updateAppointment = async (req,res)=>{ appointment: updatedAppointment, }); } catch (error) { - console.error('Error updating appointment:', error); + logger.error('Error updating appointment', { error: error.message, appointmentId: id }); res.status(500).json({ error: 'Internal server error' }); } } @@ -133,7 +134,7 @@ const delAppointment = async (req,res)=>{ message: 'Appointment deleted successfully', }); } catch (error) { - console.error('Error deleting appointment:', error); + logger.error('Error deleting appointment', { error: error.message, appointmentId: id }); res.status(500).json({ error: 'Internal server error' }); } } @@ -149,7 +150,7 @@ const getAppointments = async (req, res) => { // Respond with the retrieved appointment data res.status(200).json(appointments); } catch (error) { - console.error('Error retrieving appointments:', error); + logger.error('Error retrieving appointments', { error: error.message }); res.status(500).json({ error: 'Internal server error' }); } }; @@ -174,7 +175,7 @@ const getAppointmentsV2 = async (req, res) => { appointments }); } catch (error) { - console.error("Error retrieving appointments:", error); + logger.error('Error retrieving appointments (V2)', { error: error.message }); res.status(500).json({ error: "Internal server error" }); } }; diff --git a/controller/authController.js b/controller/authController.js index 63b4a173..320564ed 100644 --- a/controller/authController.js +++ b/controller/authController.js @@ -1,4 +1,5 @@ const authService = require('../services/authService'); +const logger = require('../utils/logger'); const { createClient } = require('@supabase/supabase-js'); const supabase = createClient( @@ -28,7 +29,7 @@ exports.register = async (req, res) => { res.status(201).json(result); } catch (error) { - console.error('Registration error:', error); + logger.error('Registration error', { error: error.message, email: req.body.email }); res.status(400).json({ success: false, error: error.message @@ -61,7 +62,7 @@ exports.login = async (req, res) => { res.json(result); } catch (error) { - console.error('Login error:', error); + logger.error('Login error', { error: error.message, email: req.body.email }); res.status(401).json({ success: false, error: error.message @@ -93,7 +94,7 @@ exports.refreshToken = async (req, res) => { res.json(result); } catch (error) { - console.error('Token refresh error:', error); + logger.error('Token refresh error', { error: error.message }); res.status(401).json({ success: false, error: error.message @@ -113,7 +114,7 @@ exports.logout = async (req, res) => { res.json(result); } catch (error) { - console.error('Logout error:', error); + logger.error('Logout error', { error: error.message, userId: req.user?.userId }); res.status(500).json({ success: false, error: error.message @@ -133,7 +134,7 @@ exports.logoutAll = async (req, res) => { res.json(result); } catch (error) { - console.error('Logout all error:', error); + logger.error('Logout all error', { error: error.message, userId: req.user?.userId }); res.status(500).json({ success: false, error: error.message @@ -181,7 +182,7 @@ exports.getProfile = async (req, res) => { }); } catch (error) { - console.error('Get profile error:', error); + logger.error('Get profile error', { error: error.message, userId: req.user?.userId }); res.status(500).json({ success: false, error: 'Internal server error' @@ -210,7 +211,7 @@ exports.logLoginAttempt = async (req, res) => { ]); if (error) { - console.error('❌ Failed to insert login log:', error); + logger.error('Failed to insert login log', { error: error.message, email }); return res.status(500).json({ error: 'Failed to log login attempt' }); } @@ -239,7 +240,7 @@ exports.sendSMSByEmail = async (req, res) => { const phone = data.contact_number; const verificationCode = Math.floor(100000 + Math.random() * 900000).toString(); - console.log(`📨 [DEV] Verification code for ${phone}: ${verificationCode}`); + logger.info('[DEV] Verification code generated', { phone, verificationCode }); return res.status(200).json({ @@ -247,7 +248,7 @@ exports.sendSMSByEmail = async (req, res) => { phone, }); } catch (err) { - console.error('❌ Error sending SMS:', err); + logger.error('Error sending SMS', { error: err.message, email }); return res.status(500).json({ error: 'Internal server error' }); } }; diff --git a/controller/chatbotController.js b/controller/chatbotController.js index b214bdc7..1ab0ef40 100644 --- a/controller/chatbotController.js +++ b/controller/chatbotController.js @@ -1,4 +1,5 @@ const { addHistory, getHistory, deleteHistory } = require('../model/chatbotHistory'); +const logger = require('../utils/logger'); const fetch = (...args) => import('node-fetch').then(({default: fetch}) => fetch(...args)); @@ -46,7 +47,7 @@ const getChatResponse = async (req, res) => { responseText = result.msg; } } catch (aiError) { - console.error("Error connecting to AI server:", aiError); + logger.error('Error connecting to AI server', { error: aiError.message, userId: user_id }); // Continue with fallback response } @@ -54,7 +55,7 @@ const getChatResponse = async (req, res) => { try { await addHistory(user_id, user_input, responseText); } catch (dbError) { - console.error("Error storing chat history:", dbError); + logger.error('Error storing chat history', { error: dbError.message, userId: user_id }); } // Return response to user @@ -64,7 +65,7 @@ const getChatResponse = async (req, res) => { }); } catch (error) { - console.error("Error in chatbot response:", error); + logger.error('Error in chatbot response', { error: error.message, userId: user_id }); return res.status(500).json({ error: "Internal server error" }); @@ -109,14 +110,14 @@ const addURL = async (req, res) => { result: result }); } catch (aiError) { - console.error("Error connecting to AI server:", aiError); + logger.error('Error connecting to AI server', { error: aiError.message, urls }); return res.status(503).json({ error: "AI server unavailable" }); } } catch (error) { - console.error("Error processing URL:", error); + logger.error('Error processing URL', { error: error.message }); return res.status(500).json({ error: "Internal server error" }); @@ -136,7 +137,7 @@ const addPDF = async (req, res) => { result: "This is dummy response" }); } catch (error) { - console.error("Error in chatbot response:", error); + logger.error('Error processing PDF', { error: error.message }); return res.status(500).json({ error: "Internal server error", details: process.env.NODE_ENV === 'development' ? error.message : undefined @@ -170,7 +171,7 @@ const getChatHistory = async (req, res) => { chat_history: history }); } catch (error) { - console.error("Error retrieving chat history:", error); + logger.error('Error retrieving chat history', { error: error.message, userId: user_id }); return res.status(500).json({ error: "Internal server error", details: process.env.NODE_ENV === 'development' ? error.message : undefined @@ -196,7 +197,7 @@ const clearChatHistory = async (req, res) => { message: "Chat history cleared successfully" }); } catch (error) { - console.error("Error clearing chat history:", error); + logger.error('Error clearing chat history', { error: error.message, userId: user_id }); return res.status(500).json({ error: "Internal server error", details: process.env.NODE_ENV === 'development' ? error.message : undefined diff --git a/controller/homeServiceController.js b/controller/homeServiceController.js index b9136890..7e5bb22c 100644 --- a/controller/homeServiceController.js +++ b/controller/homeServiceController.js @@ -1,4 +1,5 @@ const supabase = require("../dbConnection.js"); +const logger = require('../utils/logger'); const { createServiceModel, updateServiceModel, @@ -17,7 +18,7 @@ const getServiceContents = async (req, res) => { .select("title, description, image"); if (error) { - console.error("Error get service contents:", error.message); + logger.error('Error getting service contents', { error: error.message }); return res.status(500).json({ error: "Failed to get service contents" }); } @@ -25,7 +26,7 @@ const getServiceContents = async (req, res) => { .status(200) .json({ message: "Get service contents successfully", data }); } catch (error) { - console.error("Internal server error:", error.message); + logger.error('Internal server error in getServiceContents', { error: error.message }); return res.status(500).json({ error: "Internal server error" }); } }; @@ -62,7 +63,7 @@ const getServiceContentsPage = async (req, res) => { const { data, error, count } = await query; if (error) { - console.error("Error getting service contents:", error.message); + logger.error('Error getting service contents', { error: error.message }); return res.status(500).json({ error: "Failed to get service contents" }); } @@ -75,7 +76,7 @@ const getServiceContentsPage = async (req, res) => { data, }); } catch (error) { - console.error("Internal server error:", error.message); + logger.error('Internal server error in getServiceContentsPage', { error: error.message }); return res.status(500).json({ error: "Internal server error" }); } }; @@ -100,7 +101,7 @@ const createService = async (req, res) => { data: service, }); } catch (error) { - console.error("Error creating service:", error.message); + logger.error('Error creating service', { error: error.message }); res.status(500).json({ error: error.message }); } }; @@ -126,7 +127,7 @@ const updateService = async (req, res) => { data: service, }); } catch (error) { - console.error("Error updating service:", error.message); + logger.error('Error updating service', { error: error.message, serviceId: req.params.id }); res.status(500).json({ error: error.message }); } }; @@ -145,7 +146,7 @@ const deleteService = async (req, res) => { message: "Service deleted successfully", }); } catch (error) { - console.error("Error deleting service:", error.message); + logger.error('Error deleting service', { error: error.message, serviceId: req.params.id }); res.status(500).json({ error: error.message }); } }; @@ -167,7 +168,7 @@ const addSubscribe = async (req, res) => { data: subscribe, }); } catch (error) { - console.error("Error creating subscribe:", error.message); + logger.error('Error creating subscribe', { error: error.message, email: req.body.email }); res.status(500).json({ error: error.message }); } }; diff --git a/controller/imageClassificationController.js b/controller/imageClassificationController.js index 75600b73..16e673b4 100644 --- a/controller/imageClassificationController.js +++ b/controller/imageClassificationController.js @@ -1,12 +1,13 @@ const fs = require('fs'); const path = require('path'); +const logger = require('../utils/logger'); const { executePythonScript } = require('../services/aiExecutionService'); // Utility to delete the uploaded file const deleteFile = (filePath) => { fs.unlink(filePath, (err) => { if (err) { - console.error('Error deleting file:', err); + logger.error('Error deleting image file', { filePath, error: err.message }); } }); }; @@ -58,7 +59,7 @@ const predictImage = async (req, res) => { error: null }); } catch (error) { - console.error('Error reading image file:', error); + logger.error('Error reading image file', { error: error.message, filePath: imagePath }); return res.status(500).json({ success: false, prediction: null, diff --git a/controller/loginController.js b/controller/loginController.js index 4c3f91c5..73fd70ec 100644 --- a/controller/loginController.js +++ b/controller/loginController.js @@ -1,5 +1,6 @@ const bcrypt = require("bcryptjs"); const jwt = require("jsonwebtoken"); +const logger = require('../utils/logger'); const logLoginEvent = require("../Monitor_&_Logging/loginLogger"); const getUserCredentials = require("../model/getUserCredentials.js"); const { addMfaToken, verifyMfaToken } = require("../model/addMfaToken.js"); @@ -129,7 +130,7 @@ const login = async (req, res) => { return res.status(200).json({ user, token }); } catch (err) { - console.error("Login error:", err); + logger.error('Login error', { error: err.message, email }); return res.status(500).json({ error: "Internal server error" }); } }; @@ -176,7 +177,7 @@ const loginMfa = async (req, res) => { return res.status(200).json({ user, token }); } catch (err) { - console.error("MFA login error:", err); + logger.error('MFA login error', { error: err.message, email }); return res.status(500).json({ error: "Internal server error" }); } }; @@ -198,9 +199,9 @@ async function sendOtpEmail(email, token) {

– NutriHelp Security Team

` }); - console.log("✅ OTP email sent successfully to", email); + logger.info('OTP email sent successfully', { email }); } catch (err) { - console.error("Error sending OTP email:", err.message); + logger.error('Error sending OTP email', { error: err.message, email }); } } @@ -220,9 +221,9 @@ async function sendFailedLoginAlert(email, ip) {

– NutriHelp Security Team

` }); - console.log(`✅ Failed login alert sent to ${email}`); + logger.info('Failed login alert sent', { email, ip }); } catch (err) { - console.error("Failed to send alert email:", err.message); + logger.error('Failed to send alert email', { error: err.message, email }); } } diff --git a/controller/medicalPredictionController.js b/controller/medicalPredictionController.js index 0811f5ab..adff2e5e 100644 --- a/controller/medicalPredictionController.js +++ b/controller/medicalPredictionController.js @@ -6,6 +6,7 @@ // [TEMP-DB-OFF] keep imports for easy revert; safe to leave unused const { insertSurvey } = require("../model/healthSurveyModel"); const { insertRiskReport } = require("../model/healthRiskReportModel"); +const logger = require('../utils/logger'); const AI_RETRIEVE_URL = process.env.AI_RETRIEVE_URL || @@ -193,7 +194,7 @@ const predict = async (req, res) => { medical_report, }); } catch (error) { - console.error("[predict] Unexpected error:", error); + logger.error('Unexpected error in medical prediction', { error: error.message }); return res.status(500).json({ error: "Internal server error" }); } }; diff --git a/controller/notificationController.js b/controller/notificationController.js index c4ce8e19..89ddc1a7 100644 --- a/controller/notificationController.js +++ b/controller/notificationController.js @@ -1,4 +1,5 @@ const supabase = require('../dbConnection.js'); +const logger = require('../utils/logger'); // Create a new notification exports.createNotification = async (req, res) => { @@ -13,7 +14,7 @@ exports.createNotification = async (req, res) => { res.status(201).json({ message: 'Notification created', notification: data }); } catch (error) { - console.error('Error creating notification:', error); + logger.error('Error creating notification', { error: error.message, user_id: req.body.user_id }); res.status(500).json({ error: 'An error occurred while creating the notification' }); } }; @@ -36,7 +37,7 @@ exports.getNotificationsByUserId = async (req, res) => { res.status(200).json(data); } catch (error) { - console.error('Error retrieving notifications:', error); + logger.error('Error retrieving notifications', { error: error.message, user_id: req.params.user_id }); res.status(500).json({ error: 'An error occurred while retrieving notifications' }); } }; @@ -54,7 +55,7 @@ exports.updateNotificationStatusById = async (req, res) => { if (error) { - console.error('Error updating notification:', error); + logger.error('Error updating notification', { error: error.message, notificationId: id }); return res.status(500).json({ error: 'Failed to update notification' }); } @@ -65,7 +66,7 @@ exports.updateNotificationStatusById = async (req, res) => { res.status(200).json({ message: 'Notification updated successfully', notification: data }); } catch (error) { - console.error('Error updating notification:', error); + logger.error('Error updating notification', { error: error.message, notificationId: req.params.id }); res.status(500).json({ error: 'An error occurred while updating the notification' }); } }; @@ -82,7 +83,7 @@ exports.deleteNotificationById = async (req, res) => { if (error) { - console.error('Error deleting notification:', error); + logger.error('Error deleting notification', { error: error.message, notificationId: id }); return res.status(500).json({ error: 'Failed to delete notification' }); } @@ -93,7 +94,7 @@ exports.deleteNotificationById = async (req, res) => { res.status(200).json({ message: 'Notification deleted successfully' }); } catch (error) { - console.error('Error deleting notification:', error); + logger.error('Error deleting notification', { error: error.message, notificationId: req.params.id }); res.status(500).json({ error: 'An error occurred while deleting the notification' }); } }; @@ -121,7 +122,7 @@ exports.markAllUnreadNotificationsAsRead = async (req, res) => { res.status(200).json({ message: 'All unread notifications marked as read', updatedNotifications: data }); } catch (error) { - console.error('Error marking notifications as read:', error); + logger.error('Error marking notifications as read', { error: error.message, user_id: req.params.user_id }); res.status(500).json({ error: 'An error occurred while marking notifications as read' }); } }; diff --git a/controller/uploadController.js b/controller/uploadController.js index 04fb4780..5e8ed247 100644 --- a/controller/uploadController.js +++ b/controller/uploadController.js @@ -1,4 +1,5 @@ const multer = require('multer'); +const logger = require('../utils/logger'); const { createClient } = require('@supabase/supabase-js'); const supabase = createClient( @@ -76,7 +77,7 @@ exports.uploadFile = async (req, res) => { return res.status(201).json({ message: 'File uploaded successfully', fileUrl: fileUrl }); } catch (error) { - console.error('❌ File upload failed:', error); + logger.error('File upload failed', { error: error.message, userId: req.user?.userId }); return res.status(500).json({ error: 'File upload failed' }); } }); diff --git a/controller/userPreferencesController.js b/controller/userPreferencesController.js index fc7b5902..f99205c5 100644 --- a/controller/userPreferencesController.js +++ b/controller/userPreferencesController.js @@ -1,4 +1,5 @@ const fetchUserPreferences = require("../model/fetchUserPreferences"); +const logger = require('../utils/logger'); const updateUserPreferences = require("../model/updateUserPreferences"); const getUserPreferences = async (req, res) => { @@ -17,7 +18,7 @@ const getUserPreferences = async (req, res) => { return res.status(200).json(userPreferences); } catch (error) { - console.error(error); + logger.error('Error fetching user preferences', { error: error.message, userId: req.user?.userId }); return res.status(500).json({ error: "Internal server error" }); } }; @@ -31,7 +32,7 @@ const postUserPreferences = async (req, res) => { .status(204) .json({ message: "User preferences updated successfully" }); } catch (error) { - console.error(error); + logger.error('Error updating user preferences', { error: error.message, userId: req.body.user?.userId }); return res.status(500).json({ error: "Internal server error" }); } }; diff --git a/middleware/requestLogger.js b/middleware/requestLogger.js new file mode 100644 index 00000000..8cf5bdbf --- /dev/null +++ b/middleware/requestLogger.js @@ -0,0 +1,83 @@ +/** + * middleware/requestLogger.js + * + * Structured request logging middleware + * Logs all incoming requests and responses + */ + +const logger = require('../utils/logger'); + +/** + * Generate unique request ID + */ +const generateRequestId = () => { + return `${Date.now()}-${Math.random().toString(36).substr(2, 9)}`; +}; + +/** + * Main request logging middleware + */ +const requestLoggingMiddleware = (req, res, next) => { + // Generate and attach request ID + const requestId = req.headers['x-request-id'] || generateRequestId(); + req.id = requestId; + + // Track request start time + const startTime = Date.now(); + + // Extract useful request info + const method = req.method; + const path = req.path; + const ip = req.ip || req.connection.remoteAddress; + const userAgent = req.headers['user-agent'] || 'unknown'; + + // Log incoming request + logger.info(`→ ${method} ${path}`, { + requestId, + method, + path, + ip, + userAgent, + ...(req.user ? { userId: req.user.id } : {}), + query: Object.keys(req.query).length > 0 ? req.query : undefined + }); + + // Capture response details + const originalSend = res.send; + res.send = function(data) { + // Calculate duration + const duration = Date.now() - startTime; + const statusCode = res.statusCode; + + // Determine log level based on status code + let logLevel = 'info'; + if (statusCode >= 500) logLevel = 'error'; + else if (statusCode >= 400) logLevel = 'warn'; + else if (duration > 5000) logLevel = 'warn'; // Slow request + + // Log response + const logMessage = `← ${method} ${path} ${statusCode} (${duration}ms)`; + + logger[logLevel](logMessage, { + requestId, + method, + path, + statusCode, + duration, + ...(req.user ? { userId: req.user.id } : {}), + contentLength: res.get('content-length'), + ...(logLevel === 'error' ? { responseBody: data } : {}) + }); + + // Call original send + return originalSend.call(this, data); + }; + + // Attach logger to request for use in controllers + req.logger = logger; + req.requestId = requestId; + + next(); +}; + +module.exports = { requestLoggingMiddleware, generateRequestId }; diff --git a/middleware/structuredErrorHandler.js b/middleware/structuredErrorHandler.js new file mode 100644 index 00000000..8e01851e --- /dev/null +++ b/middleware/structuredErrorHandler.js @@ -0,0 +1,79 @@ +/** + * middleware/structuredErrorHandler.js + * + * Centralized error handling with structured logging + * Should be used as the last middleware in Express + */ + +const logger = require('../utils/logger'); + +/** + * Structured error handling middleware + * Must be defined after all other middleware and routes + */ +const structuredErrorHandler = (err, req, res, next) => { + // Determine error status code + const statusCode = err.statusCode || err.status || 500; + const isClientError = statusCode >= 400 && statusCode < 500; + const isServerError = statusCode >= 500; + + // Build error context + const errorContext = { + requestId: req.id || req.requestId, + userId: req.user?.id, + method: req.method, + path: req.path, + ip: req.ip, + statusCode, + errorType: err.constructor.name, + errorCode: err.code, + validation: err.validation, // For validation errors + details: err.details // Additional error details + }; + + // Log the error with appropriate level + if (isServerError) { + logger.error(`Server Error: ${err.message}`, { + ...errorContext, + stack: err.stack, + ...(err.originalError && { originalError: err.originalError }) + }); + } else if (isClientError) { + logger.warn(`Client Error: ${err.message}`, { + ...errorContext, + // Don't include stack trace for client errors + }); + } else { + logger.info(`Error: ${err.message}`, errorContext); + } + + // Send error response + res.status(statusCode).json({ + success: false, + error: { + message: err.message, + code: err.code || 'INTERNAL_ERROR', + ...(process.env.NODE_ENV !== 'production' && { stack: err.stack }) + }, + requestId: req.id || req.requestId, + ...(process.env.NODE_ENV === 'development' && { details: err.details }) + }); +}; + +/** + * Custom error class for structured errors + */ +class AppError extends Error { + constructor(message, statusCode = 500, code = 'ERROR', details = {}) { + super(message); + this.statusCode = statusCode; + this.code = code; + this.details = details; + Error.captureStackTrace(this, this.constructor); + } +} + +module.exports = { + structuredErrorHandler, + AppError +}; diff --git a/package-lock.json b/package-lock.json index 74a2579a..6244baa9 100644 --- a/package-lock.json +++ b/package-lock.json @@ -31,6 +31,7 @@ "sinon": "18.0.0", "swagger-ui-express": "5.0.0", "twilio": "5.9.0", + "winston": "^3.11.0", "yamljs": "0.3.0" }, "devDependencies": { @@ -639,6 +640,26 @@ "dev": true, "license": "MIT" }, + "node_modules/@colors/colors": { + "version": "1.6.0", + "resolved": "https://registry.npmjs.org/@colors/colors/-/colors-1.6.0.tgz", + "integrity": "sha512-Ir+AOibqzrIsL6ajt3Rz3LskB7OiMVHqltZmspbW/TJuTVuyOMirVqAkjfY6JISiLHgyNqicAC8AyHHGzNd/dA==", + "license": "MIT", + "engines": { + "node": ">=0.1.90" + } + }, + "node_modules/@dabh/diagnostics": { + "version": "2.0.8", + "resolved": "https://registry.npmjs.org/@dabh/diagnostics/-/diagnostics-2.0.8.tgz", + "integrity": "sha512-R4MSXTVnuMzGD7bzHdW2ZhhdPC/igELENcq5IjEverBvq5hn1SXCWcsi6eSsdWP0/Ur+SItRRjAktmdoX/8R/Q==", + "license": "MIT", + "dependencies": { + "@so-ric/colorspace": "^1.1.6", + "enabled": "2.0.x", + "kuler": "^2.0.0" + } + }, "node_modules/@emnapi/core": { "version": "1.7.1", "resolved": "https://registry.npmjs.org/@emnapi/core/-/core-1.7.1.tgz", @@ -1497,6 +1518,16 @@ "integrity": "sha512-DE427ROAphMQzU4ENbliGYrBSYPXF+TtLg9S8vzeA+OF4ZKzoDdzfL8sxuMUGS/lgRhM6j1URSk9ghf7Xo1tyA==", "license": "(Unlicense OR Apache-2.0)" }, + "node_modules/@so-ric/colorspace": { + "version": "1.1.6", + "resolved": "https://registry.npmjs.org/@so-ric/colorspace/-/colorspace-1.1.6.tgz", + "integrity": "sha512-/KiKkpHNOBgkFJwu9sh48LkHSMYGyuTcSFK/qMBdnOAlrRJzRSXAOFB5qwzaVQuDl8wAvHVMkaASQDReTahxuw==", + "license": "MIT", + "dependencies": { + "color": "^5.0.2", + "text-hex": "1.0.x" + } + }, "node_modules/@supabase/auth-js": { "version": "2.86.0", "resolved": "https://registry.npmjs.org/@supabase/auth-js/-/auth-js-2.86.0.tgz", @@ -1709,6 +1740,12 @@ "form-data": "^4.0.0" } }, + "node_modules/@types/triple-beam": { + "version": "1.3.5", + "resolved": "https://registry.npmjs.org/@types/triple-beam/-/triple-beam-1.3.5.tgz", + "integrity": "sha512-6WaYesThRMCl19iryMYP7/x2OVgCtbIVflDGFpWnb9irXI3UjYE4AzmYuiUKY1AJstGijoY+MgUszMgRxIYTYw==", + "license": "MIT" + }, "node_modules/@types/ws": { "version": "8.18.1", "resolved": "https://registry.npmjs.org/@types/ws/-/ws-8.18.1.tgz", @@ -2173,6 +2210,12 @@ "dev": true, "license": "MIT" }, + "node_modules/async": { + "version": "3.2.6", + "resolved": "https://registry.npmjs.org/async/-/async-3.2.6.tgz", + "integrity": "sha512-htCUDlxyyCLMgaM3xXg0C0LW2xqfuQ6p05pCEIsXuyQ+a1koYKTuBMzRNwmybfLgvJDMd0r1LTn4+E0Ti6C2AA==", + "license": "MIT" + }, "node_modules/asynckit": { "version": "0.4.0", "resolved": "https://registry.npmjs.org/asynckit/-/asynckit-0.4.0.tgz", @@ -2770,6 +2813,19 @@ "dev": true, "license": "MIT" }, + "node_modules/color": { + "version": "5.0.3", + "resolved": "https://registry.npmjs.org/color/-/color-5.0.3.tgz", + "integrity": "sha512-ezmVcLR3xAVp8kYOm4GS45ZLLgIE6SPAFoduLr6hTDajwb3KZ2F46gulK3XpcwRFb5KKGCSezCBAY4Dw4HsyXA==", + "license": "MIT", + "dependencies": { + "color-convert": "^3.1.3", + "color-string": "^2.1.3" + }, + "engines": { + "node": ">=18" + } + }, "node_modules/color-convert": { "version": "2.0.1", "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-2.0.1.tgz", @@ -2790,6 +2846,27 @@ "dev": true, "license": "MIT" }, + "node_modules/color-string": { + "version": "2.1.4", + "resolved": "https://registry.npmjs.org/color-string/-/color-string-2.1.4.tgz", + "integrity": "sha512-Bb6Cq8oq0IjDOe8wJmi4JeNn763Xs9cfrBcaylK1tPypWzyoy2G3l90v9k64kjphl/ZJjPIShFztenRomi8WTg==", + "license": "MIT", + "dependencies": { + "color-name": "^2.0.0" + }, + "engines": { + "node": ">=18" + } + }, + "node_modules/color-string/node_modules/color-name": { + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/color-name/-/color-name-2.1.0.tgz", + "integrity": "sha512-1bPaDNFm0axzE4MEAzKPuqKWeRaT43U/hyxKPBdqTfmPF+d6n7FSoTFxLVULUJOmiLp01KjhIPPH+HrXZJN4Rg==", + "license": "MIT", + "engines": { + "node": ">=12.20" + } + }, "node_modules/color-support": { "version": "1.1.3", "resolved": "https://registry.npmjs.org/color-support/-/color-support-1.1.3.tgz", @@ -2798,6 +2875,27 @@ "color-support": "bin.js" } }, + "node_modules/color/node_modules/color-convert": { + "version": "3.1.3", + "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-3.1.3.tgz", + "integrity": "sha512-fasDH2ont2GqF5HpyO4w0+BcewlhHEZOFn9c1ckZdHpJ56Qb7MHhH/IcJZbBGgvdtwdwNbLvxiBEdg336iA9Sg==", + "license": "MIT", + "dependencies": { + "color-name": "^2.0.0" + }, + "engines": { + "node": ">=14.6" + } + }, + "node_modules/color/node_modules/color-name": { + "version": "2.1.0", + "resolved": "https://registry.npmjs.org/color-name/-/color-name-2.1.0.tgz", + "integrity": "sha512-1bPaDNFm0axzE4MEAzKPuqKWeRaT43U/hyxKPBdqTfmPF+d6n7FSoTFxLVULUJOmiLp01KjhIPPH+HrXZJN4Rg==", + "license": "MIT", + "engines": { + "node": ">=12.20" + } + }, "node_modules/combined-stream": { "version": "1.0.8", "resolved": "https://registry.npmjs.org/combined-stream/-/combined-stream-1.0.8.tgz", @@ -3209,6 +3307,12 @@ "integrity": "sha512-MSjYzcWNOA0ewAHpz0MxpYFvwg6yjy1NG3xteoqz644VCo/RPgnr1/GGt+ic3iJTzQ8Eu3TdM14SawnVUmGE6A==", "license": "MIT" }, + "node_modules/enabled": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/enabled/-/enabled-2.0.0.tgz", + "integrity": "sha512-AKrN98kuwOzMIdAizXGI86UFBoo26CL21UM763y1h/GMSJ4/OHU9k2YlsmBpyScFo/wbLzWQJBMCW4+IO3/+OQ==", + "license": "MIT" + }, "node_modules/encodeurl": { "version": "1.0.2", "resolved": "https://registry.npmjs.org/encodeurl/-/encodeurl-1.0.2.tgz", @@ -3492,6 +3596,12 @@ "bser": "2.1.1" } }, + "node_modules/fecha": { + "version": "4.2.3", + "resolved": "https://registry.npmjs.org/fecha/-/fecha-4.2.3.tgz", + "integrity": "sha512-OP2IUU6HeYKJi3i0z4A19kHMQoLVs4Hc+DPqqxI2h/DPZHTm/vjsfC6P0b4jCMy14XizLBqvndQ+UilD7707Jw==", + "license": "MIT" + }, "node_modules/fetch-blob": { "version": "3.2.0", "resolved": "https://registry.npmjs.org/fetch-blob/-/fetch-blob-3.2.0.tgz", @@ -3587,6 +3697,12 @@ "flat": "cli.js" } }, + "node_modules/fn.name": { + "version": "1.1.0", + "resolved": "https://registry.npmjs.org/fn.name/-/fn.name-1.1.0.tgz", + "integrity": "sha512-GRnmB5gPyJpAhTQdSZTSp9uaPSvl09KoYcMQtsB9rQoOmzs9dH6ffeccH+Z+cv6P68Hu5bC6JjRh4Ah/mHSNRw==", + "license": "MIT" + }, "node_modules/follow-redirects": { "version": "1.15.11", "resolved": "https://registry.npmjs.org/follow-redirects/-/follow-redirects-1.15.11.tgz", @@ -4333,7 +4449,6 @@ "version": "2.0.1", "resolved": "https://registry.npmjs.org/is-stream/-/is-stream-2.0.1.tgz", "integrity": "sha512-hFoiJiTl63nn+kstHGBtewWSKnQLpyb155KHheA1l39uvtO9nWIop1p3udqPcUd/xbF1VLMO4n7OI6p7RbngDg==", - "dev": true, "license": "MIT", "engines": { "node": ">=8" @@ -5193,6 +5308,12 @@ "safe-buffer": "^5.0.1" } }, + "node_modules/kuler": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/kuler/-/kuler-2.0.0.tgz", + "integrity": "sha512-Xq9nH7KlWZmXAtodXDDRE7vs6DU1gTU8zYDHDiWLSip45Egwq3plLHzPn27NgvzL2r1LMPC1vdqh98sQxtqj4A==", + "license": "MIT" + }, "node_modules/leven": { "version": "3.1.0", "resolved": "https://registry.npmjs.org/leven/-/leven-3.1.0.tgz", @@ -5291,6 +5412,29 @@ "url": "https://github.com/sponsors/sindresorhus" } }, + "node_modules/logform": { + "version": "2.7.0", + "resolved": "https://registry.npmjs.org/logform/-/logform-2.7.0.tgz", + "integrity": "sha512-TFYA4jnP7PVbmlBIfhlSe+WKxs9dklXMTEGcBCIvLhE/Tn3H6Gk1norupVW7m5Cnd4bLcr08AytbyV/xj7f/kQ==", + "license": "MIT", + "dependencies": { + "@colors/colors": "1.6.0", + "@types/triple-beam": "^1.3.2", + "fecha": "^4.2.0", + "ms": "^2.1.1", + "safe-stable-stringify": "^2.3.1", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, + "node_modules/logform/node_modules/ms": { + "version": "2.1.3", + "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.3.tgz", + "integrity": "sha512-6FlzubTLZG3J2a/NVCAleEhjzq5oxgHyaCU9yYXvcLsvoVaHJq/s5xXI6/XXP6tz7R9xAOtHnSO/tXtF3WRTlA==", + "license": "MIT" + }, "node_modules/long": { "version": "5.3.2", "resolved": "https://registry.npmjs.org/long/-/long-5.3.2.tgz", @@ -6012,6 +6156,15 @@ "wrappy": "1" } }, + "node_modules/one-time": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/one-time/-/one-time-1.0.0.tgz", + "integrity": "sha512-5DXOiRKwuSEcQ/l0kGCF6Q3jcADFv5tSmRaJck/OqkVFcOzutB134KRSfF0xDrL39MNnqxbHBbUUcjZIhTgb2g==", + "license": "MIT", + "dependencies": { + "fn.name": "1.x.x" + } + }, "node_modules/onetime": { "version": "5.1.2", "resolved": "https://registry.npmjs.org/onetime/-/onetime-5.1.2.tgz", @@ -6601,6 +6754,15 @@ ], "license": "MIT" }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz", @@ -6904,6 +7066,15 @@ "node": ">= 0.6" } }, + "node_modules/stack-trace": { + "version": "0.0.10", + "resolved": "https://registry.npmjs.org/stack-trace/-/stack-trace-0.0.10.tgz", + "integrity": "sha512-KGzahc7puUKkzyMt+IqAep+TVNbKP+k2Lmwhub39m1AsTSkaDutx56aDCo+HLDzf/D26BIHTJWNiTG1KAJiQCg==", + "license": "MIT", + "engines": { + "node": "*" + } + }, "node_modules/stack-utils": { "version": "2.0.6", "resolved": "https://registry.npmjs.org/stack-utils/-/stack-utils-2.0.6.tgz", @@ -7336,6 +7507,12 @@ "node": "*" } }, + "node_modules/text-hex": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/text-hex/-/text-hex-1.0.0.tgz", + "integrity": "sha512-uuVGNWzgJ4yhRaNSiubPY7OjISw4sw4E5Uv0wbjp+OzcbmVU/rsT8ujgcXJhn9ypzsgr5vlzpPqP+MBBKcGvbg==", + "license": "MIT" + }, "node_modules/time-span": { "version": "5.1.0", "resolved": "https://registry.npmjs.org/time-span/-/time-span-5.1.0.tgz", @@ -7407,6 +7584,15 @@ "tree-kill": "cli.js" } }, + "node_modules/triple-beam": { + "version": "1.4.1", + "resolved": "https://registry.npmjs.org/triple-beam/-/triple-beam-1.4.1.tgz", + "integrity": "sha512-aZbgViZrg1QNcG+LULa7nhZpJTZSLm/mXnHXnbAbjmN5aSa0y7V+wvv6+4WaBtpISJzThKy+PIPxc1Nq1EJ9mg==", + "license": "MIT", + "engines": { + "node": ">= 14.0.0" + } + }, "node_modules/tslib": { "version": "2.8.1", "resolved": "https://registry.npmjs.org/tslib/-/tslib-2.8.1.tgz", @@ -7676,6 +7862,70 @@ "string-width": "^1.0.2 || 2 || 3 || 4" } }, + "node_modules/winston": { + "version": "3.11.0", + "resolved": "https://registry.npmjs.org/winston/-/winston-3.11.0.tgz", + "integrity": "sha512-L3yR6/MzZAOl0DsysUXHVjOwv8mKZ71TrA/41EIduGpOOV5LQVodqN+QdQ6BS6PJ/RdIshZhq84P/fStEZkk7g==", + "license": "MIT", + "dependencies": { + "@colors/colors": "^1.6.0", + "@dabh/diagnostics": "^2.0.2", + "async": "^3.2.3", + "is-stream": "^2.0.0", + "logform": "^2.4.0", + "one-time": "^1.0.0", + "readable-stream": "^3.4.0", + "safe-stable-stringify": "^2.3.1", + "stack-trace": "0.0.x", + "triple-beam": "^1.3.0", + "winston-transport": "^4.5.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, + "node_modules/winston-transport": { + "version": "4.9.0", + "resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.9.0.tgz", + "integrity": "sha512-8drMJ4rkgaPo1Me4zD/3WLfI/zPdA9o2IipKODunnGDcuqbHwjsbB79ylv04LCGGzU0xQ6vTznOMpQGaLhhm6A==", + "license": "MIT", + "dependencies": { + "logform": "^2.7.0", + "readable-stream": "^3.6.2", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, + "node_modules/winston-transport/node_modules/readable-stream": { + "version": "3.6.2", + "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.2.tgz", + "integrity": "sha512-9u/sniCrY3D5WdsERHzHE4G2YCXqoG5FTHUiCC4SIbr6XcLZBY05ya9EKjYek9O5xOAwjGq+1JdGBAS7Q9ScoA==", + "license": "MIT", + "dependencies": { + "inherits": "^2.0.3", + "string_decoder": "^1.1.1", + "util-deprecate": "^1.0.1" + }, + "engines": { + "node": ">= 6" + } + }, + "node_modules/winston/node_modules/readable-stream": { + "version": "3.6.2", + "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.2.tgz", + "integrity": "sha512-9u/sniCrY3D5WdsERHzHE4G2YCXqoG5FTHUiCC4SIbr6XcLZBY05ya9EKjYek9O5xOAwjGq+1JdGBAS7Q9ScoA==", + "license": "MIT", + "dependencies": { + "inherits": "^2.0.3", + "string_decoder": "^1.1.1", + "util-deprecate": "^1.0.1" + }, + "engines": { + "node": ">= 6" + } + }, "node_modules/workerpool": { "version": "9.3.4", "resolved": "https://registry.npmjs.org/workerpool/-/workerpool-9.3.4.tgz", diff --git a/package.json b/package.json index 651a13fe..9d26bcb8 100644 --- a/package.json +++ b/package.json @@ -46,6 +46,7 @@ "sinon": "18.0.0", "swagger-ui-express": "5.0.0", "twilio": "5.9.0", + "winston": "^3.11.0", "yamljs": "0.3.0" }, "devDependencies": { diff --git a/server.js b/server.js index b1c8ffd1..d385836a 100644 --- a/server.js +++ b/server.js @@ -1,5 +1,10 @@ require("dotenv").config(); +// Structured Logging - NEW +const logger = require('./utils/logger'); +const { requestLoggingMiddleware } = require('./middleware/requestLogger'); +const { structuredErrorHandler } = require('./middleware/structuredErrorHandler'); + //Logging & Metrics const { metricsMiddleware, @@ -74,8 +79,8 @@ const port = process.env.PORT || 80; // DB let db = require("./dbConnection"); -// System routes -app.use("/api/system", systemRoutes); +// ⚠️ CRITICAL: Add request logging middleware FIRST, before any routes +app.use(requestLoggingMiddleware); // CORS app.use( @@ -146,6 +151,9 @@ app.use(express.urlencoded({ limit: "50mb", extended: true })); app.use(metricsMiddleware); app.get("/metrics", metricsEndpoint); +// System routes (early in chain) +app.use("/api/system", systemRoutes); + // Main routes registrar const routes = require("./routes"); routes(app); @@ -161,20 +169,8 @@ app.use("/security", securityEventsRoutes); // Error handler app.use(errorLogger); -// Final error handler -app.use((err, req, res, next) => { - const status = err.status || 500; - const message = - process.env.NODE_ENV === "production" - ? "Internal Server Error" - : err.message; - - res.status(status).json({ - success: false, - error: message, - timestamp: new Date().toISOString(), - }); -}); +// Structured error handling middleware (MUST be last) +app.use(structuredErrorHandler); // Global error handler const { diff --git a/utils/logger.js b/utils/logger.js new file mode 100644 index 00000000..60d4d266 --- /dev/null +++ b/utils/logger.js @@ -0,0 +1,163 @@ +/** + * utils/logger.js + * + * Centralized structured logging using Winston + * + * Usage: + * const logger = require('../utils/logger'); + * logger.info('User logged in', { userId: 123, email: 'user@example.com' }); + * logger.error('Database error', { error: err, query: sql }); + * logger.warn('Rate limit approaching', { userId: 123, limit: 1000 }); + */ + +const winston = require('winston'); +const path = require('path'); +const fs = require('fs'); + +// Ensure logs directory exists +const logsDir = path.join(process.cwd(), 'logs'); +if (!fs.existsSync(logsDir)) { + fs.mkdirSync(logsDir, { recursive: true }); +} + +/** + * Custom format for structured logging + */ +const customFormat = winston.format.combine( + winston.format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }), + winston.format.errors({ stack: true }), + winston.format.json(), + // Custom printf for console (more readable) + winston.format.printf(({ timestamp, level, message, requestId, userId, ...meta }) => { + let baseLog = `${timestamp} [${level.toUpperCase()}]`; + + if (requestId) baseLog += ` [REQ:${requestId}]`; + if (userId) baseLog += ` [USER:${userId}]`; + + baseLog += ` ${message}`; + + // Add metadata if present + if (Object.keys(meta).length > 0) { + // Filter out the symbol used by winston + const cleanMeta = Object.fromEntries( + Object.entries(meta).filter(([key]) => !key.startsWith('Symbol')) + ); + if (Object.keys(cleanMeta).length > 0) { + baseLog += ` ${JSON.stringify(cleanMeta)}`; + } + } + + return baseLog; + }) +); + +/** + * Create logger with Winston + */ +const logger = winston.createLogger({ + level: process.env.LOG_LEVEL || (process.env.NODE_ENV === 'production' ? 'info' : 'debug'), + format: customFormat, + defaultMeta: { + service: 'nutrihelp-api', + environment: process.env.NODE_ENV || 'development' + }, + transports: [ + // Console output (always) + new winston.transports.Console({ + level: process.env.NODE_ENV === 'production' ? 'info' : 'debug', + format: winston.format.combine( + winston.format.colorize(), + winston.format.printf(({ timestamp, level, message, requestId, userId, ...meta }) => { + let output = `${timestamp} ${level} `; + if (requestId) output += `(${requestId}) `; + if (userId) output += `[${userId}] `; + output += message; + + if (Object.keys(meta).length > 0) { + const cleanMeta = Object.fromEntries( + Object.entries(meta).filter(([key]) => !key.startsWith('Symbol')) + ); + if (Object.keys(cleanMeta).length > 0) { + output += ` ${JSON.stringify(cleanMeta, null, 2)}`; + } + } + return output; + }) + ) + }), + + // File logging - all logs + new winston.transports.File({ + filename: path.join(logsDir, 'app.log'), + maxsize: 10485760, // 10MB + maxFiles: 5, + format: winston.format.json() + }), + + // File logging - errors only + new winston.transports.File({ + filename: path.join(logsDir, 'error.log'), + level: 'error', + maxsize: 10485760, + maxFiles: 10, + format: winston.format.json() + }), + + // File logging - requests (if in production) + ...(process.env.NODE_ENV === 'production' ? [ + new winston.transports.File({ + filename: path.join(logsDir, 'requests.log'), + maxsize: 10485760, + maxFiles: 5, + format: winston.format.json() + }) + ] : []) + ] +}); + +/** + * Log levels: + * error (0): Something failed + * warn (1): Something concerning but not fatal + * info (2): General information + * http (3): HTTP requests/responses + * debug (4): Detailed debugging information + */ + +/** + * Helper to create error log with standard format + */ +logger.logError = (message, error, context = {}) => { + logger.error(message, { + error: { + message: error?.message, + code: error?.code, + stack: error?.stack + }, + ...context + }); +}; + +/** + * Helper to create HTTP log with standard format + */ +logger.logHttpRequest = (method, path, statusCode, duration, context = {}) => { + logger.info(`${method} ${path} - ${statusCode}`, { + http: { + method, + path, + statusCode, + duration: `${duration}ms` + }, + ...context + }); +}; + +/** + * Helper for database operations + */ +logger.logDB = (operation, table, context = {}) => { + logger.debug(`DB: ${operation} on ${table}`, context); +}; + +module.exports = logger;