codeflash-internal/js/cf-api/middlewares/enhanced-logging.ts
Kevin Turcios d7a8b8f227
perf: fix CI build + lazy-load heavy libs + parallelize DB queries (#2601)
## Summary
- **Fix CI build failure**: Auth0Client crashes during Next.js
prerendering when env vars aren't set. Returns a no-op stub (`getSession
→ null`) when domain is missing — semantically correct for static
generation
- **Lazy-load markdown libs (~260kb)**: ReactMarkdown, remarkGfm, and
react-syntax-highlighter were eagerly imported in monaco-diff-viewer but
only rendered when user expands "Generated Tests". Extracted into a
dynamic component
- **Parallelize repo detail query**: `getRepositoryById` ran the
activity count sequentially after the repo lookup. Since `repoId` is
already available, all three queries now run in parallel

## Test plan
- [ ] CI `build` check passes (was failing since #2598)
- [ ] Trace page still renders generated tests correctly when expanded
- [ ] Repository detail page loads correctly with activity status
2026-04-13 11:03:05 -05:00

317 lines
10 KiB
TypeScript

import { Request, Response, NextFunction } from "express"
import { logger, LogContext } from "../utils/logger.js"
import { addTracingHeaders, extractOrGenerateRequestId } from "../utils/request-tracing.js"
import * as Sentry from "@sentry/node"
import { SENSITIVE_KEYS } from "../constants/index.js"
function safeRedact(payload: any): any {
if (payload == null || typeof payload !== "object") {
return payload
}
if (Array.isArray(payload)) {
return payload.map(item => safeRedact(item))
}
const redacted = { ...payload }
for (const [key, value] of Object.entries(redacted)) {
if (SENSITIVE_KEYS.some(sensitiveKey => key.toLowerCase().includes(sensitiveKey))) {
redacted[key] = "[REDACTED]"
continue
}
if (typeof value === "object" && value !== null) {
redacted[key] = safeRedact(value)
}
}
return redacted
}
// Extend Express Request interface to include our custom properties
declare global {
namespace Express {
interface Request {
requestId?: string
traceId?: string
correlationId?: string
startTime?: number
requestLogger?: typeof logger
endpoint?: string
}
}
}
/**
* Enhanced request logging middleware that provides structured logging
* with request tracing, performance metrics, and error correlation
*
* SIMPLIFIED APPROACH: Uses a single request ID for all tracing needs
* This ID serves as both correlation ID and trace ID for simplicity
*
* WHY SIMPLIFIED APPROACH:
* - Reduces complexity for developers
* - Easier to understand and maintain
* - Still supports distributed tracing via header inheritance
* - Sufficient for most microservices architectures
*
* TO REVERT TO INDUSTRY STANDARD (separate IDs):
* 1. Update request-tracing.ts to restore separate correlation/trace ID functions
* 2. Change this middleware to use:
* - const correlationId = extractOrGenerateCorrelationId(req)
* - const traceId = extractOrGenerateTraceId(req)
* - const requestId = generateRequestId()
* 3. Update child logger and Sentry context to use separate IDs
* 4. Update addTracingHeaders call to pass separate IDs
*
* Production: Only logs errors, warnings, and important events
* Development: Logs all request details for debugging
*/
export function enhancedRequestLogger(req: Request, res: Response, next: NextFunction): void {
// SIMPLIFIED APPROACH: Use a single request ID for all tracing needs
// This ID serves as both correlation ID and trace ID
const requestId = extractOrGenerateRequestId(req)
const startTime = Date.now()
// Attach to request object for use in other middleware/endpoints
req.requestId = requestId
req.traceId = requestId // Same as requestId for simplicity
req.correlationId = requestId // Same as requestId for simplicity
req.startTime = startTime
// Create child logger with request context
// NOTE: All IDs are the same value in simplified approach
// Extract pathname from URL (remove query string) to ensure endpoint is always set
// Always parse from req.originalUrl or req.url to get the actual path
let endpoint = ""
if (req.originalUrl) {
endpoint = req.originalUrl.split("?")[0]
} else if (req.url) {
endpoint = req.url.split("?")[0]
} else if (req.path) {
endpoint = req.path
}
// Ensure we always have a value (default to "/" if nothing found)
if (!endpoint || endpoint.trim() === "") {
endpoint = "/"
}
// Store endpoint on request for reuse in other middleware
req.endpoint = endpoint
req.requestLogger = logger.child({
requestId,
traceId: requestId, // Same as requestId
correlationId: requestId, // Same as requestId
endpoint,
})
// Suppress request lifecycle logs for healthcheck/root paths to reduce noise
const isSuppressedPath = endpoint === "/healthcheck" || endpoint === "/"
// Add Sentry context and breadcrumb
Sentry.setTag("correlationId", requestId)
Sentry.setTag("requestId", requestId)
Sentry.addBreadcrumb({
category: "request",
message: `${req.method} ${req.path}`,
level: "info",
data: {
correlationId: requestId,
requestId,
method: req.method,
path: req.path,
ip: req.ip,
userAgent: req.headers["user-agent"],
},
})
// Create base context for all logs related to this request
// Use the endpoint already declared above
const baseContext: LogContext = {
requestId,
traceId: requestId,
correlationId: requestId,
endpoint,
operation: "request_start",
}
// Add tracing headers to response
// SIMPLIFIED APPROACH: All headers use the same requestId value
// Industry standard would use: addTracingHeaders(res, requestId, traceId, correlationId)
addTracingHeaders(res, requestId, requestId, requestId)
if (!isSuppressedPath) {
// Log request start - logger handles environment filtering automatically
// Production: INFO level (minimal info), Development: INFO level (clean details)
logger.info("Request started", baseContext, {
method: req.method,
url: req.url,
...(req.get("User-Agent") && { userAgent: req.get("User-Agent") }),
...(req.ip && { ip: req.ip }),
...(req.get("Content-Length") && { contentLength: req.get("Content-Length") }),
...(req.get("Content-Type") && { contentType: req.get("Content-Type") }),
})
// Log request completion when response finishes
res.on("finish", () => {
const duration = Date.now() - startTime
const responseContext: LogContext = {
...baseContext,
operation: "request_complete",
}
// Determine log level based on status code and environment
if (res.statusCode >= 500) {
// Always log server errors
logger.error("Request completed with server error", responseContext, {
statusCode: res.statusCode,
duration,
...(res.get("Content-Length") && { contentLength: res.get("Content-Length") }),
error: res.statusMessage,
method: req.method,
url: req.url,
})
} else if (res.statusCode >= 400) {
// Always log client errors
logger.warn("Request completed with client error", responseContext, {
statusCode: res.statusCode,
duration,
...(res.get("Content-Length") && { contentLength: res.get("Content-Length") }),
error: res.statusMessage,
method: req.method,
url: req.url,
})
} else {
// Log successful requests - logger handles environment filtering automatically
// Production: INFO level (minimal info), Development: INFO level (clean details)
logger.info("Request completed successfully", responseContext, {
statusCode: res.statusCode,
duration,
...(res.get("Content-Length") && { contentLength: res.get("Content-Length") }),
})
}
})
}
// Always log request errors (even for healthcheck paths)
res.on("error", (error: Error) => {
const errorContext: LogContext = {
...baseContext,
operation: "request_error",
}
logger.error(
"Request error occurred",
errorContext,
{
error: error.message,
stack: error.stack,
method: req.method,
url: req.url,
},
error,
)
})
next()
}
/**
* Middleware to enhance user context in logs and Sentry
* Automatically extracts user information from various sources
*/
export function addUserContext(req: Request, res: Response, next: NextFunction): void {
// Get user info from various sources
const userId = (req as any).user?.sub || (req as any).userId
const username = (req as any).user?.nickname || (req as any).username
const userEmail = (req as any).user?.email || (req as any).userEmail
if (userId || username || userEmail) {
// Enhance request logger with user context
req.requestLogger &&= req.requestLogger.child({
userId,
username,
userEmail,
})
// Add to Sentry
Sentry.setUser({
id: userId,
username,
email: userEmail,
})
// Add breadcrumb
Sentry.addBreadcrumb({
category: "user",
message: `User context identified`,
level: "info",
data: {
userId,
username,
userEmail,
},
})
}
next()
}
/**
* Middleware to log request body (only in development)
* Replaces the existing logRequestBody middleware with structured logging
*/
export function logRequestBody(req: Request, res: Response, next: NextFunction): void {
// Log request body - logger handles environment filtering automatically
// Production: Not logged (DEBUG level), Development: Full details (DEBUG level)
const context: LogContext = {
requestId: req.requestId,
traceId: req.traceId,
endpoint: req.endpoint || "unknown",
operation: "request_body",
}
logger.debug("Request body received", context, {
...(req.body && Object.keys(req.body).length > 0 && { body: safeRedact(req.body) }),
bodySize: JSON.stringify(req.body || {}).length,
})
next()
}
/**
* Middleware to log authentication events
* Provides structured logging for auth-related events
*
* Production: Only logs authentication failures and important events
* Development: Logs all authentication attempts
*/
export function logAuthEvent(req: Request, res: Response, next: NextFunction): void {
const context: LogContext = {
requestId: req.requestId,
traceId: req.traceId,
endpoint: req.endpoint || "unknown",
operation: "auth_event",
}
// Log authentication attempts
const authHeader = req.headers.authorization
if (authHeader) {
// Log authentication attempts - logger handles environment filtering automatically
// Production: Not logged (DEBUG level), Development: Full details (DEBUG level)
logger.debug("Authentication attempt", context, {
authType: authHeader.startsWith("Bearer") ? "Bearer" : "Other",
// Don't log the actual token for security
tokenLength: authHeader.length,
})
} else {
// Always log missing authentication as it's important (WARN level)
logger.warn("Request without authentication", context, {
hasAuthHeader: false,
url: req.url,
method: req.method,
})
}
next()
}