- 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 }); } } @@ -335,9 +336,10 @@ async function sendFailedLoginAlert(email, ip) {- NutriHelp Security Team
` }); - } catch (error) { - console.error('Failed to send alert email:', error.message); + logger.info('Failed login alert sent', { email, ip }); + } catch (err) { + logger.error('Failed to send alert email', { error: err.message, email }); } } -module.exports = { login, loginMfa, resendMfa }; +module.exports = { login, loginMfa, resendMfa }; \ No newline at end of file diff --git a/controller/medicalPredictionController.js b/controller/medicalPredictionController.js index 8d32e63..e3b0ad9 100644 --- a/controller/medicalPredictionController.js +++ b/controller/medicalPredictionController.js @@ -1,5 +1,6 @@ const { medicalPredictionService } = require('../services/medicalPredictionService'); const { isServiceError } = require('../services/serviceError'); +const logger = require('../utils/logger'); async function predict(req, res) { try { @@ -13,9 +14,9 @@ async function predict(req, res) { }); } - 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' }); } } -module.exports = { predict }; +module.exports = { predict }; \ No newline at end of file diff --git a/controller/notificationController.js b/controller/notificationController.js index c4ce8e1..89ddc1a 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 04fb478..5e8ed24 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 fc7b590..f99205c 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 0000000..8cf5bdb --- /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 0000000..8e01851 --- /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.json b/package.json index aa8d5f5..963fc66 100644 --- a/package.json +++ b/package.json @@ -49,6 +49,7 @@ "sinon": "18.0.0", "swagger-ui-express": "5.0.0", "twilio": "5.9.0", + "winston": "^3.11.0", "yamljs": "0.3.0" } } \ No newline at end of file diff --git a/server.js b/server.js index b1c8ffd..d385836 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 0000000..60d4d26 --- /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;