diff --git a/packages/jimmy/migrations/0007_tool_call_log.down.sql b/packages/jimmy/migrations/0007_tool_call_log.down.sql new file mode 100644 index 00000000..327c4a91 --- /dev/null +++ b/packages/jimmy/migrations/0007_tool_call_log.down.sql @@ -0,0 +1,5 @@ +-- Roll back 0007_tool_call_log. +DROP INDEX IF EXISTS idx_tool_call_error; +DROP INDEX IF EXISTS idx_tool_call_engine_tool; +DROP INDEX IF EXISTS idx_tool_call_session; +DROP TABLE IF EXISTS tool_call_log; diff --git a/packages/jimmy/migrations/0007_tool_call_log.up.sql b/packages/jimmy/migrations/0007_tool_call_log.up.sql new file mode 100644 index 00000000..a85f7fc5 --- /dev/null +++ b/packages/jimmy/migrations/0007_tool_call_log.up.sql @@ -0,0 +1,38 @@ +-- 0007_tool_call_log: audit-log table for HTTP-loop engine tool calls +-- +-- Receives one row per tool invocation by the ollama / openai engine +-- wrappers (see packages/jimmy/src/engines/agentLoop.ts). The shape +-- mirrors the AuditRow contract from V1 (engines/audit.ts): +-- metadata only — no stdout/stderr/file body/HTTP response body. +-- +-- The args_summary column is pre-sanitized JSON (secret-keyed fields +-- redacted, URLs scrubbed for query-string and userinfo credentials, +-- long strings truncated to 200 chars). +-- +-- Designed for cost/forensic analysis joined to cost_log and sessions +-- on session_id. + +CREATE TABLE IF NOT EXISTS tool_call_log ( + id TEXT PRIMARY KEY, + session_id TEXT NOT NULL, + engine TEXT NOT NULL, + tool_name TEXT NOT NULL, + args_summary TEXT, + duration_ms INTEGER, + exit_code INTEGER, + http_status INTEGER, + error TEXT, + result_truncated INTEGER NOT NULL DEFAULT 0, + result_bytes INTEGER, + created_at TEXT NOT NULL DEFAULT (datetime('now')) +); + +CREATE INDEX IF NOT EXISTS idx_tool_call_session + ON tool_call_log (session_id, created_at); + +CREATE INDEX IF NOT EXISTS idx_tool_call_engine_tool + ON tool_call_log (engine, tool_name, created_at); + +CREATE INDEX IF NOT EXISTS idx_tool_call_error + ON tool_call_log (error, created_at) + WHERE error IS NOT NULL; diff --git a/packages/jimmy/src/engines/__tests__/audit.test.ts b/packages/jimmy/src/engines/__tests__/audit.test.ts index 03ebebf1..4750d389 100644 --- a/packages/jimmy/src/engines/__tests__/audit.test.ts +++ b/packages/jimmy/src/engines/__tests__/audit.test.ts @@ -146,15 +146,49 @@ describe("audit: buildAuditRow keeps NO content / stdout / stderr / body", () => }, }; const row = buildAuditRow("read", { path: "x.txt" }, result, 5); - // Whitelist of allowed keys + // Whitelist of allowed keys. sessionId + engineName are populated + // by the agent loop from ToolExecutionContext; they're optional in + // the shape but always present (possibly undefined) on the object. expect(Object.keys(row).sort()).toEqual( - ["argsSummary", "durationMs", "error", "exitCode", "httpStatus", "resultBytes", "toolName", "truncated"].sort(), + [ + "argsSummary", + "durationMs", + "engineName", + "error", + "exitCode", + "httpStatus", + "resultBytes", + "sessionId", + "toolName", + "truncated", + ].sort(), ); // Sanity: no content leak const serialized = JSON.stringify(row); expect(serialized).not.toContain("FULL FILE CONTENTS"); }); + it("populates sessionId + engineName when scope is provided (Phase 7a)", () => { + const result: ToolResult = { + ok: true, + content: "x", + audit: { truncated: false }, + }; + const row = buildAuditRow("read", { path: "x.txt" }, result, 1, { + sessionId: "sess-42", + engineName: "ollama", + }); + expect(row.sessionId).toBe("sess-42"); + expect(row.engineName).toBe("ollama"); + }); + + it("leaves sessionId + engineName undefined when scope is omitted", () => { + const result: ToolResult = { ok: true, content: "", audit: { truncated: false } }; + const row = buildAuditRow("read", {}, result, 1); + expect(row.sessionId).toBeUndefined(); + expect(row.engineName).toBeUndefined(); + }); + it("captures bash exit_code", () => { const result: ToolResult = { ok: false, diff --git a/packages/jimmy/src/engines/__tests__/sqliteAuditLogger.test.ts b/packages/jimmy/src/engines/__tests__/sqliteAuditLogger.test.ts new file mode 100644 index 00000000..a8454f73 --- /dev/null +++ b/packages/jimmy/src/engines/__tests__/sqliteAuditLogger.test.ts @@ -0,0 +1,230 @@ +/** + * Tests for SqliteAuditLogger — the persistence layer for HTTP-loop + * engine tool calls. + * + * Each test runs against a fresh in-memory sqlite DB that's seeded with + * just the 0007_tool_call_log schema (no other migrations needed; the + * audit table is self-contained). + */ +import { describe, it, expect, beforeEach } from "vitest"; +import Database from "better-sqlite3"; +import fs from "node:fs"; +import path from "node:path"; +import { fileURLToPath } from "node:url"; +import { SqliteAuditLogger } from "../sqliteAuditLogger.js"; +import type { AuditRow } from "../audit.js"; + +// Resolve the migration SQL relative to this test file so it works under +// both `vitest run` and `vitest --watch`. Mirrors the migrate-runner's +// own path-resolution strategy. +const MIGRATION_SQL = fs.readFileSync( + path.resolve( + fileURLToPath(import.meta.url), + "../../../../migrations/0007_tool_call_log.up.sql", + ), + "utf8", +); + +function freshDb(): Database.Database { + const db = new Database(":memory:"); + db.exec(MIGRATION_SQL); + return db; +} + +function baseRow(overrides: Partial = {}): AuditRow { + return { + toolName: "read", + argsSummary: '{"path":"x.txt"}', + durationMs: 12, + error: null, + truncated: false, + resultBytes: 1024, + exitCode: null, + httpStatus: null, + sessionId: "sess-abc", + engineName: "ollama", + ...overrides, + }; +} + +let db: Database.Database; +let logger: SqliteAuditLogger; + +beforeEach(() => { + db = freshDb(); + logger = new SqliteAuditLogger(db); +}); + +// ─── Insert shape ──────────────────────────────────────────────────── + +describe("SqliteAuditLogger: insert shape", () => { + it("writes one row per record() with the documented columns", () => { + logger.record(baseRow()); + const rows = db.prepare("SELECT * FROM tool_call_log").all() as Array>; + expect(rows).toHaveLength(1); + const r = rows[0]!; + expect(r.session_id).toBe("sess-abc"); + expect(r.engine).toBe("ollama"); + expect(r.tool_name).toBe("read"); + expect(r.args_summary).toBe('{"path":"x.txt"}'); + expect(r.duration_ms).toBe(12); + expect(r.exit_code).toBeNull(); + expect(r.http_status).toBeNull(); + expect(r.error).toBeNull(); + expect(r.result_truncated).toBe(0); + expect(r.result_bytes).toBe(1024); + expect(typeof r.id).toBe("string"); + expect((r.id as string).length).toBeGreaterThan(20); + expect(typeof r.created_at).toBe("string"); + }); + + it("persists bash-shaped audit rows (exit_code, error)", () => { + logger.record( + baseRow({ + toolName: "bash", + argsSummary: '{"command":"git","args":["status"]}', + durationMs: 45, + error: "nonzero_exit", + truncated: true, + resultBytes: 32000, + exitCode: 1, + }), + ); + const r = db.prepare("SELECT * FROM tool_call_log").get() as Record; + expect(r.tool_name).toBe("bash"); + expect(r.exit_code).toBe(1); + expect(r.error).toBe("nonzero_exit"); + expect(r.result_truncated).toBe(1); + expect(r.result_bytes).toBe(32000); + }); + + it("persists webfetch-shaped audit rows (http_status)", () => { + logger.record( + baseRow({ + toolName: "webfetch", + argsSummary: '{"url":"https://example.com/"}', + durationMs: 220, + httpStatus: 200, + resultBytes: 5000, + }), + ); + const r = db.prepare("SELECT * FROM tool_call_log").get() as Record; + expect(r.tool_name).toBe("webfetch"); + expect(r.http_status).toBe(200); + expect(r.exit_code).toBeNull(); + }); + + it("inserts each call independently (no replace/dedupe by tool_name)", () => { + logger.record(baseRow({ toolName: "read" })); + logger.record(baseRow({ toolName: "read" })); + logger.record(baseRow({ toolName: "read" })); + const count = (db.prepare("SELECT COUNT(*) AS n FROM tool_call_log").get() as { n: number }).n; + expect(count).toBe(3); + }); + + it("synthesizes a unique id per row", () => { + logger.record(baseRow()); + logger.record(baseRow()); + const ids = db.prepare("SELECT id FROM tool_call_log").all() as Array<{ id: string }>; + expect(new Set(ids.map((r) => r.id)).size).toBe(2); + }); + + it("falls back to 'unknown' when sessionId / engineName are omitted", () => { + logger.record(baseRow({ sessionId: undefined, engineName: undefined })); + const r = db.prepare("SELECT session_id, engine FROM tool_call_log").get() as Record; + expect(r.session_id).toBe("unknown"); + expect(r.engine).toBe("unknown"); + }); +}); + +// ─── No-content persistence (security guarantee) ───────────────────── + +describe("SqliteAuditLogger: NEVER persists tool output content", () => { + it("schema has no 'content', 'stdout', 'stderr', or 'body' columns", () => { + const cols = db.prepare("PRAGMA table_info(tool_call_log)").all() as Array<{ name: string }>; + const names = cols.map((c) => c.name.toLowerCase()); + expect(names).not.toContain("content"); + expect(names).not.toContain("stdout"); + expect(names).not.toContain("stderr"); + expect(names).not.toContain("body"); + expect(names).not.toContain("response_body"); + }); + + it("a sentinel content string never appears in the persisted row", () => { + // AuditRow itself doesn't carry tool body content — the agent loop's + // buildAuditRow() filters that. This test guards the persistence + // layer: even if a future change tried to slip body bytes in via + // argsSummary, they'd only land in the documented column. + logger.record( + baseRow({ + argsSummary: '{"path":"safe.txt"}', + }), + ); + const dump = db.prepare("SELECT * FROM tool_call_log").get() as Record; + const serialized = JSON.stringify(dump); + expect(serialized).not.toContain("THIS_IS_FILE_BODY_THAT_MUST_NOT_LEAK"); + }); + + it("redacted argsSummary survives the round-trip (sanitizer is upstream)", () => { + logger.record( + baseRow({ + argsSummary: '{"url":"https://api.example.com/path?api_key=%5Bredacted%5D&q=hi"}', + }), + ); + const r = db.prepare("SELECT args_summary FROM tool_call_log").get() as { args_summary: string }; + expect(r.args_summary).toContain("%5Bredacted%5D"); + expect(r.args_summary).not.toContain("secret"); + }); +}); + +// ─── Failure resilience ────────────────────────────────────────────── + +describe("SqliteAuditLogger: failure surfacing (loop wraps in safeAudit)", () => { + it("constructor throws if the migration hasn't been applied", () => { + const blankDb = new Database(":memory:"); + // No migration → table missing → prepare() fails fast at construction. + expect(() => new SqliteAuditLogger(blankDb)).toThrow(/no such table/i); + }); + + it("record() throws when the DB has been closed mid-session", () => { + db.close(); + expect(() => logger.record(baseRow())).toThrow(); + // The agent loop's safeAudit() catches this and routes to logger.warn. + // That behavior is covered in agentLoop.test.ts; here we just confirm + // the underlying throw propagates so safeAudit can see it. + }); + + it("record() does NOT corrupt the DB after a single failure", () => { + logger.record(baseRow()); + const goodCount = (db.prepare("SELECT COUNT(*) AS n FROM tool_call_log").get() as { n: number }).n; + expect(goodCount).toBe(1); + + // Force a collision by inserting a row with a duplicate id directly. + const firstId = (db.prepare("SELECT id FROM tool_call_log").get() as { id: string }).id; + expect(() => + db.prepare("INSERT INTO tool_call_log (id, session_id, engine, tool_name) VALUES (?, ?, ?, ?)").run( + firstId, + "s", + "e", + "t", + ), + ).toThrow(/UNIQUE/i); + const stillOne = (db.prepare("SELECT COUNT(*) AS n FROM tool_call_log").get() as { n: number }).n; + expect(stillOne).toBe(1); + logger.record(baseRow({ toolName: "write" })); + const finalCount = (db.prepare("SELECT COUNT(*) AS n FROM tool_call_log").get() as { n: number }).n; + expect(finalCount).toBe(2); + }); +}); + +// ─── Indexes (forensic query speed) ────────────────────────────────── + +describe("SqliteAuditLogger: schema indexes", () => { + it("indexes session_id, engine+tool_name, and error", () => { + const idx = db.prepare("PRAGMA index_list(tool_call_log)").all() as Array<{ name: string }>; + const names = idx.map((i) => i.name); + expect(names).toContain("idx_tool_call_session"); + expect(names).toContain("idx_tool_call_engine_tool"); + expect(names).toContain("idx_tool_call_error"); + }); +}); diff --git a/packages/jimmy/src/engines/agentLoop.ts b/packages/jimmy/src/engines/agentLoop.ts index 52275a7f..8f73caa4 100644 --- a/packages/jimmy/src/engines/agentLoop.ts +++ b/packages/jimmy/src/engines/agentLoop.ts @@ -212,7 +212,10 @@ export async function runAgentLoop(opts: AgentLoopOpts): Promise]>; + + constructor(private readonly db: Database.Database) { + // Prepare once at construction; reuse across every record() call. + this.insertStmt = this.db.prepare(INSERT_SQL); + } + + record(row: AuditRow): void { + this.insertStmt.run({ + id: randomUUID(), + session_id: row.sessionId ?? "unknown", + engine: row.engineName ?? "unknown", + tool_name: row.toolName, + args_summary: row.argsSummary, + duration_ms: row.durationMs, + exit_code: row.exitCode, + http_status: row.httpStatus, + error: row.error, + result_truncated: row.truncated ? 1 : 0, + result_bytes: row.resultBytes, + }); + } +} diff --git a/packages/jimmy/src/gateway/server.ts b/packages/jimmy/src/gateway/server.ts index e44891cb..ee1140b9 100644 --- a/packages/jimmy/src/gateway/server.ts +++ b/packages/jimmy/src/gateway/server.ts @@ -14,6 +14,7 @@ import { ClaudeEngine } from "../engines/claude.js"; import { CodexEngine } from "../engines/codex.js"; import { GeminiEngine } from "../engines/gemini.js"; import { handleApiRequest, resumePendingWebQueueItems, type ApiContext } from "./api.js"; +import type { AuditLogger } from "../engines/audit.js"; import { ensureFilesDir } from "./files.js"; import { initStt } from "../stt/stt.js"; import { startWatchers, stopWatchers, syncSkillSymlinks } from "./watcher.js"; @@ -141,6 +142,17 @@ export async function startGateway( engines.set("codex", codexEngine); engines.set("gemini", geminiEngine); + // Audit sink for HTTP-loop engines. Constructed once and shared across + // ollama/openai — both wrappers receive the same instance, which writes + // one row per tool call into tool_call_log (migrations/0007). The sink + // is constructed only when at least one HTTP engine is configured so + // the import isn't paid for in claude-only deployments. + let httpEnginesAudit: AuditLogger | undefined; + if (config.engines.ollama || config.engines.openai) { + const { SqliteAuditLogger } = await import("../engines/sqliteAuditLogger.js"); + httpEnginesAudit = new SqliteAuditLogger(initDb()); + } + // HTTP-loop engines: register ONLY when configured, so /api/status and // route-resolution errors reflect what's actually available. // @@ -152,7 +164,7 @@ export async function startGateway( if (config.engines.ollama) { try { const { OllamaEngine } = await import("../engines/ollama.js"); - engines.set("ollama", new OllamaEngine(config.engines.ollama)); + engines.set("ollama", new OllamaEngine(config.engines.ollama, { audit: httpEnginesAudit })); logger.info("engine registered: ollama"); } catch (err) { throw new Error( @@ -164,7 +176,7 @@ export async function startGateway( if (config.engines.openai) { try { const { OpenAIEngine } = await import("../engines/openai.js"); - engines.set("openai", new OpenAIEngine(config.engines.openai)); + engines.set("openai", new OpenAIEngine(config.engines.openai, { audit: httpEnginesAudit })); logger.info("engine registered: openai"); } catch (err) { throw new Error(