logger

Author: spoons-and-mirrors

lib/compress-logger.ts

@@ -0,0 +1,97 @@
+import * as fs from "fs"
+import * as path from "path"
+
+// =============================================================================
+// Dedicated compress diagnostics logger for DCP
+// Modeled after pocket-universe logger: buffered async file writes, always-on
+// Logs to .logs/dcp-compress.log relative to cwd
+// =============================================================================
+
+const LOG_DIR = path.join(process.cwd(), ".logs")
+const LOG_FILE = path.join(LOG_DIR, "dcp-compress.log")
+const WRITE_INTERVAL_MS = 100
+const MAX_DATA_CHARS = 20000
+
+let buffer: string[] = []
+let scheduled = false
+let initialized = false
+
+function init(): boolean {
+    if (initialized) return true
+    try {
+        if (!fs.existsSync(LOG_DIR)) {
+            fs.mkdirSync(LOG_DIR, { recursive: true })
+        }
+        fs.writeFileSync(LOG_FILE, "")
+        initialized = true
+        return true
+    } catch {
+        return false
+    }
+}
+
+async function flush(): Promise<void> {
+    if (buffer.length === 0) {
+        scheduled = false
+        return
+    }
+    const chunk = buffer.join("")
+    buffer = []
+    scheduled = false
+    try {
+        await fs.promises.appendFile(LOG_FILE, chunk)
+    } catch {}
+}
+
+function schedule(): void {
+    if (!scheduled) {
+        scheduled = true
+        setTimeout(flush, WRITE_INTERVAL_MS)
+    }
+}
+
+type Level = "DEBUG" | "INFO" | "WARN" | "ERROR"
+
+function shouldWrite(_level: Level): boolean {
+    return true
+}
+
+function stringifyData(data: unknown): string {
+    try {
+        const text = JSON.stringify(data)
+        if (text.length <= MAX_DATA_CHARS) return text
+        return `${text.substring(0, MAX_DATA_CHARS)}... [truncated ${text.length - MAX_DATA_CHARS} chars]`
+    } catch {
+        return `"[unserializable data]"`
+    }
+}
+
+function write(level: Level, category: string, message: string, data?: unknown): void {
+    if (!init()) return
+    if (!shouldWrite(level)) return
+    const ts = new Date().toISOString()
+    const dataStr = data !== undefined ? ` | ${stringifyData(data)}` : ""
+    buffer.push(`[${ts}] [${level}] [${category}] ${message}${dataStr}\n`)
+    schedule()
+}
+
+export const clog = {
+    debug: (category: string, message: string, data?: unknown) =>
+        write("DEBUG", category, message, data),
+    info: (category: string, message: string, data?: unknown) =>
+        write("INFO", category, message, data),
+    warn: (category: string, message: string, data?: unknown) =>
+        write("WARN", category, message, data),
+    error: (category: string, message: string, data?: unknown) =>
+        write("ERROR", category, message, data),
+    flush,
+}
+
+export const C = {
+    COMPRESS: "COMPRESS",
+    BOUNDARY: "BOUNDARY",
+    PRUNE: "PRUNE",
+    INJECT: "INJECT",
+    STATE: "STATE",
+    HOOK: "HOOK",
+} as const

lib/hooks.ts

@@ -14,6 +14,7 @@ import { handleSweepCommand } from "./commands/sweep"
 import { handleManualToggleCommand, handleManualTriggerCommand } from "./commands/manual"
 import { ensureSessionInitialized } from "./state/state"
 import { getCurrentParams } from "./strategies/utils"
+import { clog, C } from "./compress-logger"
 
 const INTERNAL_AGENT_SIGNATURES = [
     "You are a title generator",
@@ -101,9 +102,15 @@ export function createChatMessageTransformHandler(
     config: PluginConfig,
 ) {
     return async (input: {}, output: { messages: WithParts[] }) => {
+        clog.debug(
+            C.HOOK,
+            `messages.transform: ${output.messages.length} messages, session=${state.sessionId}`,
+        )
+
         await checkSession(client, state, logger, output.messages, config.manualMode.enabled)
 
         if (state.isSubAgent) {
+            clog.debug(C.HOOK, "Skipping DCP transforms for sub-agent session")
             return
         }
 
@@ -114,8 +121,16 @@ export function createChatMessageTransformHandler(
         supersedeWrites(state, logger, config, output.messages)
         purgeErrors(state, logger, config, output.messages)
 
+        clog.debug(
+            C.HOOK,
+            `Before prune: ${output.messages.length} messages, prune.tools=${state.prune.tools.size}, prune.messages=${state.prune.messages.size}, summaries=${state.compressSummaries.length}`,
+        )
+
         prune(state, logger, config, output.messages)
-        insertCompressToolContext(state, config, logger, output.messages)
+
+        clog.debug(C.HOOK, `After prune: ${output.messages.length} messages`)
+
+        insertCompressToolContext(state, config, output.messages)
 
         applyPendingManualTriggerPrompt(state, output.messages, logger)
         annotateContext(output.messages)

lib/messages/inject.ts

@@ -1,5 +1,4 @@
 import type { SessionState, WithParts } from "../state"
-import type { Logger } from "../logger"
 import type { PluginConfig } from "../config"
 import type { UserMessage } from "@opencode-ai/sdk/v2"
 import { renderNudge } from "../prompts"
@@ -12,6 +11,7 @@ import {
 import { getFilePathsFromParameters, isProtected } from "../protected-file-patterns"
 import { getLastUserMessage, isMessageCompacted } from "../shared-utils"
 import { getCurrentTokenUsage } from "../strategies/utils"
+import { clog, C } from "../compress-logger"
 
 function parsePercentageString(value: string, total: number): number | undefined {
     if (!value.endsWith("%")) return undefined
@@ -149,14 +149,15 @@ const buildContextPressureTools = (state: SessionState, config: PluginConfig): s
 export const insertCompressToolContext = (
     state: SessionState,
     config: PluginConfig,
-    logger: Logger,
     messages: WithParts[],
 ): void => {
     if (state.manualMode || state.pendingManualTrigger) {
+        clog.debug(C.INJECT, "Skipping compress context injection (manual mode or pending trigger)")
         return
     }
 
     if (config.tools.compress.permission === "deny") {
+        clog.debug(C.INJECT, "Skipping compress context injection (compress denied)")
         return
     }
 
@@ -170,38 +171,48 @@ export const insertCompressToolContext = (
         : undefined
 
     if (state.lastToolPrune) {
-        logger.debug("Last context operation was compress - injecting cooldown")
+        clog.info(C.INJECT, "Injecting cooldown (lastToolPrune=true)")
         contentParts.push(wrapCooldownMessage())
     } else {
         if (config.tools.settings.contextPressureEnabled) {
             const contextPressureTools = buildContextPressureTools(state, config)
             if (contextPressureTools) {
                 contentParts.push(contextPressureTools)
+                clog.debug(C.INJECT, "Added context pressure tools list")
             }
         }
 
         if (config.tools.settings.compressContextEnabled) {
             contentParts.push(buildCompressContext(state, messages))
+            clog.debug(C.INJECT, "Added compress context block")
         }
 
         if (shouldInjectLimitNudge(config, state, messages, providerId, modelId)) {
-            logger.info("Injecting context-limit nudge")
+            clog.info(C.INJECT, "Injecting context-limit nudge", {
+                nudgeCounter: state.nudgeCounter,
+                currentTokens: getCurrentTokenUsage(messages),
+            })
             contentParts.push(renderNudge("context-limit"))
         } else if (
             config.tools.settings.nudgeEnabled &&
             state.nudgeCounter >= config.tools.settings.nudgeFrequency
         ) {
-            logger.info("Injecting frequency nudge")
+            clog.info(C.INJECT, "Injecting frequency nudge", {
+                nudgeCounter: state.nudgeCounter,
+                nudgeFrequency: config.tools.settings.nudgeFrequency,
+            })
             contentParts.push(renderNudge("frequency"))
         }
     }
 
     if (contentParts.length === 0) {
+        clog.debug(C.INJECT, "No content parts to inject")
         return
     }
 
     const combinedContent = contentParts.join("\n")
     if (!lastUserMessage) {
+        clog.warn(C.INJECT, "No last user message found, cannot inject")
         return
     }
 
@@ -210,16 +221,25 @@ export const insertCompressToolContext = (
         (message) => !(message.info.role === "user" && isIgnoredUserMessage(message)),
     )
     if (!lastNonIgnoredMessage) {
+        clog.warn(C.INJECT, "No non-ignored message found, cannot inject")
         return
     }
 
     if (lastNonIgnoredMessage.info.role === "user") {
         const textPart = createSyntheticTextPart(lastNonIgnoredMessage, combinedContent)
         lastNonIgnoredMessage.parts.push(textPart)
+        clog.debug(C.INJECT, "Injected as synthetic text part on user message", {
+            msgId: lastNonIgnoredMessage.info.id,
+            contentLen: combinedContent.length,
+        })
         return
     }
 
     const modelID = userInfo.model?.modelID || ""
     const toolPart = createSyntheticToolPart(lastNonIgnoredMessage, combinedContent, modelID)
     lastNonIgnoredMessage.parts.push(toolPart)
+    clog.debug(C.INJECT, "Injected as synthetic tool part on assistant message", {
+        msgId: lastNonIgnoredMessage.info.id,
+        contentLen: combinedContent.length,
+    })
 }

lib/messages/prune.ts

@@ -4,6 +4,7 @@ import type { PluginConfig } from "../config"
 import { isMessageCompacted, getLastUserMessage } from "../shared-utils"
 import { createSyntheticUserMessage, COMPRESS_SUMMARY_PREFIX } from "./utils"
 import type { UserMessage } from "@opencode-ai/sdk/v2"
+import { clog, C } from "../compress-logger"
 
 const PRUNED_TOOL_OUTPUT_REPLACEMENT =
     "[Output removed to save context - information superseded or no longer needed]"
@@ -165,10 +166,20 @@ const filterCompressedRanges = (
     messages: WithParts[],
 ): void => {
     if (!state.prune.messages?.size) {
+        clog.debug(C.PRUNE, "filterCompressedRanges: no pruned messages, skipping")
         return
     }
 
+    clog.info(C.PRUNE, "filterCompressedRanges entry", {
+        totalMessages: messages.length,
+        prunedMessagesCount: state.prune.messages.size,
+        compressSummariesCount: state.compressSummaries.length,
+        summaryAnchors: state.compressSummaries.map((s) => s.anchorMessageId),
+    })
+
     const result: WithParts[] = []
+    let injected = 0
+    let pruned = 0
 
     for (const msg of messages) {
         const msgId = msg.info.id
@@ -186,27 +197,42 @@ const filterCompressedRanges = (
                 result.push(
                     createSyntheticUserMessage(userMessage, summaryContent, userInfo.variant),
                 )
+                injected++
 
-                logger.info("Injected compress summary", {
+                clog.info(C.PRUNE, `Injected compress summary at anchor`, {
                     anchorMessageId: msgId,
                     summaryLength: summary.summary.length,
+                    summaryPreview: summary.summary.substring(0, 80),
+                    baseUserMsgId: userMessage.info.id,
                 })
             } else {
-                logger.warn("No user message found for compress summary", {
+                clog.error(C.PRUNE, `No user message found for compress summary injection`, {
                     anchorMessageId: msgId,
+                    msgIndex,
+                    messageRoles: messages
+                        .slice(0, msgIndex + 1)
+                        .map((m, i) => `${i}:${m.info.role}`),
                 })
             }
         }
 
         // Skip messages that are in the prune list
         if (state.prune.messages.has(msgId)) {
+            pruned++
             continue
         }
 
         // Normal message, include it
         result.push(msg)
     }
 
+    clog.info(C.PRUNE, "filterCompressedRanges complete", {
+        inputMessages: messages.length,
+        outputMessages: result.length,
+        summariesInjected: injected,
+        messagesPruned: pruned,
+    })
+
     // Replace messages array contents
     messages.length = 0
     messages.push(...result)