feat: add request IDs and structured JSON logs

src/__tests__/helmetCors.test.ts

@@ -39,6 +39,7 @@ describe('Helmet and CORS', () => {
 
     expect(res.headers['access-control-allow-origin']).toBe('http://localhost:5173');
     expect(res.headers['access-control-expose-headers']?.toLowerCase()).toContain('content-disposition');
+    expect(res.headers['access-control-expose-headers']?.toLowerCase()).toContain('x-request-id');
   });
 
   it('does not allow an unlisted origin', async () => {

src/__tests__/requestId.test.ts

@@ -0,0 +1,42 @@
+import { describe, expect, it, vi } from 'vitest';
+import request from 'supertest';
+import app from '../app.js';
+import { resolveRequestId } from '../middleware/requestId.js';
+import { serializeLog } from '../utils/logger.js';
+
+describe('request IDs', () => {
+  it('generates an X-Request-Id when the client does not send one', async () => {
+    const res = await request(app).get('/api/health');
+    expect(res.headers['x-request-id']).toMatch(
+      /^[0-9a-f]{8}-[0-9a-f]{4}-[1-8][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i
+    );
+  });
+
+  it('preserves an incoming X-Request-Id', async () => {
+    const res = await request(app).get('/api/health').set('X-Request-Id', 'client-trace-123');
+    expect(res.headers['x-request-id']).toBe('client-trace-123');
+  });
+
+  it('strips newlines from an incoming request id', () => {
+    expect(resolveRequestId('abc\n{"injected":true}')).toBe('abc{"injected":true}');
+  });
+});
+
+describe('structured logger', () => {
+  it('writes JSON and drops password fields', () => {
+    const spy = vi.spyOn(console, 'log').mockImplementation(() => {});
+    const line = serializeLog('info', {
+      event: 'upload_success',
+      fileId: 'file-1',
+      password: 'secret',
+    } as never);
+
+    const payload = JSON.parse(line) as Record<string, unknown>;
+    expect(payload.event).toBe('upload_success');
+    expect(payload.fileId).toBe('file-1');
+    expect(payload.password).toBeUndefined();
+    expect(payload.level).toBe('info');
+    expect(typeof payload.ts).toBe('string');
+    spy.mockRestore();
+  });
+});

src/app.ts

@@ -10,6 +10,7 @@ import { parseTrustProxy } from './config/trustProxy.js';
 import { createApiRateLimiter } from './middleware/rateLimits.js';
 import { isOriginAllowed, resolveCorsOrigin } from './config/cors.js';
 import { securityHeaders } from './config/helmet.js';
+import { requestIdMiddleware } from './middleware/requestId.js';
 
 dotenv.config();
 
@@ -18,14 +19,15 @@ const app: Application = express();
 app.set('trust proxy', parseTrustProxy(process.env.TRUST_PROXY));
 
 // Middlewares
+app.use(requestIdMiddleware);
 app.use(securityHeaders());
 app.use(express.json());
 const corsOrigin = resolveCorsOrigin(process.env.CORS_ORIGIN);
 app.use(cors({
   origin: (requestOrigin, callback) => {
     callback(null, isOriginAllowed(requestOrigin, corsOrigin));
   },
-  exposedHeaders: ['Content-Disposition'],
+  exposedHeaders: ['Content-Disposition', 'X-Request-Id'],
 }));
 
 // Routes

src/config/db.ts

@@ -1,18 +1,15 @@
 import dotenv from 'dotenv';
-import { initializeSqlite, getSqlitePath } from '../../backend/database/sqlite-setup.js';
+import { initializeSqlite } from '../../backend/database/sqlite-setup.js';
+import { log } from '../utils/logger.js';
 
 dotenv.config();
 
 const connectDB = async (): Promise<void> => {
   try {
     initializeSqlite();
-    console.log(`SQLite Connected: ${getSqlitePath()}`);
-  } catch (error) {
-    if (error instanceof Error) {
-      console.error(`SQLite connection error: ${error.message}`);
-    } else {
-      console.error('An unknown error occurred during SQLite connection');
-    }
+    log('info', { event: 'startup', message: 'sqlite_ready' });
+  } catch {
+    log('error', { event: 'startup', message: 'sqlite_failed' });
     process.exit(1);
   }
 };

src/controllers/fileController.ts

@@ -7,6 +7,7 @@ import { v4 as uuidv4 } from 'uuid';
 import { formatContentDisposition } from '../utils/disposition.js';
 import { validateFileMagicBytes } from '../utils/fileValidation.js';
 import { parseExpiryMinutes, parseMaxDownloads } from '../utils/uploadConstraints.js';
+import { log, requestContext } from '../utils/logger.js';
 
 const removeUploadedFile = (filePath?: string): void => {
   if (filePath && fs.existsSync(filePath)) {
@@ -32,27 +33,31 @@ const uuidV4Pattern = /^[0-9a-f]{8}-[0-9a-f]{4}-4[0-9a-f]{3}-[89ab][0-9a-f]{3}-[
 export const uploadFile = async (req: Request, res: Response): Promise<void> => {
   try {
     if (!req.file) {
+      log('warn', { event: 'upload_fail', ...requestContext(req), status: 400, message: 'No file uploaded' });
       res.status(400).json({ success: false, message: 'No file uploaded' });
       return;
     }
 
     const expiry = parseExpiryMinutes(req.body.expiryMinutes || req.body.expiry);
     if (!expiry.ok) {
       removeUploadedFile(req.file.path);
+      log('warn', { event: 'upload_fail', ...requestContext(req), status: 400, message: expiry.message });
       res.status(400).json({ success: false, message: expiry.message });
       return;
     }
 
     const downloads = parseMaxDownloads(req.body.maxDownloads);
     if (!downloads.ok) {
       removeUploadedFile(req.file.path);
+      log('warn', { event: 'upload_fail', ...requestContext(req), status: 400, message: downloads.message });
       res.status(400).json({ success: false, message: downloads.message });
       return;
     }
 
     const validation = validateFileMagicBytes(req.file.path, req.file.mimetype);
     if (!validation.valid) {
       removeUploadedFile(req.file.path);
+      log('warn', { event: 'upload_fail', ...requestContext(req), status: 400, message: validation.message || 'Invalid file content' });
       res.status(400).json({ success: false, message: validation.message || 'Invalid file content' });
       return;
     }
@@ -89,13 +94,15 @@ export const uploadFile = async (req: Request, res: Response): Promise<void> =>
       passwordHash
     );
 
+    log('info', { event: 'upload_success', ...requestContext(req), status: 201, fileId, size: req.file.size });
     res.status(201).json({
       success: true,
       fileId,
       downloadLink: `/api/download/${fileId}`,
     });
   } catch {
     removeUploadedFile(req.file?.path);
+    log('error', { event: 'upload_fail', ...requestContext(req), status: 500 });
     res.status(500).json({ success: false, message: 'An unknown error occurred' });
   }
 };
@@ -104,6 +111,7 @@ export const downloadFile = async (req: Request, res: Response): Promise<void> =
     const fileIdParam = req.params.id;
     const fileId = Array.isArray(fileIdParam) ? fileIdParam[0] : fileIdParam;
     if (!uuidV4Pattern.test(fileId)) {
+      log('warn', { event: 'download_fail', ...requestContext(req), status: 404 });
       res.status(404).json({ success: false, message: 'File not found' });
       return;
     }
@@ -113,6 +121,7 @@ export const downloadFile = async (req: Request, res: Response): Promise<void> =
     const file = getFile.get(fileId) as SqliteFileRow | undefined;
 
     if (!file) {
+      log('warn', { event: 'download_fail', ...requestContext(req), status: 410, fileId });
       res.status(410).json({ success: false, message: 'File has expired or is no longer available' });
       return;
     }
@@ -123,29 +132,33 @@ export const downloadFile = async (req: Request, res: Response): Promise<void> =
           fs.unlinkSync(file.file_path);
         }
         db.prepare('DELETE FROM files WHERE id = ?').run(fileId);
-      } catch (err) {
-        console.error('Error deleting file:', err);
+      } catch {
+        log('error', { event: 'download_fail', ...requestContext(req), fileId, message: 'delete_failed' });
       }
     };
 
     if (Date.now() > new Date(file.expires_at).getTime()) {
+      log('warn', { event: 'download_fail', ...requestContext(req), status: 410, fileId, message: 'expired' });
       res.status(410).json({ success: false, message: 'File has expired and is no longer available' });
       return;
     }
 
     if (file.download_count >= file.max_downloads) {
+      log('warn', { event: 'download_fail', ...requestContext(req), status: 410, fileId, message: 'limit_reached' });
       res.status(410).json({ success: false, message: 'Download limit reached' });
       return;
     }
 
     if (file.password_hash) {
       const providedPassword = typeof req.body?.password === 'string' ? req.body.password : '';
       if (!providedPassword) {
+        log('warn', { event: 'password_fail', ...requestContext(req), status: 403, fileId, message: 'required' });
         res.status(403).json({ success: false, message: 'Password required' });
         return;
       }
       const isMatch = await bcrypt.compare(providedPassword, file.password_hash);
       if (!isMatch) {
+        log('warn', { event: 'password_fail', ...requestContext(req), status: 403, fileId, message: 'incorrect' });
         res.status(403).json({ success: false, message: 'Incorrect password' });
         return;
       }
@@ -162,6 +175,7 @@ export const downloadFile = async (req: Request, res: Response): Promise<void> =
     `).run(fileId, new Date().toISOString());
 
     if (reservation.changes === 0) {
+      log('warn', { event: 'download_fail', ...requestContext(req), status: 410, fileId, message: 'reservation_lost' });
       res.status(410).json({ success: false, message: 'File has expired or is no longer available' });
       return;
     }
@@ -172,7 +186,7 @@ export const downloadFile = async (req: Request, res: Response): Promise<void> =
 
     res.sendFile(absolutePath, async (err) => {
       if (err) {
-        console.error('Error sending file:', err);
+        log('error', { event: 'download_fail', ...requestContext(req), status: 500, fileId });
         if (!res.headersSent) {
           res.status(500).json({ success: false, message: 'Error downloading file' });
         }
@@ -182,14 +196,14 @@ export const downloadFile = async (req: Request, res: Response): Promise<void> =
         return;
       }
 
+      log('info', { event: 'download_success', ...requestContext(req), status: 200, fileId });
       if (reservedCount >= file.max_downloads) {
         await deleteFile();
       }
     });
-  } catch (error) {
-    if (error instanceof Error) {
-      res.status(500).json({ success: false, message: error.message });
-    } else {
+  } catch {
+    log('error', { event: 'download_fail', ...requestContext(req), status: 500 });
+    if (!res.headersSent) {
       res.status(500).json({ success: false, message: 'An unknown error occurred' });
     }
   }
@@ -231,11 +245,8 @@ export const getFileInfo = async (req: Request, res: Response): Promise<void> =>
         createdAt: file.created_at,
       },
     });
-  } catch (error) {
-    if (error instanceof Error) {
-      res.status(500).json({ success: false, message: error.message });
-    } else {
-      res.status(500).json({ success: false, message: 'An unknown error occurred' });
-    }
+  } catch {
+    log('error', { event: 'server_error', ...requestContext(req), status: 500, path: req.path });
+    res.status(500).json({ success: false, message: 'An unknown error occurred' });
   }
 };

src/middleware/errorHandler.ts

@@ -1,6 +1,7 @@
 import { NextFunction, Request, Response } from 'express';
 import fs from 'fs';
 import multer from 'multer';
+import { log, requestContext } from '../utils/logger.js';
 
 const removeUploadedFile = (req: Request): void => {
   const uploaded = req.file;
@@ -21,14 +22,17 @@ export const errorHandler = (err: unknown, req: Request, res: Response, next: Ne
     const message = err.code === 'LIMIT_FILE_SIZE'
       ? 'File exceeds the 10MB limit'
       : err.message;
+    log('warn', { event: 'upload_fail', ...requestContext(req), status: 400, message });
     res.status(400).json({ success: false, message });
     return;
   }
 
   if (err instanceof Error && err.message === 'Invalid file type') {
+    log('warn', { event: 'upload_fail', ...requestContext(req), status: 400, message: 'Invalid file type' });
     res.status(400).json({ success: false, message: 'Invalid file type' });
     return;
   }
 
+  log('error', { event: 'server_error', ...requestContext(req), status: 500 });
   res.status(500).json({ success: false, message: 'An unknown error occurred' });
 };

src/middleware/rateLimits.ts

@@ -1,11 +1,13 @@
 import rateLimit, { type Options } from 'express-rate-limit';
+import { log, requestContext } from '../utils/logger.js';
 
 const parsePositiveInt = (raw: string | undefined, fallback: number): number => {
   const value = Number(raw);
   return Number.isInteger(value) && value > 0 ? value : fallback;
 };
 
 const jsonExceededHandler: Options['handler'] = (req, res, _next, options) => {
+  log('warn', { event: 'rate_limited', ...requestContext(req), status: options.statusCode });
   res.status(options.statusCode).json({ success: false, message: 'Too many requests' });
 };
 

src/middleware/requestId.ts

@@ -0,0 +1,17 @@
+import { randomUUID } from 'crypto';
+import type { NextFunction, Request, Response } from 'express';
+
+export const REQUEST_ID_HEADER = 'x-request-id';
+const MAX_REQUEST_ID_LENGTH = 128;
+
+export const resolveRequestId = (incoming: string | undefined): string => {
+  const sanitized = (incoming ?? '').trim().replace(/[\r\n\t]/g, '').slice(0, MAX_REQUEST_ID_LENGTH);
+  return sanitized.length > 0 ? sanitized : randomUUID();
+};
+
+export const requestIdMiddleware = (req: Request, res: Response, next: NextFunction): void => {
+  const requestId = resolveRequestId(req.header('X-Request-Id'));
+  req.requestId = requestId;
+  res.setHeader('X-Request-Id', requestId);
+  next();
+};

src/server.ts

@@ -3,6 +3,7 @@ import app from './app.js';
 import connectDB from './config/db.js';
 import { startCleanupJob, stopCleanupJob } from './services/cleanupService.js';
 import { closeSqlite } from '../backend/database/sqlite-setup.js';
+import { log } from './utils/logger.js';
 
 dotenv.config();
 
@@ -15,22 +16,19 @@ connectDB();
 startCleanupJob();
 
 const server = app.listen(PORT, () => {
-  console.log(`Server running in ${process.env.NODE_ENV || 'development'} mode on port ${PORT}`);
+  log('info', { event: 'startup', message: `listening on ${PORT}` });
 });
 
 export const gracefulShutdown = (signal: string, callback?: () => void) => {
-  console.log(`Received ${signal}. Initiating graceful shutdown...`);
+  log('info', { event: 'shutdown', signal });
 
   stopCleanupJob();
 
   server.close(() => {
-    console.log('HTTP server closed.');
-
     try {
       closeSqlite();
-      console.log('SQLite connection closed.');
-    } catch (err) {
-      console.error('Error closing SQLite database:', err);
+    } catch {
+      log('error', { event: 'shutdown', signal, message: 'sqlite_close_failed' });
     }
 
     if (callback) {
@@ -41,7 +39,7 @@ export const gracefulShutdown = (signal: string, callback?: () => void) => {
   });
 
   setTimeout(() => {
-    console.error('Forcefully shutting down server due to timeout.');
+    log('error', { event: 'shutdown', signal, message: 'timeout' });
     if (!callback) {
       process.exit(1);
     }