feature: add logging

Author: cbullinger

mflix/server/java-spring/src/main/java/com/mongodb/samplemflix/config/RequestLoggingFilter.java

@@ -0,0 +1,105 @@
+package com.mongodb.samplemflix.config;
+
+import jakarta.servlet.FilterChain;
+import jakarta.servlet.ServletException;
+import jakarta.servlet.http.HttpServletRequest;
+import jakarta.servlet.http.HttpServletResponse;
+import java.io.IOException;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.springframework.core.Ordered;
+import org.springframework.core.annotation.Order;
+import org.springframework.stereotype.Component;
+import org.springframework.web.filter.OncePerRequestFilter;
+
+/**
+ * HTTP Request Logging Filter
+ *
+ * <p>This filter logs all incoming HTTP requests with useful information
+ * including method, URL, status code, and response time.
+ * It helps with debugging and monitoring application traffic.
+ *
+ * <p>Log output format:
+ * <pre>
+ * INFO  - GET /api/movies 200 - 45ms
+ * WARN  - GET /api/movies/invalid 400 - 2ms
+ * ERROR - POST /api/movies 500 - 120ms
+ * </pre>
+ *
+ * <p>The filter is ordered to run first in the filter chain to ensure
+ * accurate timing measurements.
+ */
+@Component
+@Order(Ordered.HIGHEST_PRECEDENCE)
+public class RequestLoggingFilter extends OncePerRequestFilter {
+
+    private static final Logger logger = LoggerFactory.getLogger(RequestLoggingFilter.class);
+
+    @Override
+    protected void doFilterInternal(
+            HttpServletRequest request,
+            HttpServletResponse response,
+            FilterChain filterChain) throws ServletException, IOException {
+
+        // Record the start time
+        long startTime = System.currentTimeMillis();
+
+        // Log incoming request at debug level
+        logger.debug("Incoming request: {} {} from {}",
+                request.getMethod(),
+                request.getRequestURI(),
+                request.getRemoteAddr());
+
+        try {
+            // Continue with the filter chain
+            filterChain.doFilter(request, response);
+        } finally {
+            // Calculate response time
+            long responseTime = System.currentTimeMillis() - startTime;
+
+            // Log the completed request with appropriate level based on status code
+            logRequest(request.getMethod(), request.getRequestURI(), response.getStatus(), responseTime);
+        }
+    }
+
+    /**
+     * Logs the HTTP request with appropriate log level based on status code.
+     *
+     * <p>Log levels:
+     * <ul>
+     *   <li>ERROR: 5xx server errors</li>
+     *   <li>WARN: 4xx client errors</li>
+     *   <li>INFO: 2xx and 3xx success/redirect</li>
+     * </ul>
+     *
+     * @param method HTTP method (GET, POST, etc.)
+     * @param uri Request URI
+     * @param statusCode HTTP response status code
+     * @param responseTime Response time in milliseconds
+     */
+    private void logRequest(String method, String uri, int statusCode, long responseTime) {
+        String message = String.format("%s %s %d - %dms", method, uri, statusCode, responseTime);
+
+        if (statusCode >= 500) {
+            logger.error(message);
+        } else if (statusCode >= 400) {
+            logger.warn(message);
+        } else {
+            logger.info(message);
+        }
+    }
+
+    /**
+     * Skip logging for static resources and health checks to reduce noise.
+     */
+    @Override
+    protected boolean shouldNotFilter(HttpServletRequest request) {
+        String path = request.getRequestURI();
+        return path.startsWith("/swagger-ui")
+                || path.startsWith("/api-docs")
+                || path.startsWith("/v3/api-docs")
+                || path.equals("/favicon.ico")
+                || path.startsWith("/actuator");
+    }
+}
+

mflix/server/java-spring/src/main/resources/application.properties

@@ -19,11 +19,22 @@ voyage.api.key=${VOYAGE_API_KEY:}
 spring.application.name=sample-app-java-mflix
 
 # Logging Configuration
-logging.level.com.mongodb.samplemflix=INFO
+# Log level can be overridden with LOG_LEVEL environment variable
+# Available levels: TRACE, DEBUG, INFO, WARN, ERROR
+logging.level.com.mongodb.samplemflix=${LOG_LEVEL:INFO}
 logging.level.org.mongodb.driver=WARN
 # Suppress connection pool maintenance warnings (these are usually harmless)
 logging.level.org.mongodb.driver.connection=ERROR
 
+# Console logging pattern with colors and timestamps
+logging.pattern.console=%clr(%d{HH:mm:ss}){faint} %clr(%5p){highlight} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n
+
+# File logging (optional - enabled when LOG_FILE is set)
+logging.file.name=${LOG_FILE:}
+logging.pattern.file=%d{yyyy-MM-dd HH:mm:ss} %5p --- [%15.15t] %-40.40logger{39} : %m%n
+logging.logback.rollingpolicy.max-file-size=5MB
+logging.logback.rollingpolicy.max-history=5
+
 # Jackson Configuration (JSON serialization)
 spring.jackson.default-property-inclusion=non_null
 spring.jackson.serialization.write-dates-as-timestamps=false

mflix/server/js-express/.env.example

@@ -10,6 +10,10 @@ VOYAGE_API_KEY=your_voyage_api_key
 PORT=3001
 NODE_ENV=development
 
+# Logging Configuration
+# Available levels: error, warn, info, http, debug
+# Default: debug (development), info (production), error (test)
+LOG_LEVEL=debug
 
 # CORS Configuration
 # Allowed origin for cross-origin requests (frontend URL)

mflix/server/js-express/package.json

@@ -24,7 +24,8 @@
     "express": "^5.1.0",
     "mongodb": "^7.0.0",
     "swagger-jsdoc": "^6.2.8",
-    "swagger-ui-express": "^5.0.1"
+    "swagger-ui-express": "^5.0.1",
+    "winston": "^3.19.0"
   },
   "devDependencies": {
     "@types/cors": "^2.8.17",

mflix/server/js-express/src/app.ts

@@ -18,6 +18,8 @@ import {
 import { errorHandler } from "./utils/errorHandler";
 import moviesRouter from "./routes/movies";
 import { swaggerSpec } from "./config/swagger";
+import logger from "./utils/logger";
+import { requestLogger } from "./middleware/requestLogger";
 
 // Load environment variables from .env file
 // This must be called before any other imports that use environment variables
@@ -46,6 +48,12 @@ app.use(
 app.use(express.json({ limit: "10mb" }));
 app.use(express.urlencoded({ extended: true, limit: "10mb" }));
 
+/**
+ * Request Logging Middleware
+ * Logs all incoming HTTP requests with method, URL, status code, and response time
+ */
+app.use(requestLogger);
+
 /**
  * Swagger API Documentation
  * Provides interactive API documentation at /api-docs
@@ -119,25 +127,25 @@ app.use(errorHandler);
  */
 async function startServer() {
   try {
-    console.log("Starting MongoDB Sample MFlix API...");
+    logger.info("Starting MongoDB Sample MFlix API...");
 
     // Connect to MongoDB database
-    console.log("Connecting to MongoDB...");
+    logger.info("Connecting to MongoDB...");
     await connectToDatabase();
-    console.log("Connected to MongoDB successfully");
+    logger.info("Connected to MongoDB successfully");
 
     // Verify that all required indexes and sample data exist
-    console.log("Verifying requirements (indexes and sample data)...");
+    logger.info("Verifying requirements (indexes and sample data)...");
     await verifyRequirements();
-    console.log("All requirements verified successfully");
+    logger.info("All requirements verified successfully");
 
     // Start the Express server
     app.listen(PORT, () => {
-      console.log(`Server running on port ${PORT}`);
-      console.log(`API documentation available at http://localhost:${PORT}/api-docs`);
+      logger.info(`Server running on port ${PORT}`);
+      logger.info(`API documentation available at http://localhost:${PORT}/api-docs`);
     });
   } catch (error) {
-    console.error("Failed to start server:", error);
+    logger.error("Failed to start server:", error);
 
     // Exit the process if we can't start properly
     // This ensures the application doesn't run in a broken state
@@ -150,13 +158,13 @@ async function startServer() {
  * Ensures the application shuts down cleanly when terminated
  */
 process.on("SIGINT", () => {
-  console.log("\nReceived SIGINT. Shutting down...");
+  logger.info("Received SIGINT. Shutting down gracefully...");
   closeDatabaseConnection();
   process.exit(0);
 });
 
 process.on("SIGTERM", () => {
-  console.log("\nReceived SIGTERM. Shutting down...");
+  logger.info("Received SIGTERM. Shutting down gracefully...");
   closeDatabaseConnection();
   process.exit(0);
 });

mflix/server/js-express/src/config/database.ts

@@ -7,6 +7,7 @@
  */
 
 import { MongoClient, Db, Collection, Document } from "mongodb";
+import logger from "../utils/logger";
 
 let client: MongoClient;
 let database: Db;
@@ -40,7 +41,7 @@ async function _connectToDatabase(): Promise<Db> {
     // Get reference to the sample_mflix database
     database = client.db("sample_mflix");
 
-    console.log(`Connected to database: ${database.databaseName}`);
+    logger.debug(`Connected to database: ${database.databaseName}`);
 
     return database;
   } catch (error) {
@@ -85,7 +86,7 @@ export function getCollection<T extends Document>(
 export async function closeDatabaseConnection(): Promise<void> {
   if (client) {
     await client.close();
-    console.log("Database connection closed");
+    logger.info("Database connection closed");
   }
 }
 
@@ -100,9 +101,9 @@ export async function verifyRequirements(): Promise<void> {
 
     // Check if the movies collection exists and has data
     await verifyMoviesCollection(db);
-    console.log("All database requirements verified successfully");
+    logger.debug("All database requirements verified successfully");
   } catch (error) {
-    console.error("Requirements verification failed:", error);
+    logger.error("Requirements verification failed:", error);
     throw error;
   }
 }
@@ -117,7 +118,7 @@ async function verifyMoviesCollection(db: Db): Promise<void> {
   const movieCount = await moviesCollection.estimatedDocumentCount();
 
   if (movieCount === 0) {
-    console.warn(
+    logger.warn(
       "Movies collection is empty. Please ensure sample_mflix data is loaded."
     );
   }
@@ -131,8 +132,8 @@ async function verifyMoviesCollection(db: Db): Promise<void> {
         background: true,
       }
     );
-    console.log("Text search index created for movies collection");
+    logger.debug("Text search index created for movies collection");
   } catch (error) {
-    console.error("Could not create text search index:", error);
+    logger.error("Could not create text search index:", error);
   }
 }

mflix/server/js-express/src/controllers/movieController.ts

@@ -24,6 +24,7 @@ import {
   createSuccessResponse,
   validateRequiredFields,
 } from "../utils/errorHandler";
+import logger from "../utils/logger";
 import {
   CreateMovieRequest,
   UpdateMovieRequest,
@@ -874,7 +875,7 @@ export async function vectorSearchMovies(req: Request, res: Response): Promise<v
       )
     );
   } catch (error) {
-    console.error("Vector search error:", error);
+    logger.error("Vector search error:", error);
 
     // Handle Voyage AI authentication errors
     if (error instanceof VoyageAuthError) {

mflix/server/js-express/src/middleware/requestLogger.ts

@@ -0,0 +1,50 @@
+/**
+ * Request Logging Middleware
+ *
+ * This middleware logs incoming HTTP requests with useful information
+ * including method, URL, status code, and response time.
+ * It helps with debugging and monitoring application traffic.
+ */
+
+import { Request, Response, NextFunction } from "express";
+import logger, { logHttpRequest } from "../utils/logger";
+
+/**
+ * Express middleware that logs HTTP requests
+ *
+ * Logs the following information for each request:
+ * - HTTP method (GET, POST, PUT, DELETE, etc.)
+ * - Request URL
+ * - Response status code
+ * - Response time in milliseconds
+ *
+ * @param req - Express request object
+ * @param res - Express response object
+ * @param next - Express next function
+ */
+export function requestLogger(
+  req: Request,
+  res: Response,
+  next: NextFunction
+): void {
+  // Record the start time
+  const startTime = Date.now();
+
+  // Log request details at debug level when request starts
+  logger.debug(`Incoming request: ${req.method} ${req.url}`, {
+    headers: {
+      "user-agent": req.get("user-agent"),
+      "content-type": req.get("content-type"),
+    },
+    query: Object.keys(req.query).length > 0 ? req.query : undefined,
+    ip: req.ip,
+  });
+
+  // Log when response finishes
+  res.on("finish", () => {
+    const responseTime = Date.now() - startTime;
+    logHttpRequest(req.method, req.url, res.statusCode, responseTime);
+  });
+
+  next();
+}

mflix/server/js-express/src/utils/errorHandler.ts

@@ -8,6 +8,7 @@
 import { Request, Response, NextFunction } from "express";
 import { MongoError } from "mongodb";
 import { SuccessResponse, ErrorResponse } from "../types";
+import logger from "./logger";
 
 /**
  * Custom ValidationError class for field validation errors
@@ -37,17 +38,13 @@ export function errorHandler(
   next: NextFunction
 ): void {
   // Log the error for debugging purposes
-  // In production, we recommend using a logging service
-  // Suppress error logging during tests to keep test output clean
-  if (process.env.NODE_ENV !== "test") {
-    console.error("Error occurred:", {
-      message: err.message,
-      stack: err.stack,
-      url: req.url,
-      method: req.method,
-      timestamp: new Date().toISOString(),
-    });
-  }
+  // The logger automatically handles environment-specific behavior
+  logger.error("Error occurred:", {
+    message: err.message,
+    stack: err.stack,
+    url: req.url,
+    method: req.method,
+  });
 
   // Determine the appropriate HTTP status code and error message
   const errorDetails = parseErrorDetails(err);