Merge pull request #715 from SatyamPandey-07/feature/logging-telemetry-713

Fix #713: Implement Centralized Structured Logging & Telemetry Pipeline

Author: Renu-code123

LOGGING_ARCHITECTURE.md

@@ -0,0 +1,57 @@
+# Centralized Structured Logging & Telemetry Pipeline
+
+## 🚀 Overview
+Issue #713 overhauls the application's logging infrastructure, moving from primitive `console.log` statements to a professional **Structured JSON Logging System**. This allows for high-resolution request tracing, automated monitoring, and easier debugging across distributed components.
+
+## 🏗️ Technical Architecture
+
+### 1. Structured Logger (`utils/structuredLogger.js`)
+The core engine that produces JSON-formatted logs.
+- **AsyncLocalStorage**: Uses Node.js `AsyncLocalStorage` to automatically propagate Trace IDs (Correlation IDs) across asynchronous operations without manual prop-drilling.
+- **Log Levels**: Supports `DEBUG`, `INFO`, `WARN`, `ERROR`, and `CRITICAL`.
+- **Metadata Support**: Every log can include a dynamic metadata object for rich context.
+
+### 2. Request Correlation (`middleware/requestCorrelation.js`)
+- Generates a `traceId` for every incoming HTTP request.
+- Injects this ID into the logger's storage context.
+- Returns the ID as a response header (`x-trace-id`) for better client-side troubleshooting.
+
+### 3. HTTP Traffic Interceptor (`middleware/httpLogger.js`)
+- Records every request and response.
+- Calculates and logs the **Response Latency** in milliseconds.
+- Automatically adjusts log levels based on HTTP status codes (4xx = Warn, 5xx = Error).
+
+### 4. Telemetry Sink (`utils/telemetryExporter.js`)
+- Implements a buffered export pattern.
+- Batches logs to reduce I/O overhead.
+- Simulates integration with professional observability platforms (Datadog/NewRelic).
+
+## 📂 File Structure
+- `utils/structuredLogger.js`: The JSON logger engine.
+- `middleware/requestCorrelation.js`: Context provider.
+- `middleware/httpLogger.js`: Network telemetry.
+- `utils/telemetryExporter.js`: Centralized export.
+- `routes/telemetry.js`: Visibility API.
+- `jobs/logRotator.js`: Maintenance & disk cleanup.
+
+## 📊 Sample Log Entry
+```json
+{
+  "timestamp": "2026-02-19T13:14:02.123Z",
+  "level": "INFO",
+  "message": "Completed POST /api/expenses [201]",
+  "traceId": "a1b2c3d4-e5f6-7890",
+  "userId": "648f12a3b4c5",
+  "type": "http_response",
+  "durationMs": 45,
+  "environment": "production"
+}
+```
+
+## ✅ Implementation Checklist
+- [x] JSON-structured logger with `AsyncLocalStorage`.
+- [x] Request Trace ID propagation middleware.
+- [x] Automatic HTTP latency logging.
+- [x] Batch log exporter with buffering logic.
+- [x] Log rotation and archival background job.
+- [x] Refactored existing services to use structured logs.

jobs/logRotator.js

@@ -0,0 +1,67 @@
+const cron = require('node-cron');
+const fs = require('fs');
+const path = require('path');
+const logger = require('../utils/structuredLogger');
+
+/**
+ * Log Rotator Job
+ * Issue #713: Prevents log files from consuming infinite disk space.
+ */
+class LogRotator {
+    constructor() {
+        this.logDir = path.join(process.cwd(), 'logs');
+    }
+
+    start() {
+        console.log('[LogRotator] Initializing log rotation worker...');
+
+        // Run every night at midnight
+        cron.schedule('0 0 * * *', () => {
+            this.rotate();
+        });
+    }
+
+    rotate() {
+        logger.info('Starting nightly log rotation sequence...');
+
+        try {
+            const files = fs.readdirSync(this.logDir);
+            const timestamp = new Date().toISOString().replace(/:/g, '-');
+
+            for (const file of files) {
+                if (file.endsWith('.log') && !file.includes('_archive_')) {
+                    const oldPath = path.join(this.logDir, file);
+                    const newPath = path.join(this.logDir, `${file.replace('.log', '')}_archive_${timestamp}.log`);
+
+                    // In a real system, we might GZIP this, or move it to S3
+                    fs.renameSync(oldPath, newPath);
+                }
+            }
+
+            // Also clean up archives older than 7 days
+            this.cleanupArchives();
+
+            logger.info('Log rotation completed successfully.');
+        } catch (err) {
+            logger.error('Log rotation failed', { error: err.message });
+        }
+    }
+
+    cleanupArchives() {
+        const files = fs.readdirSync(this.logDir);
+        const sevenDaysAgo = Date.now() - (7 * 24 * 60 * 60 * 1000);
+
+        for (const file of files) {
+            if (file.includes('_archive_')) {
+                const filePath = path.join(this.logDir, file);
+                const stats = fs.statSync(filePath);
+
+                if (stats.mtimeMs < sevenDaysAgo) {
+                    fs.unlinkSync(filePath);
+                }
+            }
+        }
+    }
+}
+
+module.exports = new LogRotator();

logs/info.log

@@ -0,0 +1,2 @@
+{"timestamp":"2026-02-19T13:19:09.339Z","level":"INFO","message":"System startup","traceId":"system","userId":"anonymous","component":"test-suite","environment":"development","version":"1.0.0"}
+{"timestamp":"2026-02-19T13:19:09.342Z","level":"INFO","message":"User action performed","traceId":"test-trace-123","userId":"user-789","action":"click_login","environment":"development","version":"1.0.0"}

logs/warn.log

@@ -0,0 +1 @@
+{"timestamp":"2026-02-19T13:19:09.454Z","level":"WARN","message":"Asynchronous warning","traceId":"test-trace-123","userId":"user-789","latency":500,"environment":"development","version":"1.0.0"}

middleware/httpLogger.js

@@ -0,0 +1,34 @@
+const logger = require('../utils/structuredLogger');
+
+/**
+ * HTTP Request/Response Logger
+ * Issue #713: Standardizes logging for all network traffic.
+ */
+const httpLogger = (req, res, next) => {
+    const startTime = Date.now();
+
+    // Log the incoming request
+    logger.info(`Incoming ${req.method} ${req.originalUrl}`, {
+        type: 'http_request',
+        userAgent: req.get('user-agent'),
+        referrer: req.get('referrer'),
+        ip: req.ip
+    });
+
+    // Hook into the finish event to log the response
+    res.on('finish', () => {
+        const duration = Date.now() - startTime;
+        const level = res.statusCode >= 500 ? 'error' : (res.statusCode >= 400 ? 'warn' : 'info');
+
+        logger[level](`Completed ${req.method} ${req.originalUrl} [${res.statusCode}]`, {
+            type: 'http_response',
+            statusCode: res.statusCode,
+            durationMs: duration,
+            contentLength: res.get('content-length')
+        });
+    });
+
+    next();
+};
+
+module.exports = httpLogger;

middleware/requestCorrelation.js

@@ -0,0 +1,31 @@
+const { v4: uuidv4 } = require('uuid');
+const logger = require('../utils/structuredLogger');
+const crypto = require('crypto');
+
+/**
+ * Request Correlation Middleware
+ * Issue #713: Ensures every request has a unique Trace ID for log aggregation.
+ */
+const requestCorrelation = (req, res, next) => {
+    // Generate or propagate Trace ID
+    const traceId = req.header('x-trace-id') || crypto.randomUUID();
+
+    // Set response header for client-side tracking
+    res.setHeader('x-trace-id', traceId);
+
+    const context = {
+        traceId,
+        startTime: Date.now(),
+        ip: req.ip,
+        method: req.method,
+        url: req.originalUrl,
+        userId: req.user ? req.user._id : null
+    };
+
+    // Run the rest of the request within the async context
+    logger.getStorage().run(context, () => {
+        next();
+    });
+};
+
+module.exports = requestCorrelation;

routes/telemetry.js

@@ -0,0 +1,64 @@
+const express = require('express');
+const router = express.Router();
+const fs = require('fs');
+const path = require('path');
+const auth = require('../middleware/auth');
+const logger = require('../utils/structuredLogger');
+
+/**
+ * Telemetry API
+ * Issue #713: Provides visibility into the centralized logging pipeline.
+ */
+
+router.get('/stats', auth, async (req, res) => {
+    try {
+        const logDir = path.join(process.cwd(), 'logs');
+        const files = fs.readdirSync(logDir);
+
+        const stats = files.map(file => {
+            const filePath = path.join(logDir, file);
+            const size = fs.statSync(filePath).size;
+            return {
+                level: file.split('.')[0],
+                sizeBytes: size,
+                lastUpdated: fs.statSync(filePath).mtime
+            };
+        });
+
+        res.json({
+            success: true,
+            data: {
+                activeLogs: stats,
+                loggerConfig: {
+                    minLevel: process.env.LOG_LEVEL || 'INFO',
+                    environment: process.env.NODE_ENV || 'development'
+                }
+            }
+        });
+    } catch (err) {
+        logger.error('Failed to retrieve telemetry stats', { error: err.message });
+        res.status(500).json({ success: false, error: 'Failed to access log subsystem' });
+    }
+});
+
+router.get('/tail/:level', auth, async (req, res) => {
+    const { level } = req.params;
+    const logFile = path.join(process.cwd(), 'logs', `${level.toLowerCase()}.log`);
+
+    if (!fs.existsSync(logFile)) {
+        return res.status(404).json({ success: false, error: 'Log level file not found' });
+    }
+
+    try {
+        // Simple tail: last 50 lines
+        const content = fs.readFileSync(logFile, 'utf8');
+        const lines = content.trim().split('\n').slice(-50);
+        const logs = lines.map(line => JSON.parse(line));
+
+        res.json({ success: true, data: logs });
+    } catch (err) {
+        res.status(500).json({ success: false, error: 'Failed to read log file' });
+    }
+});
+
+module.exports = router;

server.js

@@ -8,6 +8,11 @@ require('dotenv').config();
 const app = express();
 const server = http.createServer(app);
 
+// Initialize logging context at the very start
+app.use(require('./middleware/requestCorrelation'));
+app.use(require('./middleware/httpLogger'));
+
+
 /* ================================
    SECURITY
 ================================ */
@@ -72,6 +77,8 @@ async function connectDatabase() {
         require('./jobs/forecastRetrainer').start();
         require('./jobs/taxonomyAuditor').start();
         require('./jobs/conflictCleaner').start();
+        require('./jobs/logRotator').start();
+
 
 
         console.log('✓ Cron jobs initialized');
@@ -99,6 +106,10 @@ app.use('/api/analytics', require('./routes/analytics'));
 app.use('/api/export', require('./routes/export'));
 app.use('/api/forecasting', require('./routes/forecasting'));
 app.use('/api/governance', require('./routes/governance'));
+app.use('/api/taxonomy', require('./routes/taxonomy'));
+app.use('/api/sync', require('./routes/syncManager'));
+app.use('/api/telemetry', require('./routes/telemetry'));
+
 
 
 

services/validationEngine.js

@@ -1,6 +1,8 @@
 const remediationRules = require('../utils/remediationRules');
 const ValidationLog = require('../models/ValidationLog');
 const crypto = require('crypto');
+const logger = require('../utils/structuredLogger');
+
 
 
 /**
@@ -80,7 +82,7 @@ class ValidationEngine {
             };
 
         } catch (error) {
-            console.error('[ValidationEngine] Pipeline failure:', error);
+            logger.error('Validation pipeline failure', { error: error.message, stack: error.stack });
             throw error;
         }
     }

utils/structuredLogger.js

@@ -0,0 +1,80 @@
+const fs = require('fs');
+const path = require('path');
+const { AsyncLocalStorage } = require('async_hooks');
+
+/**
+ * Global store for request-scoped context (Correlation IDs)
+ */
+const storage = new AsyncLocalStorage();
+
+/**
+ * Structured Logger Engine
+ * Issue #713: Implements high-performance JSON-based structured logging.
+ */
+class StructuredLogger {
+    constructor() {
+        this.logDir = path.join(process.cwd(), 'logs');
+        if (!fs.existsSync(this.logDir)) {
+            fs.mkdirSync(this.logDir);
+        }
+
+        this.levels = {
+            DEBUG: 0,
+            INFO: 1,
+            WARN: 2,
+            ERROR: 3,
+            CRITICAL: 4
+        };
+
+        this.minLevel = process.env.LOG_LEVEL || 'INFO';
+    }
+
+    /**
+     * Internal method to write the log entry
+     */
+    _write(level, message, metadata = {}) {
+        if (this.levels[level] < this.levels[this.minLevel]) return;
+
+        const context = storage.getStore() || {};
+        const logEntry = {
+            timestamp: new Date().toISOString(),
+            level,
+            message,
+            traceId: context.traceId || 'system',
+            userId: context.userId || 'anonymous',
+            ...metadata,
+            environment: process.env.NODE_ENV || 'development',
+            version: process.env.APP_VERSION || '1.0.0'
+        };
+
+        const logString = JSON.stringify(logEntry);
+
+        // Output to console for cloud log collectors (like Vercel/AWS)
+        if (level === 'ERROR' || level === 'CRITICAL') {
+            console.error(logString);
+        } else {
+            console.log(logString);
+        }
+
+        // Also write to local file for development audit trails
+        const logFile = path.join(this.logDir, `${level.toLowerCase()}.log`);
+        fs.appendFile(logFile, logString + '\n', (err) => {
+            if (err) console.error('Failed to write to log file:', err);
+        });
+    }
+
+    info(msg, meta) { this._write('INFO', msg, meta); }
+    debug(msg, meta) { this._write('DEBUG', msg, meta); }
+    warn(msg, meta) { this._write('WARN', msg, meta); }
+    error(msg, meta) { this._write('ERROR', msg, meta); }
+    critical(msg, meta) { this._write('CRITICAL', msg, meta); }
+
+    /**
+     * Provide access to the storage for middleware integration
+     */
+    getStorage() {
+        return storage;
+    }
+}
+
+module.exports = new StructuredLogger();