/** * Mandu Runtime Logger ๐Ÿ“ * Trace ๊ธฐ๋ฐ˜ ์š”์ฒญ/์‘๋‹ต ๋กœ๊น… ๋ ˆ์ด์–ด * * ์—ญํ•  ๋ถ„๋ฆฌ: * - Trace = ์ˆ˜์ง‘ (์›๋ณธ ์ด๋ฒคํŠธ, duration ์ธก์ •) * - Logger = ์ถœ๋ ฅ (ํฌ๋งท/ํ•„ํ„ฐ/๋ ˆ๋“œ์•ก์…˜/์ƒ˜ํ”Œ๋ง) * * ๊ธฐ๋ณธ๊ฐ’์€ ์•ˆ์ „: * - includeHeaders: false * - includeBody: false * - redact: ๋ฏผ๊ฐ ์ •๋ณด ์ž๋™ ๋งˆ์Šคํ‚น * * @example * ```typescript * import { logger } from "@mandujs/core"; * * // ๊ธฐ๋ณธ ์‚ฌ์šฉ * app.use(logger()); * // โ†’ GET /api/users * // โ† GET /api/users 200 23ms * * // ๊ฐœ๋ฐœ ๋ชจ๋“œ * app.use(logger({ * level: "debug", * includeHeaders: true, * })); * * // ํ”„๋กœ๋•์…˜ (JSON ํ˜•์‹) * app.use(logger({ * format: "json", * slowThresholdMs: 500, * })); * ``` */ import type { ManduContext } from "../filling/context"; import { enableTrace, getTrace, buildTraceReport, type TraceReport, } from "./trace"; import { newShortId } from "../id"; // ============================================ // Types // ============================================ export type LogLevel = "debug" | "info" | "warn" | "error"; export type LogFormat = "pretty" | "json"; /** * Logger ์˜ต์…˜ */ export interface LoggerOptions { /** * ๋กœ๊ทธ ํฌ๋งท * - pretty: ๊ฐœ๋ฐœ์šฉ ์ปฌ๋Ÿฌ ์ถœ๋ ฅ * - json: ์šด์˜์šฉ ๊ตฌ์กฐํ™” ๋กœ๊ทธ * @default "pretty" */ format?: LogFormat; /** * ๋กœ๊ทธ ๋ ˆ๋ฒจ * - debug: ๋ชจ๋“  ์š”์ฒญ ์ƒ์„ธ ์ถœ๋ ฅ * - info: ๊ธฐ๋ณธ ์š”์ฒญ/์‘๋‹ต (๊ธฐ๋ณธ๊ฐ’) * - warn: ๋А๋ฆฐ ์š”์ฒญ + ์—๋Ÿฌ * - error: ์—๋Ÿฌ๋งŒ * @default "info" */ level?: LogLevel; /** * ํ—ค๋” ํฌํ•จ ์—ฌ๋ถ€ * โš ๏ธ ๊ธฐ๋ณธ OFF - ๋ฏผ๊ฐ ์ •๋ณด ๋…ธ์ถœ ์œ„ํ—˜ * @default false */ includeHeaders?: boolean; /** * ๋ฐ”๋”” ํฌํ•จ ์—ฌ๋ถ€ * โš ๏ธ ๊ธฐ๋ณธ OFF - ๋ฏผ๊ฐ ์ •๋ณด ๋…ธ์ถœ + ์ŠคํŠธ๋ฆผ ๋ฌธ์ œ * @default false */ includeBody?: boolean; /** * ๋ฐ”๋”” ์ตœ๋Œ€ ๋ฐ”์ดํŠธ (includeBody=true ์‹œ) * @default 1024 */ maxBodyBytes?: number; /** * ๋ ˆ๋“œ์•ก์…˜ ๋Œ€์ƒ ํ—ค๋”/ํ•„๋“œ๋ช… (๊ธฐ๋ณธ๊ฐ’ ๋‚ด์žฅ) * ์ถ”๊ฐ€ํ•  ํ•„๋“œ๋งŒ ์ง€์ •ํ•˜๋ฉด ๊ธฐ๋ณธ๊ฐ’๊ณผ ๋ณ‘ํ•ฉ๋จ */ redact?: string[]; /** * Request ID ์ƒ์„ฑ ๋ฐฉ์‹ * - "auto": crypto.randomUUID() ๋˜๋Š” ํƒ€์ž„์Šคํƒฌํ”„ ๊ธฐ๋ฐ˜ * - ํ•จ์ˆ˜: ์ปค์Šคํ…€ ์ƒ์„ฑ * @default "auto" */ requestId?: "auto" | ((ctx: ManduContext) => string); /** * ์ƒ˜ํ”Œ๋ง ๋น„์œจ (0-1) * ์šด์˜ ํ™˜๊ฒฝ์—์„œ ๋กœ๊ทธ ์–‘ ์กฐ์ ˆ * @default 1 (100%) */ sampleRate?: number; /** * ๋А๋ฆฐ ์š”์ฒญ ์ž„๊ณ„๊ฐ’ (ms) * ์ด ๊ฐ’ ์ดˆ๊ณผ ์‹œ warn ๋ ˆ๋ฒจ๋กœ ์ƒ์„ธ ์ถœ๋ ฅ * @default 1000 */ slowThresholdMs?: number; /** * Trace ๋ฆฌํฌํŠธ ํฌํ•จ ์—ฌ๋ถ€ (๋А๋ฆฐ ์š”์ฒญ ์‹œ) * @default true */ includeTraceOnSlow?: boolean; /** * ์ปค์Šคํ…€ ๋กœ๊ทธ ์‹ฑํฌ (์™ธ๋ถ€ ์‹œ์Šคํ…œ ์—ฐ๋™์šฉ) * ์ง€์ • ์‹œ console ์ถœ๋ ฅ ๋Œ€์‹  ์ด ํ•จ์ˆ˜ ํ˜ธ์ถœ */ sink?: (entry: LogEntry) => void; /** * ๋กœ๊น… ์ œ์™ธ ๊ฒฝ๋กœ ํŒจํ„ด * @example ["/health", "/metrics", /^\/static\//] */ skip?: (string | RegExp)[]; } /** * ๋กœ๊ทธ ์—”ํŠธ๋ฆฌ (JSON ์ถœ๋ ฅ ๋ฐ sink์šฉ) */ export interface LogEntry { timestamp: string; requestId: string; method: string; path: string; status?: number; duration?: number; level: LogLevel; error?: { message: string; stack?: string; }; headers?: Record; body?: unknown; trace?: TraceReport; slow?: boolean; } // ============================================ // Constants // ============================================ /** ๊ธฐ๋ณธ ๋ ˆ๋“œ์•ก์…˜ ๋Œ€์ƒ (๋Œ€์†Œ๋ฌธ์ž ๋ฌด์‹œ) */ const DEFAULT_REDACT_PATTERNS = [ "authorization", "cookie", "set-cookie", "x-api-key", "api-key", "apikey", "api_key", "password", "passwd", "secret", "token", "bearer", "credential", "credentials", "private", "session", "jwt", ]; /** Context ์ €์žฅ ํ‚ค */ const LOGGER_START_KEY = "__mandu_logger_start"; const LOGGER_REQUEST_ID_KEY = "__mandu_logger_request_id"; const LOGGER_ERROR_KEY = "__mandu_logger_error"; const LOGGER_RESPONSE_KEY = "__mandu_logger_response"; /** ๋กœ๊ทธ ๋ ˆ๋ฒจ ์šฐ์„ ์ˆœ์œ„ */ const LEVEL_PRIORITY: Record = { debug: 0, info: 1, warn: 2, error: 3, }; /** ANSI ์ปฌ๋Ÿฌ ์ฝ”๋“œ */ const COLORS = { reset: "\x1b[0m", dim: "\x1b[2m", cyan: "\x1b[36m", green: "\x1b[32m", yellow: "\x1b[33m", red: "\x1b[31m", magenta: "\x1b[35m", }; // ============================================ // Utilities // ============================================ /** * Request ID ์ƒ์„ฑ โ€” ์งง์€ 8์ž hex prefix. v7 ๊ธฐ๋ฐ˜์ด๋ฉด ์‹œ๊ฐ„ ์ •๋ ฌ๋จ. */ function generateRequestId(): string { if (typeof crypto !== "undefined" && typeof crypto.randomUUID === "function") { return newShortId(); } return Date.now().toString(36) + Math.random().toString(36).slice(2, 6); } /** * ํ˜„์žฌ ์‹œ๊ฐ„ (๊ณ ํ•ด์ƒ๋„) */ function now(): number { if (typeof performance !== "undefined" && performance.now) { return performance.now(); } return Date.now(); } /** * URL์—์„œ pathname ์ถ”์ถœ */ function getPathname(url: string): string { try { return new URL(url).pathname; } catch { return url; } } /** * ํ—ค๋” ๋ ˆ๋“œ์•ก์…˜ ์ฒ˜๋ฆฌ */ function redactHeaders( headers: Headers, patterns: string[] ): Record { const result: Record = {}; const lowerPatterns = patterns.map((p) => p.toLowerCase()); headers.forEach((value, key) => { const lowerKey = key.toLowerCase(); const shouldRedact = lowerPatterns.some( (pattern) => lowerKey.includes(pattern) || pattern.includes(lowerKey) ); result[key] = shouldRedact ? "[REDACTED]" : value; }); return result; } /** * ๊ฐ์ฒด ๋‚ด ๋ฏผ๊ฐ ํ•„๋“œ ๋ ˆ๋“œ์•ก์…˜ */ function redactObject( obj: unknown, patterns: string[], maxBytes: number ): unknown { if (obj === null || obj === undefined) return obj; // ๋ฌธ์ž์—ด์ด๋ฉด ๊ธธ์ด ์ œํ•œ๋งŒ if (typeof obj === "string") { if (obj.length > maxBytes) { return obj.slice(0, maxBytes) + `... [truncated ${obj.length - maxBytes} bytes]`; } return obj; } // ๋ฐฐ์—ด if (Array.isArray(obj)) { const str = JSON.stringify(obj); if (str.length > maxBytes) { return `[Array length=${obj.length}, truncated]`; } return obj.map((item) => redactObject(item, patterns, maxBytes)); } // ๊ฐ์ฒด if (typeof obj === "object") { const lowerPatterns = patterns.map((p) => p.toLowerCase()); const result: Record = {}; for (const [key, value] of Object.entries(obj)) { const lowerKey = key.toLowerCase(); const shouldRedact = lowerPatterns.some( (pattern) => lowerKey.includes(pattern) || pattern.includes(lowerKey) ); if (shouldRedact) { result[key] = "[REDACTED]"; } else if (typeof value === "object" && value !== null) { result[key] = redactObject(value, patterns, maxBytes); } else { result[key] = value; } } return result; } return obj; } /** * ๊ฒฝ๋กœ๊ฐ€ skip ํŒจํ„ด์— ๋งค์นญ๋˜๋Š”์ง€ ํ™•์ธ */ function shouldSkip(path: string, patterns: (string | RegExp)[]): boolean { return patterns.some((pattern) => { if (typeof pattern === "string") { return path === pattern || path.startsWith(pattern + "/"); } return pattern.test(path); }); } /** * ๋กœ๊ทธ ๋ ˆ๋ฒจ ํ•„ํ„ฐ๋ง */ function shouldLog(entryLevel: LogLevel, configLevel: LogLevel): boolean { return LEVEL_PRIORITY[entryLevel] >= LEVEL_PRIORITY[configLevel]; } /** * HTTP ์ƒํƒœ ์ฝ”๋“œ์— ๋”ฐ๋ฅธ ์ƒ‰์ƒ */ function getStatusColor(status: number): string { if (status >= 500) return COLORS.red; if (status >= 400) return COLORS.yellow; if (status >= 300) return COLORS.cyan; return COLORS.green; } // ============================================ // Pretty Formatter // ============================================ function formatPretty(entry: LogEntry): string { const { method, path, status, duration, requestId, error, slow, headers, trace } = entry; const lines: string[] = []; // ์š”์ฒญ ๋ผ์ธ if (status === undefined) { // ์š”์ฒญ ์‹œ์ž‘ lines.push( `${COLORS.dim}[${requestId}]${COLORS.reset} ${COLORS.cyan}โ†’${COLORS.reset} ${method} ${path}` ); } else { // ์‘๋‹ต const statusColor = getStatusColor(status); const durationStr = duration !== undefined ? ` ${duration.toFixed(0)}ms` : ""; const slowIndicator = slow ? ` ${COLORS.yellow}[SLOW]${COLORS.reset}` : ""; lines.push( `${COLORS.dim}[${requestId}]${COLORS.reset} ${COLORS.magenta}โ†${COLORS.reset} ${method} ${path} ${statusColor}${status}${COLORS.reset}${durationStr}${slowIndicator}` ); } // ์—๋Ÿฌ if (error) { lines.push(` ${COLORS.red}Error: ${error.message}${COLORS.reset}`); if (error.stack) { const stackLines = error.stack.split("\n").slice(1, 4); stackLines.forEach((line) => { lines.push(` ${COLORS.dim}${line.trim()}${COLORS.reset}`); }); } } // ํ—ค๋” (debug ๋ชจ๋“œ) if (headers && Object.keys(headers).length > 0) { lines.push(` ${COLORS.dim}Headers:${COLORS.reset}`); for (const [key, value] of Object.entries(headers)) { lines.push(` ${COLORS.dim}${key}:${COLORS.reset} ${value}`); } } // Trace ๋ฆฌํฌํŠธ (๋А๋ฆฐ ์š”์ฒญ) if (trace && trace.entries.length > 0) { lines.push(` ${COLORS.dim}Trace:${COLORS.reset}`); for (const traceEntry of trace.entries) { const name = traceEntry.name ? ` (${traceEntry.name})` : ""; lines.push( ` ${COLORS.dim}${traceEntry.event}${name}: ${traceEntry.duration.toFixed(1)}ms${COLORS.reset}` ); } } return lines.join("\n"); } // ============================================ // JSON Formatter // ============================================ function formatJson(entry: LogEntry): string { return JSON.stringify(entry); } // ============================================ // Logger Middleware Factory // ============================================ /** * Logger ๋ฏธ๋“ค์›จ์–ด ์ƒ์„ฑ * * @example * ```typescript * // ๊ธฐ๋ณธ ์‚ฌ์šฉ * app.use(logger()); * * // ๊ฐœ๋ฐœ ๋ชจ๋“œ * app.use(logger({ * level: "debug", * includeHeaders: true, * })); * * // ํ”„๋กœ๋•์…˜ * app.use(logger({ * format: "json", * sampleRate: 0.1, // 10% ์ƒ˜ํ”Œ๋ง * slowThresholdMs: 500, * })); * ``` */ export function logger(options: LoggerOptions = {}) { const config = { format: options.format ?? "pretty", level: options.level ?? "info", includeHeaders: options.includeHeaders ?? false, includeBody: options.includeBody ?? false, maxBodyBytes: options.maxBodyBytes ?? 1024, redact: [...DEFAULT_REDACT_PATTERNS, ...(options.redact ?? [])], requestId: options.requestId ?? "auto", sampleRate: options.sampleRate ?? 1, slowThresholdMs: options.slowThresholdMs ?? 1000, includeTraceOnSlow: options.includeTraceOnSlow ?? true, sink: options.sink, skip: options.skip ?? [], }; const formatter = config.format === "json" ? formatJson : formatPretty; /** * ๋กœ๊ทธ ์ถœ๋ ฅ ํ•จ์ˆ˜ */ function log(entry: LogEntry): void { if (!shouldLog(entry.level, config.level)) return; if (config.sink) { config.sink(entry); } else { const output = formatter(entry); switch (entry.level) { case "error": console.error(output); break; case "warn": console.warn(output); break; default: console.log(output); } } } return { /** * onRequest ํ›… - ์š”์ฒญ ์‹œ์ž‘ ๊ธฐ๋ก */ onRequest(ctx: ManduContext): void { const path = getPathname(ctx.url); // Skip ์ฒดํฌ if (shouldSkip(path, config.skip)) return; // ์ƒ˜ํ”Œ๋ง ์ฒดํฌ if (config.sampleRate < 1 && Math.random() > config.sampleRate) return; // Trace ํ™œ์„ฑํ™” enableTrace(ctx); // ์‹œ์ž‘ ์‹œ๊ฐ„ ์ €์žฅ ctx.set(LOGGER_START_KEY, now()); // Request ID ์ƒ์„ฑ/์ €์žฅ const requestId = config.requestId === "auto" ? generateRequestId() : config.requestId(ctx); ctx.set(LOGGER_REQUEST_ID_KEY, requestId); // debug ๋ ˆ๋ฒจ์ด๋ฉด ์š”์ฒญ ์‹œ์ž‘๋„ ๋กœ๊น… if (config.level === "debug") { const entry: LogEntry = { timestamp: new Date().toISOString(), requestId, method: ctx.method, path, level: "debug", }; if (config.includeHeaders) { entry.headers = redactHeaders(ctx.headers, config.redact); } log(entry); } }, /** * onError ํ›… - ์—๋Ÿฌ ์บก์ฒ˜ */ onError(ctx: ManduContext, error: Error): void { ctx.set(LOGGER_ERROR_KEY, error); }, /** * afterHandle ํ›… - ์‘๋‹ต ์บก์ฒ˜ (๋ฐ”๋”” ๋กœ๊น…์šฉ) */ afterHandle(ctx: ManduContext, response: Response): Response { ctx.set(LOGGER_RESPONSE_KEY, response); return response; }, /** * afterResponse ํ›… - ์ตœ์ข… ๋กœ๊ทธ ์ถœ๋ ฅ */ async afterResponse(ctx: ManduContext): Promise { const startTime = ctx.get(LOGGER_START_KEY); const requestId = ctx.get(LOGGER_REQUEST_ID_KEY); // ์‹œ์ž‘ ๊ธฐ๋ก์ด ์—†์œผ๋ฉด skip๋œ ์š”์ฒญ if (startTime === undefined || requestId === undefined) return; const path = getPathname(ctx.url); const duration = now() - startTime; const error = ctx.get(LOGGER_ERROR_KEY); const response = ctx.get(LOGGER_RESPONSE_KEY); const status = response?.status ?? (error ? 500 : 200); const isSlow = duration > config.slowThresholdMs; // ๋กœ๊ทธ ๋ ˆ๋ฒจ ๊ฒฐ์ • let level: LogLevel = "info"; if (error) { level = "error"; } else if (isSlow) { level = "warn"; } // ๋กœ๊ทธ ์—”ํŠธ๋ฆฌ ์ƒ์„ฑ const entry: LogEntry = { timestamp: new Date().toISOString(), requestId, method: ctx.method, path, status, duration, level, slow: isSlow, }; // ์—๋Ÿฌ ์ •๋ณด if (error) { entry.error = { message: error.message, stack: error.stack, }; } // ํ—ค๋” (debug ๋˜๋Š” ๋А๋ฆฐ ์š”์ฒญ) if (config.includeHeaders || (isSlow && config.level === "debug")) { entry.headers = redactHeaders(ctx.headers, config.redact); } // ๋ฐ”๋”” (๋ช…์‹œ์  ํ™œ์„ฑํ™” + debug ๋ ˆ๋ฒจ๋งŒ) if (config.includeBody && config.level === "debug" && response) { try { const cloned = response.clone(); const contentType = cloned.headers.get("content-type") || ""; if (contentType.includes("application/json")) { const body = await cloned.json(); entry.body = redactObject(body, config.redact, config.maxBodyBytes); } } catch { // ๋ฐ”๋”” ํŒŒ์‹ฑ ์‹คํŒจ ์‹œ ๋ฌด์‹œ } } // Trace ๋ฆฌํฌํŠธ (๋А๋ฆฐ ์š”์ฒญ) if (isSlow && config.includeTraceOnSlow) { const collector = getTrace(ctx); if (collector) { entry.trace = buildTraceReport(collector); } } log(entry); }, }; } /** * Logger ํ›…๋“ค์„ LifecycleStore์— ๋“ฑ๋กํ•˜๋Š” ํ—ฌํผ * * @example * ```typescript * import { createLifecycleStore } from "./lifecycle"; * import { logger, applyLogger } from "./logger"; * * const lifecycle = createLifecycleStore(); * applyLogger(lifecycle, logger({ level: "debug" })); * ``` */ export function applyLogger( lifecycle: { onRequest: Array<{ fn: (ctx: ManduContext) => void | Promise; scope: string }>; onError: Array<{ fn: (ctx: ManduContext, error: Error) => void | Promise; scope: string }>; afterHandle: Array<{ fn: (ctx: ManduContext, response: Response) => Response | Promise; scope: string }>; afterResponse: Array<{ fn: (ctx: ManduContext) => void | Promise; scope: string }>; }, loggerInstance: ReturnType ): void { lifecycle.onRequest.push({ fn: loggerInstance.onRequest, scope: "global" }); lifecycle.onError.push({ fn: loggerInstance.onError as (ctx: ManduContext, error: Error) => void, scope: "global" }); lifecycle.afterHandle.push({ fn: loggerInstance.afterHandle, scope: "global" }); lifecycle.afterResponse.push({ fn: loggerInstance.afterResponse, scope: "global" }); } // ============================================ // Convenience Presets // ============================================ /** * ๊ฐœ๋ฐœ์šฉ ๋กœ๊ฑฐ ํ”„๋ฆฌ์…‹ */ export function devLogger(options: Partial = {}) { return logger({ format: "pretty", level: "debug", includeHeaders: true, slowThresholdMs: 500, ...options, }); } /** * ํ”„๋กœ๋•์…˜์šฉ ๋กœ๊ฑฐ ํ”„๋ฆฌ์…‹ */ export function prodLogger(options: Partial = {}) { return logger({ format: "json", level: "info", includeHeaders: false, includeBody: false, sampleRate: 1, slowThresholdMs: 1000, ...options, }); }