feat(KB-123): add agent role tracking and expanded logging to agent system

- Extend AgentLogEntry with agent field and new event types (thinking, tool_end)
- Expand AgentLogger with thinking, tool_end callbacks and agent role support
- Wire new logging callbacks in createKbAgent and all agent call-sites (executor, merger, reviewer, triage, pi)
- Update AgentLogViewer with agent role badges and rendering for new entry types
- Export AgentRole and AgentLogType from core package and add tests for new functionality
This commit is contained in:
Dustin Byrne
2026-03-27 01:19:42 -04:00
parent 0d920e20ef
commit 948928d258
14 changed files with 474 additions and 66 deletions

View File

@@ -75,7 +75,7 @@ describe("AgentLogger", () => {
logger.onText("worldextra");
// Allow async flush
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "helloworldextra", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "helloworldextra", "text", undefined, undefined);
});
it("flushes on timer when under size threshold", async () => {
@@ -91,7 +91,7 @@ describe("AgentLogger", () => {
expect(store.appendAgentLog).not.toHaveBeenCalled();
await vi.advanceTimersByTimeAsync(500);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-002", "small", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-002", "small", "text", undefined, undefined);
});
it("flushes text before logging tool start", async () => {
@@ -110,9 +110,9 @@ describe("AgentLogger", () => {
const calls = (store.appendAgentLog as ReturnType<typeof vi.fn>).mock.calls;
expect(calls.length).toBe(2);
// Text flushed first
expect(calls[0]).toEqual(["KB-003", "pending text", "text"]);
expect(calls[0]).toEqual(["KB-003", "pending text", "text", undefined, undefined]);
// Tool logged second with detail
expect(calls[1]).toEqual(["KB-003", "Bash", "tool", "ls"]);
expect(calls[1]).toEqual(["KB-003", "Bash", "tool", "ls", undefined]);
});
it("logs tool detail using summarizeToolArgs", async () => {
@@ -122,7 +122,7 @@ describe("AgentLogger", () => {
logger.onToolStart("Read", { path: "src/index.ts" });
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-004", "Read", "tool", "src/index.ts");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-004", "Read", "tool", "src/index.ts", undefined);
});
it("logs tool with undefined detail for unknown args", async () => {
@@ -132,7 +132,7 @@ describe("AgentLogger", () => {
logger.onToolStart("task_done", { count: 42 });
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-005", "task_done", "tool", undefined);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-005", "task_done", "tool", undefined, undefined);
});
it("flush() clears timer and writes remaining text", async () => {
@@ -147,7 +147,7 @@ describe("AgentLogger", () => {
logger.onText("remaining");
await logger.flush();
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-006", "remaining", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-006", "remaining", "text", undefined, undefined);
});
it("flush() is safe to call when buffer is empty", async () => {
@@ -193,6 +193,155 @@ describe("AgentLogger", () => {
// All text should be flushed in a single call
expect(store.appendAgentLog).toHaveBeenCalledTimes(1);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-009", "abc", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-009", "abc", "text", undefined, undefined);
});
// ── Agent field propagation ──────────────────────────────────────
it("passes agent field through to all appendAgentLog calls", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-010",
agent: "executor",
flushSizeBytes: 5,
});
// Text flush
logger.onText("hello world");
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-010", "hello world", "text", undefined, "executor");
// Tool start
(store.appendAgentLog as ReturnType<typeof vi.fn>).mockClear();
logger.onToolStart("Bash", { command: "ls" });
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-010", "Bash", "tool", "ls", "executor");
});
// ── Thinking buffer/flush ────────────────────────────────────────
it("buffers thinking deltas and flushes on timer", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-011",
agent: "executor",
flushSizeBytes: 1024,
flushIntervalMs: 500,
});
logger.onThinking("thought 1 ");
logger.onThinking("thought 2");
expect(store.appendAgentLog).not.toHaveBeenCalled();
await vi.advanceTimersByTimeAsync(500);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-011", "thought 1 thought 2", "thinking", undefined, "executor");
});
it("flushes thinking on size threshold", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-012",
agent: "triage",
flushSizeBytes: 10,
});
logger.onThinking("short");
expect(store.appendAgentLog).not.toHaveBeenCalled();
logger.onThinking("enough to flush");
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-012", "shortenough to flush", "thinking", undefined, "triage");
});
it("flushes thinking buffer on flush()", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-013",
agent: "reviewer",
flushSizeBytes: 1024,
});
logger.onThinking("remaining thinking");
await logger.flush();
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-013", "remaining thinking", "thinking", undefined, "reviewer");
});
it("flushes thinking buffer before tool start", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-014",
agent: "executor",
flushSizeBytes: 1024,
});
logger.onThinking("pre-tool thought");
logger.onToolStart("Read", { path: "file.ts" });
await vi.advanceTimersByTimeAsync(0);
const calls = (store.appendAgentLog as ReturnType<typeof vi.fn>).mock.calls;
expect(calls[0]).toEqual(["KB-014", "pre-tool thought", "thinking", undefined, "executor"]);
expect(calls[1]).toEqual(["KB-014", "Read", "tool", "file.ts", "executor"]);
});
// ── onToolEnd ────────────────────────────────────────────────────
it("logs tool_result on successful tool end", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-015",
agent: "executor",
});
logger.onToolEnd("Bash", false, "command output");
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-015", "Bash", "tool_result", "command output", "executor");
});
it("logs tool_error on failed tool end", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-016",
agent: "executor",
});
logger.onToolEnd("Read", true, "file not found");
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-016", "Read", "tool_error", "file not found", "executor");
});
it("truncates long tool results to 500 chars", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-017",
agent: "executor",
});
const longResult = "x".repeat(600);
logger.onToolEnd("Bash", false, longResult);
await vi.advanceTimersByTimeAsync(0);
const call = (store.appendAgentLog as ReturnType<typeof vi.fn>).mock.calls[0];
expect(call[3]).toBe("x".repeat(500) + "…");
});
it("handles undefined result in onToolEnd", async () => {
const store = createMockStore();
const logger = new AgentLogger({
store,
taskId: "KB-018",
agent: "merger",
});
logger.onToolEnd("Bash", false);
await vi.advanceTimersByTimeAsync(0);
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-018", "Bash", "tool_result", undefined, "merger");
});
});

View File

@@ -1,4 +1,4 @@
import type { TaskStore } from "@kb/core";
import type { TaskStore, AgentRole } from "@kb/core";
/** Default byte threshold before an automatic flush. */
const FLUSH_SIZE_BYTES = 1024;
@@ -40,6 +40,8 @@ export interface AgentLoggerOptions {
store: TaskStore;
/** The task ID this logger is associated with. */
taskId: string;
/** Which agent role is producing log entries (persisted on every entry). */
agent?: AgentRole;
/** Optional callback invoked alongside text logging (e.g. for SSE streaming). */
onAgentText?: (taskId: string, delta: string) => void;
/** Optional callback invoked alongside tool logging (e.g. for SSE streaming). */
@@ -77,17 +79,21 @@ export interface AgentLoggerOptions {
*/
export class AgentLogger {
private textBuffer = "";
private thinkingBuffer = "";
private flushTimer: ReturnType<typeof setTimeout> | null = null;
private thinkingFlushTimer: ReturnType<typeof setTimeout> | null = null;
private readonly flushSizeBytes: number;
private readonly flushIntervalMs: number;
private readonly store: TaskStore;
private readonly taskId: string;
private readonly agent?: AgentRole;
private readonly externalTextCb?: (taskId: string, delta: string) => void;
private readonly externalToolCb?: (taskId: string, toolName: string) => void;
constructor(options: AgentLoggerOptions) {
this.store = options.store;
this.taskId = options.taskId;
this.agent = options.agent;
this.externalTextCb = options.onAgentText;
this.externalToolCb = options.onAgentTool;
this.flushSizeBytes = options.flushSizeBytes ?? FLUSH_SIZE_BYTES;
@@ -96,6 +102,8 @@ export class AgentLogger {
// Bind callbacks so they can be passed directly as function references
this.onText = this.onText.bind(this);
this.onToolStart = this.onToolStart.bind(this);
this.onThinking = this.onThinking.bind(this);
this.onToolEnd = this.onToolEnd.bind(this);
}
/**
@@ -113,26 +121,62 @@ export class AgentLogger {
}
}
/**
* Callback for thinking block deltas. Buffers and flushes thinking text
* as `type: "thinking"` entries, using the same size/timer pattern as `onText`.
*/
onThinking(delta: string): void {
this.thinkingBuffer += delta;
if (this.thinkingBuffer.length >= this.flushSizeBytes) {
if (this.thinkingFlushTimer) { clearTimeout(this.thinkingFlushTimer); this.thinkingFlushTimer = null; }
this.flushThinkingBuffer();
} else {
this.scheduleThinkingFlush();
}
}
/**
* Callback for tool invocation starts. Flushes pending text, then logs the
* tool name with a detail summary. Compatible with `AgentOptions.onToolStart`.
*/
onToolStart(name: string, args?: Record<string, unknown>): void {
this.externalToolCb?.(this.taskId, name);
// Flush any pending text before recording the tool entry
// Flush any pending text/thinking before recording the tool entry
if (this.flushTimer) { clearTimeout(this.flushTimer); this.flushTimer = null; }
this.flushTextBuffer();
if (this.thinkingFlushTimer) { clearTimeout(this.thinkingFlushTimer); this.thinkingFlushTimer = null; }
this.flushThinkingBuffer();
const detail = summarizeToolArgs(name, args);
this.store.appendAgentLog(this.taskId, name, "tool", detail).catch(() => {});
this.store.appendAgentLog(this.taskId, name, "tool", detail, this.agent).catch(() => {});
}
/**
* Flush any remaining buffered text and clear the timer.
* Callback for tool execution completion. Logs as `type: "tool_result"` on success
* or `type: "tool_error"` on failure.
*
* @param name - The tool name
* @param isError - Whether the tool execution resulted in an error
* @param result - Optional result value (truncated for persistence)
*/
onToolEnd(name: string, isError: boolean, result?: unknown): void {
const type = isError ? "tool_error" : "tool_result";
let detail: string | undefined;
if (result !== undefined && result !== null) {
const str = typeof result === "string" ? result : JSON.stringify(result);
detail = str.length > 500 ? str.slice(0, 500) + "…" : str;
}
this.store.appendAgentLog(this.taskId, name, type, detail, this.agent).catch(() => {});
}
/**
* Flush any remaining buffered text/thinking and clear timers.
* Call this in a `finally` block before disposing the agent session.
*/
async flush(): Promise<void> {
if (this.flushTimer) { clearTimeout(this.flushTimer); this.flushTimer = null; }
if (this.thinkingFlushTimer) { clearTimeout(this.thinkingFlushTimer); this.thinkingFlushTimer = null; }
await this.flushTextBuffer();
await this.flushThinkingBuffer();
}
// ── Internal helpers ───────────────────────────────────────────────
@@ -141,7 +185,16 @@ export class AgentLogger {
if (this.textBuffer.length === 0) return Promise.resolve();
const chunk = this.textBuffer;
this.textBuffer = "";
return this.store.appendAgentLog(this.taskId, chunk, "text").catch(() => {
return this.store.appendAgentLog(this.taskId, chunk, "text", undefined, this.agent).catch(() => {
/* best-effort persistence */
});
}
private flushThinkingBuffer(): Promise<void> {
if (this.thinkingBuffer.length === 0) return Promise.resolve();
const chunk = this.thinkingBuffer;
this.thinkingBuffer = "";
return this.store.appendAgentLog(this.taskId, chunk, "thinking", undefined, this.agent).catch(() => {
/* best-effort persistence */
});
}
@@ -153,4 +206,12 @@ export class AgentLogger {
this.flushTextBuffer();
}, this.flushIntervalMs);
}
private scheduleThinkingFlush(): void {
if (this.thinkingFlushTimer) return;
this.thinkingFlushTimer = setTimeout(() => {
this.thinkingFlushTimer = null;
this.flushThinkingBuffer();
}, this.flushIntervalMs);
}
}

View File

@@ -338,6 +338,7 @@ export class TaskExecutor {
const agentLogger = new AgentLogger({
store: this.store,
taskId: task.id,
agent: "executor",
onAgentText: this.options.onAgentText,
onAgentTool: this.options.onAgentTool,
});
@@ -349,7 +350,9 @@ export class TaskExecutor {
tools: "coding",
customTools,
onText: agentLogger.onText,
onThinking: agentLogger.onThinking,
onToolStart: agentLogger.onToolStart,
onToolEnd: agentLogger.onToolEnd,
defaultProvider: settings.defaultProvider,
defaultModelId: settings.defaultModelId,
defaultThinkingLevel: settings.defaultThinkingLevel,
@@ -544,6 +547,8 @@ export class TaskExecutor {
defaultProvider: settings.defaultProvider,
defaultModelId: settings.defaultModelId,
defaultThinkingLevel: settings.defaultThinkingLevel,
store,
taskId,
},
);

View File

@@ -369,7 +369,7 @@ describe("aiMergeTask — agent log persistence", () => {
await aiMergeTask(store, "/tmp/root", "KB-050");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-050", "Hello merge", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-050", "Hello merge", "text", undefined, "merger");
});
it("logs tool invocations to store.appendAgentLog", async () => {
@@ -395,7 +395,7 @@ describe("aiMergeTask — agent log persistence", () => {
await aiMergeTask(store, "/tmp/root", "KB-050");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-050", "Bash", "tool", "git status");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-050", "Bash", "tool", "git status", "merger");
});
it("still fires onAgentText callback alongside logging", async () => {
@@ -423,6 +423,6 @@ describe("aiMergeTask — agent log persistence", () => {
await aiMergeTask(store, "/tmp/root", "KB-050", { onAgentText });
expect(onAgentText).toHaveBeenCalledWith("hi");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-050", "hi", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-050", "hi", "text", undefined, "merger");
});
});

View File

@@ -221,6 +221,7 @@ export async function aiMergeTask(
const agentLogger = new AgentLogger({
store,
taskId,
agent: "merger",
// Merger callbacks don't include taskId — wrap to match AgentLogger signature
onAgentText: options.onAgentText
? (_id, delta) => options.onAgentText!(delta)
@@ -236,7 +237,9 @@ export async function aiMergeTask(
systemPrompt: buildMergeSystemPrompt(includeTaskId),
tools: "coding",
onText: agentLogger.onText,
onThinking: agentLogger.onThinking,
onToolStart: agentLogger.onToolStart,
onToolEnd: agentLogger.onToolEnd,
defaultProvider: settings.defaultProvider,
defaultModelId: settings.defaultModelId,
defaultThinkingLevel: settings.defaultThinkingLevel,

View File

@@ -28,8 +28,9 @@ export interface AgentOptions {
tools?: "coding" | "readonly";
customTools?: ToolDefinition[];
onText?: (delta: string) => void;
onThinking?: (delta: string) => void;
onToolStart?: (name: string, args?: Record<string, unknown>) => void;
onToolEnd?: (name: string, isError: boolean) => void;
onToolEnd?: (name: string, isError: boolean, result?: unknown) => void;
/** Default model provider (e.g. "anthropic"). Used with `defaultModelId` to select a specific model. */
defaultProvider?: string;
/** Default model ID within the provider (e.g. "claude-sonnet-4-5"). Used with `defaultProvider`. */
@@ -88,14 +89,19 @@ export async function createKbAgent(options: AgentOptions): Promise<AgentResult>
// Wire up event listeners
session.subscribe((event) => {
if (event.type === "message_update" && event.assistantMessageEvent.type === "text_delta") {
options.onText?.(event.assistantMessageEvent.delta);
if (event.type === "message_update") {
const msgEvent = event.assistantMessageEvent;
if (msgEvent.type === "text_delta") {
options.onText?.(msgEvent.delta);
} else if (msgEvent.type === "thinking_delta") {
options.onThinking?.(msgEvent.delta);
}
}
if (event.type === "tool_execution_start") {
options.onToolStart?.(event.toolName, event.args as Record<string, unknown> | undefined);
}
if (event.type === "tool_execution_end") {
options.onToolEnd?.(event.toolName, event.isError);
options.onToolEnd?.(event.toolName, event.isError, event.result);
}
});

View File

@@ -8,7 +8,9 @@
* - Verdict + feedback is returned to the worker
*/
import type { TaskStore } from "@kb/core";
import { createKbAgent } from "./pi.js";
import { AgentLogger } from "./agent-logger.js";
const REVIEWER_SYSTEM_PROMPT = `You are an independent code and plan reviewer.
@@ -117,6 +119,10 @@ export interface ReviewOptions {
defaultModelId?: string;
/** Default thinking effort level for the reviewer agent session. */
defaultThinkingLevel?: string;
/** Task store for persisting agent log entries. When provided with `taskId`, enables full conversation logging. */
store?: TaskStore;
/** Task ID for agent log persistence. Required alongside `store`. */
taskId?: string;
}
/**
@@ -137,12 +143,27 @@ export async function reviewStep(
taskId, stepNumber, stepName, reviewType, promptContent, cwd, baseline,
);
// Create AgentLogger for reviewer if store is available
const agentLogger = options.store && options.taskId
? new AgentLogger({
store: options.store,
taskId: options.taskId,
agent: "reviewer",
onAgentText: options.onText
? (_id, delta) => options.onText!(delta)
: undefined,
})
: null;
// Spawn a reviewer agent with read-only tools
const { session } = await createKbAgent({
cwd,
systemPrompt: REVIEWER_SYSTEM_PROMPT,
tools: "readonly",
onText: (delta) => options.onText?.(delta),
onText: agentLogger ? agentLogger.onText : (delta) => options.onText?.(delta),
onThinking: agentLogger?.onThinking,
onToolStart: agentLogger?.onToolStart,
onToolEnd: agentLogger?.onToolEnd,
defaultProvider: options.defaultProvider,
defaultModelId: options.defaultModelId,
defaultThinkingLevel: options.defaultThinkingLevel,
@@ -150,7 +171,7 @@ export async function reviewStep(
let reviewText = "";
// Capture the reviewer's full text output
// Capture the reviewer's full text output (still needed for verdict extraction)
session.subscribe((event) => {
if (event.type === "message_update" && event.assistantMessageEvent.type === "text_delta") {
reviewText += event.assistantMessageEvent.delta;
@@ -160,6 +181,7 @@ export async function reviewStep(
try {
await session.prompt(request);
} finally {
if (agentLogger) await agentLogger.flush();
session.dispose();
}

View File

@@ -528,7 +528,7 @@ describe("TriageProcessor agent log persistence", () => {
});
// Text buffer is flushed in finally block
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "Hello world", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "Hello world", "text", undefined, "triage");
});
it("logs tool invocations to store.appendAgentLog", async () => {
@@ -561,7 +561,7 @@ describe("TriageProcessor agent log persistence", () => {
updatedAt: new Date().toISOString(),
});
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "Read", "tool", "foo.ts");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "Read", "tool", "foo.ts", "triage");
});
it("still fires onAgentText callback alongside logging", async () => {
@@ -596,6 +596,6 @@ describe("TriageProcessor agent log persistence", () => {
});
expect(onAgentText).toHaveBeenCalledWith("KB-001", "hi");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "hi", "text");
expect(store.appendAgentLog).toHaveBeenCalledWith("KB-001", "hi", "text", undefined, "triage");
});
});

View File

@@ -256,6 +256,7 @@ export class TriageProcessor {
const agentLogger = new AgentLogger({
store: this.store,
taskId: task.id,
agent: "triage",
onAgentText: this.options.onAgentText
? (id, delta) => this.options.onAgentText!(id, delta)
: undefined,
@@ -270,7 +271,9 @@ export class TriageProcessor {
tools: "coding",
customTools: this.createTriageTools(),
onText: agentLogger.onText,
onThinking: agentLogger.onThinking,
onToolStart: agentLogger.onToolStart,
onToolEnd: agentLogger.onToolEnd,
defaultProvider: settings.defaultProvider,
defaultModelId: settings.defaultModelId,
defaultThinkingLevel: settings.defaultThinkingLevel,