-
Notifications
You must be signed in to change notification settings - Fork 30
feat(api): replace default logger with pretty colored request logging #2166
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Merged
Merged
Changes from all commits
Commits
Show all changes
4 commits
Select commit
Hold shift + click to select a range
File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,153 @@ | ||
| import type { Context, Next } from "hono"; | ||
|
|
||
| // ANSI color codes for elegant logging | ||
| const colors = { | ||
| reset: "\x1b[0m", | ||
| dim: "\x1b[2m", | ||
| bold: "\x1b[1m", | ||
| // Request methods | ||
| GET: "\x1b[36m", // cyan | ||
| POST: "\x1b[33m", // yellow | ||
| PUT: "\x1b[35m", // magenta | ||
| DELETE: "\x1b[31m", // red | ||
| // Status codes | ||
| ok: "\x1b[32m", // green | ||
| redirect: "\x1b[36m", // cyan | ||
| clientError: "\x1b[33m", // yellow | ||
| serverError: "\x1b[31m", // red | ||
| // Special | ||
| mcp: "\x1b[35m", // magenta for MCP | ||
| tool: "\x1b[96m", // bright cyan for tool names | ||
| duration: "\x1b[90m", // gray | ||
| }; | ||
|
|
||
| const getStatusColor = (status: number) => { | ||
| if (status >= 500) return colors.serverError; | ||
| if (status >= 400) return colors.clientError; | ||
| if (status >= 300) return colors.redirect; | ||
| return colors.ok; | ||
| }; | ||
|
|
||
| const getMethodColor = (method: string) => { | ||
| return colors[method as keyof typeof colors] || colors.reset; | ||
| }; | ||
|
|
||
| /** | ||
| * Sanitize strings for safe logging by removing control characters | ||
| * Prevents log forging and terminal escape injection attacks | ||
| */ | ||
| const sanitizeForLog = (str: string): string => { | ||
| return ( | ||
| str | ||
| .replace(/\r/g, "") // Remove carriage returns | ||
| .replace(/\n/g, "") // Remove newlines | ||
| // eslint-disable-next-line no-control-regex | ||
| .replace(/\x1b\[[0-9;]*m/g, "") // Remove ANSI escape sequences | ||
| // eslint-disable-next-line no-control-regex | ||
| .replace(/[\x00-\x1f\x7f-\x9f]/g, "") | ||
| ); // Remove other control characters | ||
| }; | ||
|
|
||
| export function devLogger() { | ||
| return async (c: Context, next: Next) => { | ||
| const start = Date.now(); | ||
| const method = c.req.method; | ||
| const path = c.req.path; | ||
|
|
||
| // Skip noisy paths | ||
| if (path === "/api/auth/get-session" || path.includes("favicon")) { | ||
| await next(); | ||
| return; | ||
| } | ||
|
|
||
| // For MCP calls, extract tool/method info | ||
| // Note: In production, we skip body cloning for performance. Detailed parsing | ||
| // happens deeper in the call stack where the body is already parsed (e.g., in proxy routes). | ||
| let mcpInfo = ""; | ||
| let isMcpCall = false; | ||
| if (path.startsWith("/mcp") && method === "POST") { | ||
| isMcpCall = true; | ||
| // Skip expensive body cloning in production | ||
| try { | ||
| // Only attempt to parse if Content-Type suggests JSON and body exists | ||
| const contentType = c.req.header("Content-Type"); | ||
| if (contentType?.includes("application/json")) { | ||
| const cloned = c.req.raw.clone(); | ||
| const body = (await cloned.json()) as { | ||
| method?: string; | ||
| params?: { | ||
| name?: string; | ||
| arguments?: Record<string, unknown>; | ||
| }; | ||
| }; | ||
| if (body.method === "tools/call" && body.params?.name) { | ||
| // Sanitize all user-provided fields before logging | ||
| const toolName = sanitizeForLog(body.params.name); | ||
| const args = body.params.arguments || {}; | ||
|
|
||
| // For event bus calls, show the event type prominently | ||
| if (toolName === "EVENT_PUBLISH" && args.type) { | ||
| const eventType = sanitizeForLog(String(args.type)); | ||
| mcpInfo = `${colors.tool}EVENT_PUBLISH${colors.reset} ${colors.bold}→ ${eventType}${colors.reset}`; | ||
| } else if (toolName === "EVENT_SUBSCRIBE" && args.eventType) { | ||
| const eventType = sanitizeForLog(String(args.eventType)); | ||
| mcpInfo = `${colors.tool}EVENT_SUBSCRIBE${colors.reset} ${colors.bold}← ${eventType}${colors.reset}`; | ||
| } else if (toolName === "EVENT_UNSUBSCRIBE" && args.eventType) { | ||
| const eventType = sanitizeForLog(String(args.eventType)); | ||
| mcpInfo = `${colors.tool}EVENT_UNSUBSCRIBE${colors.reset} ${colors.dim}✕ ${eventType}${colors.reset}`; | ||
| } else { | ||
| // Default: show tool name with arg keys (sanitized) | ||
| const argKeys = Object.keys(args).map((k) => sanitizeForLog(k)); | ||
| const argsStr = | ||
| argKeys.length > 0 | ||
| ? argKeys.slice(0, 3).join(",") + | ||
| (argKeys.length > 3 ? "…" : "") | ||
| : ""; | ||
| mcpInfo = `${colors.tool}${toolName}${colors.dim}(${argsStr})${colors.reset}`; | ||
| } | ||
| } else if (body.method) { | ||
| mcpInfo = `${colors.dim}${sanitizeForLog(body.method)}${colors.reset}`; | ||
| } | ||
| } | ||
| } catch { | ||
| // Ignore parse errors - body parsing failures shouldn't break the request | ||
| // Detailed error logging happens deeper in the stack | ||
| } | ||
| } | ||
|
|
||
| // Format path - shorten connection IDs (sanitize path for safety) | ||
| let displayPath = sanitizeForLog(path); | ||
| if (path.startsWith("/mcp/conn_")) { | ||
| const connId = path.split("/")[2] ?? ""; | ||
| displayPath = `/mcp/${colors.mcp}${sanitizeForLog(connId.slice(0, 12))}…${colors.reset}`; | ||
| } else if (path === "/mcp") { | ||
| displayPath = `${colors.mcp}/mcp${colors.reset}`; | ||
| } else if (path === "/mcp/registry") { | ||
| displayPath = `${colors.mcp}/mcp/registry${colors.reset}`; | ||
| } | ||
|
|
||
| // Log incoming request | ||
| const methodColor = getMethodColor(method); | ||
| const arrow = isMcpCall ? "◀" : "←"; | ||
| console.log( | ||
| `${colors.dim}${arrow}${colors.reset} ${methodColor}${method}${colors.reset} ${displayPath}${mcpInfo ? ` ${mcpInfo}` : ""}`, | ||
| ); | ||
|
|
||
| // Wrap next() in try/finally to ensure completion logs always run | ||
| // even if downstream throws an error | ||
| try { | ||
| await next(); | ||
| } finally { | ||
| const duration = Date.now() - start; | ||
| const status = c.res.status; | ||
| const statusColor = getStatusColor(status); | ||
| const durationStr = | ||
| duration < 1000 ? `${duration}ms` : `${(duration / 1000).toFixed(1)}s`; | ||
| const outArrow = isMcpCall ? "▶" : "→"; | ||
|
|
||
| console.log( | ||
| `${colors.dim}${outArrow}${colors.reset} ${methodColor}${method}${colors.reset} ${displayPath}${mcpInfo ? ` ${mcpInfo}` : ""} ${statusColor}${status}${colors.reset} ${colors.duration}${durationStr}${colors.reset}`, | ||
| ); | ||
| } | ||
| }; | ||
| } | ||
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
EVENT_UNSUBSCRIBE special log formatting never triggers
Low Severity
The condition
args.eventTypeforEVENT_UNSUBSCRIBEwill never be truthy because this tool's input schema usessubscriptionId, noteventType. The spec and implementation confirm thatEVENT_UNSUBSCRIBEtakes{ subscriptionId: string }. As a result, the special "✕ eventType" formatting will never appear for unsubscribe operations - they will fall through to the default formatting instead.