feat: consola file logger for handler.ts

Author: caozhiyuan

src/lib/logger.ts

@@ -0,0 +1,179 @@
+import consola, { type ConsolaInstance } from "consola"
+import fs from "node:fs"
+import path from "node:path"
+import util from "node:util"
+
+import { PATHS } from "./paths"
+
+const LOG_RETENTION_DAYS = 7
+const LOG_RETENTION_MS = LOG_RETENTION_DAYS * 24 * 60 * 60 * 1000
+const CLEANUP_INTERVAL_MS = 24 * 60 * 60 * 1000
+const LOG_DIR = path.join(PATHS.APP_DIR, "logs")
+const FLUSH_INTERVAL_MS = 1000
+const MAX_BUFFER_SIZE = 100
+
+const logStreams = new Map<string, fs.WriteStream>()
+const logBuffers = new Map<string, Array<string>>()
+
+const ensureLogDirectory = () => {
+  if (!fs.existsSync(LOG_DIR)) {
+    fs.mkdirSync(LOG_DIR, { recursive: true })
+  }
+}
+
+const cleanupOldLogs = () => {
+  if (!fs.existsSync(LOG_DIR)) {
+    return
+  }
+
+  const now = Date.now()
+
+  for (const entry of fs.readdirSync(LOG_DIR)) {
+    const filePath = path.join(LOG_DIR, entry)
+
+    let stats: fs.Stats
+    try {
+      stats = fs.statSync(filePath)
+    } catch {
+      continue
+    }
+
+    if (!stats.isFile()) {
+      continue
+    }
+
+    if (now - stats.mtimeMs > LOG_RETENTION_MS) {
+      try {
+        fs.rmSync(filePath)
+      } catch {
+        continue
+      }
+    }
+  }
+}
+
+const formatArgs = (args: Array<unknown>) =>
+  args
+    .map((arg) =>
+      typeof arg === "string" ? arg : (
+        util.inspect(arg, { depth: null, colors: false })
+      ),
+    )
+    .join(" ")
+
+const sanitizeName = (name: string) => {
+  const normalized = name
+    .toLowerCase()
+    .replaceAll(/[^a-z0-9]+/g, "-")
+    .replaceAll(/^-+|-+$/g, "")
+
+  return normalized === "" ? "handler" : normalized
+}
+
+const getLogStream = (filePath: string): fs.WriteStream => {
+  let stream = logStreams.get(filePath)
+  if (!stream || stream.destroyed) {
+    stream = fs.createWriteStream(filePath, { flags: "a" })
+    logStreams.set(filePath, stream)
+
+    stream.on("error", (error: unknown) => {
+      console.warn("Log stream error", error)
+      logStreams.delete(filePath)
+    })
+  }
+  return stream
+}
+
+const flushBuffer = (filePath: string) => {
+  const buffer = logBuffers.get(filePath)
+  if (!buffer || buffer.length === 0) {
+    return
+  }
+
+  const stream = getLogStream(filePath)
+  const content = buffer.join("\n") + "\n"
+  stream.write(content, (error) => {
+    if (error) {
+      console.warn("Failed to write handler log", error)
+    }
+  })
+
+  logBuffers.set(filePath, [])
+}
+
+const flushAllBuffers = () => {
+  for (const filePath of logBuffers.keys()) {
+    flushBuffer(filePath)
+  }
+}
+
+const appendLine = (filePath: string, line: string) => {
+  let buffer = logBuffers.get(filePath)
+  if (!buffer) {
+    buffer = []
+    logBuffers.set(filePath, buffer)
+  }
+
+  buffer.push(line)
+
+  if (buffer.length >= MAX_BUFFER_SIZE) {
+    flushBuffer(filePath)
+  }
+}
+
+setInterval(flushAllBuffers, FLUSH_INTERVAL_MS)
+
+const cleanup = () => {
+  flushAllBuffers()
+  for (const stream of logStreams.values()) {
+    stream.end()
+  }
+  logStreams.clear()
+  logBuffers.clear()
+}
+
+process.on("exit", cleanup)
+process.on("SIGINT", () => {
+  cleanup()
+  process.exit(0)
+})
+process.on("SIGTERM", () => {
+  cleanup()
+  process.exit(0)
+})
+
+let lastCleanup = 0
+
+export const createHandlerLogger = (name: string): ConsolaInstance => {
+  ensureLogDirectory()
+
+  const sanitizedName = sanitizeName(name)
+  const instance = consola.withTag(name)
+
+  instance.level = 5
+  instance.setReporters([])
+
+  instance.addReporter({
+    log(logObj) {
+      ensureLogDirectory()
+
+      if (Date.now() - lastCleanup > CLEANUP_INTERVAL_MS) {
+        cleanupOldLogs()
+        lastCleanup = Date.now()
+      }
+
+      const date = logObj.date
+      const dateKey = date.toLocaleDateString("sv-SE")
+      const timestamp = date.toLocaleString("sv-SE", { hour12: false })
+      const filePath = path.join(LOG_DIR, `${sanitizedName}-${dateKey}.log`)
+      const message = formatArgs(logObj.args as Array<unknown>)
+      const line = `[${timestamp}] [${logObj.type}] [${logObj.tag || name}]${
+        message ? ` ${message}` : ""
+      }`
+
+      appendLine(filePath, line)
+    },
+  })
+
+  return instance
+}

src/routes/chat-completions/handler.ts

@@ -1,9 +1,9 @@
 import type { Context } from "hono"
 
-import consola from "consola"
 import { streamSSE, type SSEMessage } from "hono/streaming"
 
 import { awaitApproval } from "~/lib/approval"
+import { createHandlerLogger } from "~/lib/logger"
 import { checkRateLimit } from "~/lib/rate-limit"
 import { state } from "~/lib/state"
 import { getTokenCount } from "~/lib/tokenizer"
@@ -14,11 +14,13 @@ import {
   type ChatCompletionsPayload,
 } from "~/services/copilot/create-chat-completions"
 
+const logger = createHandlerLogger("chat-completions-handler")
+
 export async function handleCompletion(c: Context) {
   await checkRateLimit(state)
 
   let payload = await c.req.json<ChatCompletionsPayload>()
-  consola.debug("Request payload:", JSON.stringify(payload).slice(-400))
+  logger.debug("Request payload:", JSON.stringify(payload).slice(-400))
 
   // Find the selected model
   const selectedModel = state.models?.data.find(
@@ -29,12 +31,12 @@ export async function handleCompletion(c: Context) {
   try {
     if (selectedModel) {
       const tokenCount = await getTokenCount(payload, selectedModel)
-      consola.info("Current token count:", tokenCount)
+      logger.info("Current token count:", tokenCount)
     } else {
-      consola.warn("No model selected, skipping token count calculation")
+      logger.warn("No model selected, skipping token count calculation")
     }
   } catch (error) {
-    consola.warn("Failed to calculate token count:", error)
+    logger.warn("Failed to calculate token count:", error)
   }
 
   if (state.manualApprove) await awaitApproval()
@@ -44,20 +46,20 @@ export async function handleCompletion(c: Context) {
       ...payload,
       max_tokens: selectedModel?.capabilities.limits.max_output_tokens,
     }
-    consola.debug("Set max_tokens to:", JSON.stringify(payload.max_tokens))
+    logger.debug("Set max_tokens to:", JSON.stringify(payload.max_tokens))
   }
 
   const response = await createChatCompletions(payload)
 
   if (isNonStreaming(response)) {
-    consola.debug("Non-streaming response:", JSON.stringify(response))
+    logger.debug("Non-streaming response:", JSON.stringify(response))
     return c.json(response)
   }
 
-  consola.debug("Streaming response")
+  logger.debug("Streaming response")
   return streamSSE(c, async (stream) => {
     for await (const chunk of response) {
-      consola.debug("Streaming chunk:", JSON.stringify(chunk))
+      logger.debug("Streaming chunk:", JSON.stringify(chunk))
       await stream.writeSSE(chunk as SSEMessage)
     }
   })

src/routes/messages/handler.ts

@@ -1,10 +1,10 @@
 import type { Context } from "hono"
 
-import consola from "consola"
 import { streamSSE } from "hono/streaming"
 
 import { awaitApproval } from "~/lib/approval"
 import { getSmallModel } from "~/lib/config"
+import { createHandlerLogger } from "~/lib/logger"
 import { checkRateLimit } from "~/lib/rate-limit"
 import { state } from "~/lib/state"
 import {
@@ -37,11 +37,13 @@ import {
 } from "./non-stream-translation"
 import { translateChunkToAnthropicEvents } from "./stream-translation"
 
+const logger = createHandlerLogger("messages-handler")
+
 export async function handleCompletion(c: Context) {
   await checkRateLimit(state)
 
   const anthropicPayload = await c.req.json<AnthropicMessagesPayload>()
-  consola.debug("Anthropic request payload:", JSON.stringify(anthropicPayload))
+  logger.debug("Anthropic request payload:", JSON.stringify(anthropicPayload))
 
   // fix claude code 2.0.28 warmup request consume premium request, forcing small model if no tools are used
   if (!anthropicPayload.tools || anthropicPayload.tools.length === 0) {
@@ -68,27 +70,27 @@ const handleWithChatCompletions = async (
   anthropicPayload: AnthropicMessagesPayload,
 ) => {
   const openAIPayload = translateToOpenAI(anthropicPayload)
-  consola.debug(
+  logger.debug(
     "Translated OpenAI request payload:",
     JSON.stringify(openAIPayload),
   )
 
   const response = await createChatCompletions(openAIPayload)
 
   if (isNonStreaming(response)) {
-    consola.debug(
+    logger.debug(
       "Non-streaming response from Copilot:",
       JSON.stringify(response).slice(-400),
     )
     const anthropicResponse = translateToAnthropic(response)
-    consola.debug(
+    logger.debug(
       "Translated Anthropic response:",
       JSON.stringify(anthropicResponse),
     )
     return c.json(anthropicResponse)
   }
 
-  consola.debug("Streaming response from Copilot")
+  logger.debug("Streaming response from Copilot")
   return streamSSE(c, async (stream) => {
     const streamState: AnthropicStreamState = {
       messageStartSent: false,
@@ -98,7 +100,7 @@ const handleWithChatCompletions = async (
     }
 
     for await (const rawEvent of response) {
-      consola.debug("Copilot raw stream event:", JSON.stringify(rawEvent))
+      logger.debug("Copilot raw stream event:", JSON.stringify(rawEvent))
       if (rawEvent.data === "[DONE]") {
         break
       }
@@ -111,7 +113,7 @@ const handleWithChatCompletions = async (
       const events = translateChunkToAnthropicEvents(chunk, streamState)
 
       for (const event of events) {
-        consola.debug("Translated Anthropic event:", JSON.stringify(event))
+        logger.debug("Translated Anthropic event:", JSON.stringify(event))
         await stream.writeSSE({
           event: event.type,
           data: JSON.stringify(event),
@@ -127,7 +129,7 @@ const handleWithResponsesApi = async (
 ) => {
   const responsesPayload =
     translateAnthropicMessagesToResponsesPayload(anthropicPayload)
-  consola.debug(
+  logger.debug(
     "Translated Responses payload:",
     JSON.stringify(responsesPayload),
   )
@@ -139,7 +141,7 @@ const handleWithResponsesApi = async (
   })
 
   if (responsesPayload.stream && isAsyncIterable(response)) {
-    consola.debug("Streaming response from Copilot (Responses API)")
+    logger.debug("Streaming response from Copilot (Responses API)")
     return streamSSE(c, async (stream) => {
       const streamState = createResponsesStreamState()
 
@@ -155,15 +157,15 @@ const handleWithResponsesApi = async (
           continue
         }
 
-        consola.debug("Responses raw stream event:", data)
+        logger.debug("Responses raw stream event:", data)
 
         const events = translateResponsesStreamEvent(
           JSON.parse(data) as ResponseStreamEvent,
           streamState,
         )
         for (const event of events) {
           const eventData = JSON.stringify(event)
-          consola.debug("Translated Anthropic event:", eventData)
+          logger.debug("Translated Anthropic event:", eventData)
           await stream.writeSSE({
             event: event.type,
             data: eventData,
@@ -172,7 +174,7 @@ const handleWithResponsesApi = async (
       }
 
       if (!streamState.messageCompleted) {
-        consola.warn(
+        logger.warn(
           "Responses stream ended without completion; sending fallback message_stop",
         )
         const fallback = { type: "message_stop" as const }
@@ -184,14 +186,14 @@ const handleWithResponsesApi = async (
     })
   }
 
-  consola.debug(
+  logger.debug(
     "Non-streaming Responses result:",
     JSON.stringify(response).slice(-400),
   )
   const anthropicResponse = translateResponsesResultToAnthropic(
     response as ResponsesResult,
   )
-  consola.debug(
+  logger.debug(
     "Translated Anthropic response:",
     JSON.stringify(anthropicResponse),
   )