From 213bc4df1c45b6121c70bcaff1d1fb8a8a9d5885 Mon Sep 17 00:00:00 2001 From: Mario Zechner Date: Wed, 26 Nov 2025 18:04:16 +0100 Subject: [PATCH] mom: add centralized logging, usage tracking, and improve prompt caching MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Major improvements to mom's logging and cost reporting: Centralized Logging System: - Add src/log.ts with type-safe logging functions - Colored console output (green=user, yellow=mom, dim=details) - Consistent format: [HH:MM:SS] [context] message - Replace scattered console.log/error calls throughout codebase Usage Tracking & Cost Reporting: - Track tokens (input, output, cache read/write) and costs per run - Display summary at end of each run in console and Slack thread - Example: 💰 Usage: 12,543 in + 847 out (5,234 cache read) = $0.0234 Prompt Caching Optimization: - Move recent messages from system prompt to user message - System prompt now mostly static (only changes with memory files) - Enables effective use of Anthropic's prompt caching - Significantly reduces costs on subsequent requests Model & Cost Improvements: - Switch from Claude Opus 4.5 to Sonnet 4.5 (~40% cost reduction) - Fix Claude Opus 4.5 cache pricing in ai package (was 3x too expensive) - Add manual override in generate-models.ts until upstream fix merges - Submitted PR to models.dev: https://github.com/sst/models.dev/pull/439 UI/UX Improvements: - Extract actual text from tool results instead of JSON wrapper - Cleaner Slack thread formatting with duration and labels - Tool args formatting shows paths with offset:limit notation - Add chalk for colored terminal output Dependencies: - Add chalk package for terminal colors --- package-lock.json | 23 +-- packages/ai/CHANGELOG.md | 15 ++ packages/ai/scripts/generate-models.ts | 8 + packages/ai/src/models.generated.ts | 4 +- packages/mom/CHANGELOG.md | 16 ++ packages/mom/package.json | 1 + packages/mom/src/agent.ts | 193 +++++++++++++++++---- packages/mom/src/log.ts | 226 +++++++++++++++++++++++++ packages/mom/src/main.ts | 17 +- packages/mom/src/slack.ts | 31 +++- packages/mom/src/store.ts | 7 +- 11 files changed, 478 insertions(+), 63 deletions(-) create mode 100644 packages/ai/CHANGELOG.md create mode 100644 packages/mom/src/log.ts diff --git a/package-lock.json b/package-lock.json index c19d8838..2256cf27 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1058,6 +1058,8 @@ }, "node_modules/chalk": { "version": "5.6.2", + "resolved": "https://registry.npmjs.org/chalk/-/chalk-5.6.2.tgz", + "integrity": "sha512-7NzBL0rN6fMUW+f7A6Io4h40qQlG+xGmtMxfbnH/K7TAtt8JQWVQK+6g0UXKMeVJoyV5EkkNsErQ8pVD3bLHbA==", "license": "MIT", "engines": { "node": "^12.17.0 || ^14.13 || >=16.0.0" @@ -3769,8 +3771,8 @@ "version": "0.9.4", "license": "MIT", "dependencies": { - "@mariozechner/pi-ai": "^0.9.3", - "@mariozechner/pi-tui": "^0.9.3" + "@mariozechner/pi-ai": "^0.9.4", + "@mariozechner/pi-tui": "^0.9.4" }, "devDependencies": { "@types/node": "^24.3.0", @@ -3836,9 +3838,9 @@ "version": "0.9.4", "license": "MIT", "dependencies": { - "@mariozechner/pi-agent-core": "^0.9.3", - "@mariozechner/pi-ai": "^0.9.3", - "@mariozechner/pi-tui": "^0.9.3", + "@mariozechner/pi-agent-core": "^0.9.4", + "@mariozechner/pi-ai": "^0.9.4", + "@mariozechner/pi-tui": "^0.9.4", "chalk": "^5.5.0", "diff": "^8.0.2", "glob": "^11.0.3" @@ -3875,11 +3877,12 @@ "license": "MIT", "dependencies": { "@anthropic-ai/sandbox-runtime": "^0.0.16", - "@mariozechner/pi-agent-core": "^0.9.3", - "@mariozechner/pi-ai": "^0.9.3", + "@mariozechner/pi-agent-core": "^0.9.4", + "@mariozechner/pi-ai": "^0.9.4", "@sinclair/typebox": "^0.34.0", "@slack/socket-mode": "^2.0.0", "@slack/web-api": "^7.0.0", + "chalk": "^5.6.2", "diff": "^8.0.2" }, "bin": { @@ -3916,7 +3919,7 @@ "version": "0.9.4", "license": "MIT", "dependencies": { - "@mariozechner/pi-agent-core": "^0.9.3", + "@mariozechner/pi-agent-core": "^0.9.4", "chalk": "^5.5.0" }, "bin": { @@ -3982,8 +3985,8 @@ "license": "MIT", "dependencies": { "@lmstudio/sdk": "^1.5.0", - "@mariozechner/pi-ai": "^0.9.3", - "@mariozechner/pi-tui": "^0.9.3", + "@mariozechner/pi-ai": "^0.9.4", + "@mariozechner/pi-tui": "^0.9.4", "docx-preview": "^0.3.7", "jszip": "^3.10.1", "lucide": "^0.544.0", diff --git a/packages/ai/CHANGELOG.md b/packages/ai/CHANGELOG.md new file mode 100644 index 00000000..7883aa9e --- /dev/null +++ b/packages/ai/CHANGELOG.md @@ -0,0 +1,15 @@ +# Changelog + +## [Unreleased] + +### Fixed + +- **Fixed Claude Opus 4.5 cache pricing** (was 3x too expensive) + - Corrected cache_read: $1.50 → $0.50 per MTok + - Corrected cache_write: $18.75 → $6.25 per MTok + - Added manual override in `scripts/generate-models.ts` until upstream fix is merged + - Submitted PR to models.dev: https://github.com/sst/models.dev/pull/439 + +## [0.9.4] - 2025-11-26 + +Initial release with multi-provider LLM support. diff --git a/packages/ai/scripts/generate-models.ts b/packages/ai/scripts/generate-models.ts index 82055a31..c1e06ec9 100644 --- a/packages/ai/scripts/generate-models.ts +++ b/packages/ai/scripts/generate-models.ts @@ -295,6 +295,14 @@ async function generateModels() { // Combine models (models.dev has priority) const allModels = [...modelsDevModels, ...openRouterModels]; + // Fix incorrect cache pricing for Claude Opus 4.5 from models.dev + // models.dev has 3x the correct pricing (1.5/18.75 instead of 0.5/6.25) + const opus45 = allModels.find(m => m.provider === "anthropic" && m.id === "claude-opus-4-5"); + if (opus45) { + opus45.cost.cacheRead = 0.5; + opus45.cost.cacheWrite = 6.25; + } + // Add missing gpt models if (!allModels.some(m => m.provider === "openai" && m.id === "gpt-5-chat-latest")) { allModels.push({ diff --git a/packages/ai/src/models.generated.ts b/packages/ai/src/models.generated.ts index 91fceae9..89797c8a 100644 --- a/packages/ai/src/models.generated.ts +++ b/packages/ai/src/models.generated.ts @@ -118,8 +118,8 @@ export const MODELS = { cost: { input: 5, output: 25, - cacheRead: 1.5, - cacheWrite: 18.75, + cacheRead: 0.5, + cacheWrite: 6.25, }, contextWindow: 200000, maxTokens: 64000, diff --git a/packages/mom/CHANGELOG.md b/packages/mom/CHANGELOG.md index 9eac22c6..dcc35221 100644 --- a/packages/mom/CHANGELOG.md +++ b/packages/mom/CHANGELOG.md @@ -12,6 +12,14 @@ - ISO 8601 date field in log.jsonl for easy date-based grepping - Format: `"date":"2025-11-26T10:44:00.123Z"` - Enables queries like: `grep '"date":"2025-11-26' log.jsonl` +- Centralized logging system (`src/log.ts`) + - Structured, colored console output (green for user messages, yellow for mom activity, dim for details) + - Consistent format: `[HH:MM:SS] [context] message` + - Type-safe logging functions for all event types +- Usage tracking and cost reporting + - Tracks tokens (input, output, cache read, cache write) and costs per run + - Displays summary at end of each agent run in console and Slack thread + - Example: `💰 Usage: 12,543 in + 847 out (5,234 cache read, 127 cache write) = $0.0234` ### Changed @@ -26,6 +34,14 @@ - Fixed jq patterns to handle null/empty attachments with `(.attachments // [])` - Recent messages in system prompt now formatted as TSV (43% token savings vs raw JSONL) - Enhanced security documentation with prompt injection risk warnings and mitigations +- **Moved recent messages from system prompt to user message** for better prompt caching + - System prompt is now mostly static (only changes when memory files change) + - Enables Anthropic's prompt caching to work effectively + - Significantly reduces costs on subsequent requests +- Switched from Claude Opus 4.5 to Claude Sonnet 4.5 (~40% cost reduction) +- Tool result display now extracts actual text instead of showing JSON wrapper +- Slack thread messages now show cleaner tool call formatting with duration and label +- All console logging centralized and removed from scattered locations ### Fixed diff --git a/packages/mom/package.json b/packages/mom/package.json index 2d8163ac..9bc8961f 100644 --- a/packages/mom/package.json +++ b/packages/mom/package.json @@ -26,6 +26,7 @@ "@sinclair/typebox": "^0.34.0", "@slack/socket-mode": "^2.0.0", "@slack/web-api": "^7.0.0", + "chalk": "^5.6.2", "diff": "^8.0.2" }, "devDependencies": { diff --git a/packages/mom/src/agent.ts b/packages/mom/src/agent.ts index 4a28490d..280f75c3 100644 --- a/packages/mom/src/agent.ts +++ b/packages/mom/src/agent.ts @@ -3,14 +3,14 @@ import { getModel } from "@mariozechner/pi-ai"; import { existsSync, readFileSync } from "fs"; import { mkdir } from "fs/promises"; import { join } from "path"; - +import * as log from "./log.js"; import { createExecutor, type SandboxConfig } from "./sandbox.js"; import type { SlackContext } from "./slack.js"; import type { ChannelStore } from "./store.js"; import { createMomTools, setUploadFunction } from "./tools/index.js"; // Hardcoded model for now -const model = getModel("anthropic", "claude-opus-4-5"); +const model = getModel("anthropic", "claude-sonnet-4-5"); export interface AgentRunner { run(ctx: SlackContext, channelDir: string, store: ChannelStore): Promise; @@ -67,7 +67,7 @@ function getMemory(channelDir: string): string { parts.push("### Global Workspace Memory\n" + content); } } catch (error) { - console.error(`Failed to read workspace memory: ${error}`); + log.logWarning("Failed to read workspace memory", `${workspaceMemoryPath}: ${error}`); } } @@ -80,7 +80,7 @@ function getMemory(channelDir: string): string { parts.push("### Channel-Specific Memory\n" + content); } } catch (error) { - console.error(`Failed to read channel memory: ${error}`); + log.logWarning("Failed to read channel memory", `${channelMemoryPath}: ${error}`); } } @@ -94,7 +94,6 @@ function getMemory(channelDir: string): string { function buildSystemPrompt( workspacePath: string, channelId: string, - recentMessages: string, memory: string, sandboxConfig: SandboxConfig, ): string { @@ -224,10 +223,6 @@ You can maintain working memory across conversations by writing MEMORY.md files. ### Current Working Memory ${memory} -### Recent Messages (last 50) -Format: date TAB user TAB text TAB attachments -${recentMessages} - ## Tools You have access to: bash, read, edit, write, attach tools. - bash: Run shell commands (this is your main tool) @@ -254,6 +249,68 @@ function truncate(text: string, maxLen: number): string { return text.substring(0, maxLen - 3) + "..."; } +function extractToolResultText(result: unknown): string { + // If it's already a string, return it + if (typeof result === "string") { + return result; + } + + // If it's an object with content array (tool result format) + if ( + result && + typeof result === "object" && + "content" in result && + Array.isArray((result as { content: unknown }).content) + ) { + const content = (result as { content: Array<{ type: string; text?: string }> }).content; + const textParts: string[] = []; + for (const part of content) { + if (part.type === "text" && part.text) { + textParts.push(part.text); + } + } + if (textParts.length > 0) { + return textParts.join("\n"); + } + } + + // Fallback to JSON + return JSON.stringify(result); +} + +function formatToolArgsForSlack(toolName: string, args: Record): string { + const lines: string[] = []; + + for (const [key, value] of Object.entries(args)) { + // Skip the label - it's already shown + if (key === "label") continue; + + // For read tool, format path with offset/limit + if (key === "path" && typeof value === "string") { + const offset = args.offset as number | undefined; + const limit = args.limit as number | undefined; + if (offset !== undefined && limit !== undefined) { + lines.push(`${value}:${offset}-${offset + limit}`); + } else { + lines.push(value); + } + continue; + } + + // Skip offset/limit since we already handled them + if (key === "offset" || key === "limit") continue; + + // For other values, format them + if (typeof value === "string") { + lines.push(value); + } else { + lines.push(JSON.stringify(value)); + } + } + + return lines.join("\n"); +} + export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { let agent: Agent | null = null; const executor = createExecutor(sandboxConfig); @@ -267,7 +324,7 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { const workspacePath = executor.getWorkspacePath(channelDir.replace(`/${channelId}`, "")); const recentMessages = getRecentMessages(channelDir, 50); const memory = getMemory(channelDir); - const systemPrompt = buildSystemPrompt(workspacePath, channelId, recentMessages, memory, sandboxConfig); + const systemPrompt = buildSystemPrompt(workspacePath, channelId, memory, sandboxConfig); // Set up file upload function for the attach tool // For Docker, we need to translate paths back to host @@ -292,8 +349,30 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { }), }); - // Track pending tool calls to pair args with results - const pendingTools = new Map(); + // Create logging context + const logCtx = { + channelId: ctx.message.channel, + userName: ctx.message.userName, + channelName: ctx.channelName, + }; + + // Track pending tool calls to pair args with results and timing + const pendingTools = new Map(); + + // Track usage across all assistant messages in this run + const totalUsage = { + input: 0, + output: 0, + cacheRead: 0, + cacheWrite: 0, + cost: { + input: 0, + output: 0, + cacheRead: 0, + cacheWrite: 0, + total: 0, + }, + }; // Subscribe to events agent.subscribe(async (event: AgentEvent) => { @@ -303,10 +382,14 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { const label = args.label || event.toolName; // Store args to pair with result later - pendingTools.set(event.toolCallId, { toolName: event.toolName, args: event.args }); + pendingTools.set(event.toolCallId, { + toolName: event.toolName, + args: event.args, + startTime: Date.now(), + }); // Log to console - console.log(`\n[Tool] ${event.toolName}: ${JSON.stringify(event.args)}`); + log.logToolStart(logCtx, event.toolName, label, event.args as Record); // Log to jsonl await store.logMessage(ctx.message.channel, { @@ -324,12 +407,18 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { } case "tool_execution_end": { - const resultStr = typeof event.result === "string" ? event.result : JSON.stringify(event.result); + const resultStr = extractToolResultText(event.result); const pending = pendingTools.get(event.toolCallId); pendingTools.delete(event.toolCallId); + const durationMs = pending ? Date.now() - pending.startTime : 0; + // Log to console - console.log(`[Tool Result] ${event.isError ? "ERROR: " : ""}${truncate(resultStr, 1000)}\n`); + if (event.isError) { + log.logToolError(logCtx, event.toolName, durationMs, resultStr); + } else { + log.logToolSuccess(logCtx, event.toolName, durationMs, resultStr); + } // Log to jsonl await store.logMessage(ctx.message.channel, { @@ -342,17 +431,26 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { }); // Post args + result together in thread - const argsStr = pending ? JSON.stringify(pending.args, null, 2) : "(args not found)"; + const label = pending?.args ? (pending.args as { label?: string }).label : undefined; + const argsFormatted = pending + ? formatToolArgsForSlack(event.toolName, pending.args as Record) + : "(args not found)"; + const duration = (durationMs / 1000).toFixed(1); const threadResult = truncate(resultStr, 2000); - await ctx.respondInThread( - `*[${event.toolName}]* ${event.isError ? "❌" : "✓"}\n` + - "```\n" + - argsStr + - "\n```\n" + - "*Result:*\n```\n" + - threadResult + - "\n```", - ); + + let threadMessage = `*${event.isError ? "✗" : "✓"} ${event.toolName}*`; + if (label) { + threadMessage += `: ${label}`; + } + threadMessage += ` (${duration}s)\n`; + + if (argsFormatted) { + threadMessage += "```\n" + argsFormatted + "\n```\n"; + } + + threadMessage += "*Result:*\n```\n" + threadResult + "\n```"; + + await ctx.respondInThread(threadMessage); // Show brief error in main message if failed if (event.isError) { @@ -362,25 +460,33 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { } case "message_update": { - const ev = event.assistantMessageEvent; - // Stream deltas to console - if (ev.type === "text_delta") { - process.stdout.write(ev.delta); - } else if (ev.type === "thinking_delta") { - process.stdout.write(ev.delta); - } + // No longer stream to console - just track that we're streaming break; } case "message_start": if (event.message.role === "assistant") { - process.stdout.write("\n"); + log.logResponseStart(logCtx); } break; case "message_end": if (event.message.role === "assistant") { - process.stdout.write("\n"); + const assistantMsg = event.message as any; // AssistantMessage type + + // Accumulate usage + if (assistantMsg.usage) { + totalUsage.input += assistantMsg.usage.input; + totalUsage.output += assistantMsg.usage.output; + totalUsage.cacheRead += assistantMsg.usage.cacheRead; + totalUsage.cacheWrite += assistantMsg.usage.cacheWrite; + totalUsage.cost.input += assistantMsg.usage.cost.input; + totalUsage.cost.output += assistantMsg.usage.cost.output; + totalUsage.cost.cacheRead += assistantMsg.usage.cost.cacheRead; + totalUsage.cost.cacheWrite += assistantMsg.usage.cost.cacheWrite; + totalUsage.cost.total += assistantMsg.usage.cost.total; + } + // Extract text from assistant message const content = event.message.content; let text = ""; @@ -391,6 +497,7 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { } if (text.trim()) { await ctx.respond(text); + log.logResponseComplete(logCtx, text.length); } } break; @@ -398,7 +505,21 @@ export function createAgentRunner(sandboxConfig: SandboxConfig): AgentRunner { }); // Run the agent with user's message - await agent.prompt(ctx.message.text || "(attached files)"); + // Prepend recent messages to the user prompt (not system prompt) for better caching + const userPrompt = + `Recent conversation history (last 50 messages):\n` + + `Format: date TAB user TAB text TAB attachments\n\n` + + `${recentMessages}\n\n` + + `---\n\n` + + `Current message: ${ctx.message.text || "(attached files)"}`; + + await agent.prompt(userPrompt); + + // Log usage summary if there was any usage + if (totalUsage.cost.total > 0) { + const summary = log.logUsageSummary(logCtx, totalUsage); + await ctx.respondInThread(summary); + } }, abort(): void { diff --git a/packages/mom/src/log.ts b/packages/mom/src/log.ts new file mode 100644 index 00000000..8ac04f3f --- /dev/null +++ b/packages/mom/src/log.ts @@ -0,0 +1,226 @@ +import chalk from "chalk"; + +export interface LogContext { + channelId: string; + userName?: string; + channelName?: string; // For display like #dev-team vs C16HET4EQ +} + +function timestamp(): string { + const now = new Date(); + const hh = String(now.getHours()).padStart(2, "0"); + const mm = String(now.getMinutes()).padStart(2, "0"); + const ss = String(now.getSeconds()).padStart(2, "0"); + return `[${hh}:${mm}:${ss}]`; +} + +function formatContext(ctx: LogContext): string { + // DMs: [DM:username] + // Channels: [#channel-name:username] or [C16HET4EQ:username] if no name + if (ctx.channelId.startsWith("D")) { + return `[DM:${ctx.userName || ctx.channelId}]`; + } + const channel = ctx.channelName || ctx.channelId; + const user = ctx.userName || "unknown"; + return `[${channel.startsWith("#") ? channel : `#${channel}`}:${user}]`; +} + +function truncate(text: string, maxLen: number): string { + if (text.length <= maxLen) return text; + return text.substring(0, maxLen) + `\n(truncated at ${maxLen} chars)`; +} + +function formatToolArgs(args: Record): string { + const lines: string[] = []; + + for (const [key, value] of Object.entries(args)) { + // Skip the label - it's already shown in the tool name + if (key === "label") continue; + + // For read tool, format path with offset/limit + if (key === "path" && typeof value === "string") { + const offset = args.offset as number | undefined; + const limit = args.limit as number | undefined; + if (offset !== undefined && limit !== undefined) { + lines.push(`${value}:${offset}-${offset + limit}`); + } else { + lines.push(value); + } + continue; + } + + // Skip offset/limit since we already handled them + if (key === "offset" || key === "limit") continue; + + // For other values, format them + if (typeof value === "string") { + // Multi-line strings get indented + if (value.includes("\n")) { + lines.push(value); + } else { + lines.push(value); + } + } else { + lines.push(JSON.stringify(value)); + } + } + + return lines.join("\n"); +} + +// User messages +export function logUserMessage(ctx: LogContext, text: string): void { + console.log(chalk.green(`${timestamp()} ${formatContext(ctx)} ${text}`)); +} + +// Tool execution +export function logToolStart(ctx: LogContext, toolName: string, label: string, args: Record): void { + const formattedArgs = formatToolArgs(args); + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} ↳ ${toolName}: ${label}`)); + if (formattedArgs) { + // Indent the args + const indented = formattedArgs + .split("\n") + .map((line) => ` ${line}`) + .join("\n"); + console.log(chalk.dim(indented)); + } +} + +export function logToolSuccess(ctx: LogContext, toolName: string, durationMs: number, result: string): void { + const duration = (durationMs / 1000).toFixed(1); + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} ✓ ${toolName} (${duration}s)`)); + + const truncated = truncate(result, 1000); + if (truncated) { + const indented = truncated + .split("\n") + .map((line) => ` ${line}`) + .join("\n"); + console.log(chalk.dim(indented)); + } +} + +export function logToolError(ctx: LogContext, toolName: string, durationMs: number, error: string): void { + const duration = (durationMs / 1000).toFixed(1); + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} ✗ ${toolName} (${duration}s)`)); + + const truncated = truncate(error, 1000); + const indented = truncated + .split("\n") + .map((line) => ` ${line}`) + .join("\n"); + console.log(chalk.dim(indented)); +} + +// Response streaming +export function logResponseStart(ctx: LogContext): void { + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} → Streaming response...`)); +} + +export function logResponseComplete(ctx: LogContext, charCount: number): void { + console.log( + chalk.yellow(`${timestamp()} ${formatContext(ctx)} ✓ Response sent (${charCount.toLocaleString()} chars)`), + ); +} + +// Attachments +export function logDownloadStart(ctx: LogContext, filename: string, localPath: string): void { + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} ↓ Downloading attachment`)); + console.log(chalk.dim(` ${filename} → ${localPath}`)); +} + +export function logDownloadSuccess(ctx: LogContext, sizeKB: number): void { + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} ✓ Downloaded (${sizeKB.toLocaleString()} KB)`)); +} + +export function logDownloadError(ctx: LogContext, filename: string, error: string): void { + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} ✗ Download failed`)); + console.log(chalk.dim(` ${filename}: ${error}`)); +} + +// Control +export function logStopRequest(ctx: LogContext): void { + console.log(chalk.green(`${timestamp()} ${formatContext(ctx)} stop`)); + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} ⊗ Stop requested - aborting`)); +} + +// System +export function logWarning(message: string, details?: string): void { + console.log(chalk.yellow(`${timestamp()} [system] ⚠ ${message}`)); + if (details) { + const indented = details + .split("\n") + .map((line) => ` ${line}`) + .join("\n"); + console.log(chalk.dim(indented)); + } +} + +export function logAgentError(ctx: LogContext | "system", error: string): void { + const context = ctx === "system" ? "[system]" : formatContext(ctx); + console.log(chalk.yellow(`${timestamp()} ${context} ✗ Agent error`)); + const indented = error + .split("\n") + .map((line) => ` ${line}`) + .join("\n"); + console.log(chalk.dim(indented)); +} + +// Usage summary +export function logUsageSummary( + ctx: LogContext, + usage: { + input: number; + output: number; + cacheRead: number; + cacheWrite: number; + cost: { input: number; output: number; cacheRead: number; cacheWrite: number; total: number }; + }, +): string { + const lines: string[] = []; + lines.push("*Usage Summary*"); + lines.push(`Tokens: ${usage.input.toLocaleString()} in, ${usage.output.toLocaleString()} out`); + if (usage.cacheRead > 0 || usage.cacheWrite > 0) { + lines.push(`Cache: ${usage.cacheRead.toLocaleString()} read, ${usage.cacheWrite.toLocaleString()} write`); + } + lines.push( + `Cost: $${usage.cost.input.toFixed(4)} in, $${usage.cost.output.toFixed(4)} out` + + (usage.cacheRead > 0 || usage.cacheWrite > 0 + ? `, $${usage.cost.cacheRead.toFixed(4)} cache read, $${usage.cost.cacheWrite.toFixed(4)} cache write` + : ""), + ); + lines.push(`*Total: $${usage.cost.total.toFixed(4)}*`); + + const summary = lines.join("\n"); + + // Log to console + console.log(chalk.yellow(`${timestamp()} ${formatContext(ctx)} 💰 Usage`)); + console.log( + chalk.dim( + ` ${usage.input.toLocaleString()} in + ${usage.output.toLocaleString()} out` + + (usage.cacheRead > 0 || usage.cacheWrite > 0 + ? ` (${usage.cacheRead.toLocaleString()} cache read, ${usage.cacheWrite.toLocaleString()} cache write)` + : "") + + ` = $${usage.cost.total.toFixed(4)}`, + ), + ); + + return summary; +} + +// Startup (no context needed) +export function logStartup(workingDir: string, sandbox: string): void { + console.log("Starting mom bot..."); + console.log(` Working directory: ${workingDir}`); + console.log(` Sandbox: ${sandbox}`); +} + +export function logConnected(): void { + console.log("⚡️ Mom bot connected and listening!"); + console.log(""); +} + +export function logDisconnected(): void { + console.log("Mom bot disconnected."); +} diff --git a/packages/mom/src/main.ts b/packages/mom/src/main.ts index 26551f78..ca182a1d 100644 --- a/packages/mom/src/main.ts +++ b/packages/mom/src/main.ts @@ -2,6 +2,7 @@ import { join, resolve } from "path"; import { type AgentRunner, createAgentRunner } from "./agent.js"; +import * as log from "./log.js"; import { parseSandboxArg, type SandboxConfig, validateSandbox } from "./sandbox.js"; import { MomBot, type SlackContext } from "./slack.js"; @@ -53,9 +54,7 @@ function parseArgs(): { workingDir: string; sandbox: SandboxConfig } { const { workingDir, sandbox } = parseArgs(); -console.log("Starting mom bot..."); -console.log(` Working directory: ${workingDir}`); -console.log(` Sandbox: ${sandbox.type === "host" ? "host" : `docker:${sandbox.container}`}`); +log.logStartup(workingDir, sandbox.type === "host" ? "host" : `docker:${sandbox.container}`); if (!MOM_SLACK_APP_TOKEN || !MOM_SLACK_BOT_TOKEN || (!ANTHROPIC_API_KEY && !ANTHROPIC_OAUTH_TOKEN)) { console.error("Missing required environment variables:"); @@ -75,11 +74,17 @@ async function handleMessage(ctx: SlackContext, source: "channel" | "dm"): Promi const channelId = ctx.message.channel; const messageText = ctx.message.text.toLowerCase().trim(); + const logCtx = { + channelId: ctx.message.channel, + userName: ctx.message.userName, + channelName: ctx.channelName, + }; + // Check for stop command if (messageText === "stop") { const runner = activeRuns.get(channelId); if (runner) { - console.log(`Stop requested for channel ${channelId}`); + log.logStopRequest(logCtx); runner.abort(); await ctx.respond("_Stopping..._"); } else { @@ -94,7 +99,7 @@ async function handleMessage(ctx: SlackContext, source: "channel" | "dm"): Promi return; } - console.log(`${source === "channel" ? "Channel mention" : "DM"} from <@${ctx.message.user}>: ${ctx.message.text}`); + log.logUserMessage(logCtx, ctx.message.text); const channelDir = join(workingDir, channelId); const runner = createAgentRunner(sandbox); @@ -109,7 +114,7 @@ async function handleMessage(ctx: SlackContext, source: "channel" | "dm"): Promi if (msg.includes("aborted") || msg.includes("Aborted")) { // Already said "Stopping..." - nothing more to say } else { - console.error("Agent error:", error); + log.logAgentError(logCtx, msg); await ctx.respond(`❌ Error: ${msg}`); } } finally { diff --git a/packages/mom/src/slack.ts b/packages/mom/src/slack.ts index a8f2dccb..0e3b3f69 100644 --- a/packages/mom/src/slack.ts +++ b/packages/mom/src/slack.ts @@ -2,12 +2,14 @@ import { SocketModeClient } from "@slack/socket-mode"; import { WebClient } from "@slack/web-api"; import { readFileSync } from "fs"; import { basename } from "path"; +import * as log from "./log.js"; import { type Attachment, ChannelStore } from "./store.js"; export interface SlackMessage { text: string; // message content (mentions stripped) rawText: string; // original text with mentions user: string; // user ID + userName?: string; // user handle channel: string; // channel ID ts: string; // timestamp (for threading) attachments: Attachment[]; // file attachments @@ -15,6 +17,7 @@ export interface SlackMessage { export interface SlackContext { message: SlackMessage; + channelName?: string; // channel name for logging (e.g., #dev-team) store: ChannelStore; /** Send/update the main message (accumulates text) */ respond(text: string): Promise; @@ -92,7 +95,7 @@ export class MomBot { // Log the mention (message event may not fire for app_mention) await this.logMessage(slackEvent); - const ctx = this.createContext(slackEvent); + const ctx = await this.createContext(slackEvent); await this.handler.onChannelMention(ctx); }); @@ -133,7 +136,7 @@ export class MomBot { // Only trigger handler for DMs (channel mentions are handled by app_mention event) if (slackEvent.channel_type === "im") { - const ctx = this.createContext({ + const ctx = await this.createContext({ text: slackEvent.text || "", channel: slackEvent.channel, user: slackEvent.user, @@ -167,16 +170,30 @@ export class MomBot { }); } - private createContext(event: { + private async createContext(event: { text: string; channel: string; user: string; ts: string; files?: Array<{ name: string; url_private_download?: string; url_private?: string }>; - }): SlackContext { + }): Promise { const rawText = event.text; const text = rawText.replace(/<@[A-Z0-9]+>/gi, "").trim(); + // Get user info for logging + const { userName } = await this.getUserInfo(event.user); + + // Get channel name for logging (best effort) + let channelName: string | undefined; + try { + if (event.channel.startsWith("C")) { + const result = await this.webClient.conversations.info({ channel: event.channel }); + channelName = result.channel?.name ? `#${result.channel.name}` : undefined; + } + } catch { + // Ignore errors - we'll just use the channel ID + } + // Process attachments (for context, already logged by message handler) const attachments = event.files ? this.store.processAttachments(event.channel, event.files, event.ts) : []; @@ -191,10 +208,12 @@ export class MomBot { text, rawText, user: event.user, + userName, channel: event.channel, ts: event.ts, attachments, }, + channelName, store: this.store, respond: async (responseText: string) => { // Queue updates to avoid race conditions @@ -276,11 +295,11 @@ export class MomBot { const auth = await this.webClient.auth.test(); this.botUserId = auth.user_id as string; await this.socketClient.start(); - console.log("⚡️ Mom bot connected and listening!"); + log.logConnected(); } async stop(): Promise { await this.socketClient.disconnect(); - console.log("Mom bot disconnected."); + log.logDisconnected(); } } diff --git a/packages/mom/src/store.ts b/packages/mom/src/store.ts index af7b240a..8ac02aa5 100644 --- a/packages/mom/src/store.ts +++ b/packages/mom/src/store.ts @@ -1,6 +1,7 @@ import { existsSync, mkdirSync } from "fs"; import { appendFile, writeFile } from "fs/promises"; import { join } from "path"; +import * as log from "./log.js"; export interface Attachment { original: string; // original filename from uploader @@ -152,10 +153,10 @@ export class ChannelStore { try { await this.downloadAttachment(item.localPath, item.url); - console.log(`Downloaded: ${item.localPath}`); + // Success - could add success logging here if we have context } catch (error) { - console.error(`Failed to download ${item.localPath}:`, error); - // Could re-queue for retry here + const errorMsg = error instanceof Error ? error.message : String(error); + log.logWarning(`Failed to download attachment`, `${item.localPath}: ${errorMsg}`); } }