feat(KB-202): add kb task logs command for viewing agent execution logs

- Add runTaskLogs() with --follow, --limit, and --type filtering flags
- Implement colorized log output (text/thinking/tool/tool_result/tool_error)
- Add file watching support for real-time log streaming (--follow)
- Wire up kb task logs <id> CLI command in bin.ts
- Add comprehensive tests for log filtering, limiting, and follow mode
This commit is contained in:
gsxdsm
2026-03-30 17:40:34 -07:00
parent 045519fa8b
commit 533c4bb3df
4 changed files with 546 additions and 3 deletions

View File

@@ -39,7 +39,7 @@ if (isBunBinary) {
// Dynamic imports so the pi-coding-agent config module sees PI_PACKAGE_DIR
const { runDashboard } = await import("./commands/dashboard.js");
const { runTaskCreate, runTaskList, runTaskMove, runTaskMerge, runTaskUpdate, runTaskLog, runTaskShow, runTaskAttach, runTaskPause, runTaskUnpause, runTaskImportFromGitHub, runTaskDuplicate, runTaskArchive, runTaskUnarchive, runTaskRefine, runTaskPlan, runTaskDelete, runTaskRetry } = await import("./commands/task.js");
const { runTaskCreate, runTaskList, runTaskMove, runTaskMerge, runTaskUpdate, runTaskLog, runTaskLogs, runTaskShow, runTaskAttach, runTaskPause, runTaskUnpause, runTaskImportFromGitHub, runTaskDuplicate, runTaskArchive, runTaskUnarchive, runTaskRefine, runTaskPlan, runTaskDelete, runTaskRetry } = await import("./commands/task.js");
const { runSettingsShow, runSettingsSet } = await import("./commands/settings.js");
const HELP = `
@@ -54,6 +54,8 @@ Usage:
kb task plan [description] [opts] Create task via AI-guided planning
kb task list List all tasks
kb task show <id> Show task details, steps, log
kb task logs <id> [--follow] [--limit <n>] [--type <type>]
Show task agent execution logs
kb task move <id> <col> Move a task to a column
kb task update <id> <step> <status> Update step status (pending|in-progress|done|skipped)
kb task log <id> <message> Add a log entry
@@ -190,6 +192,31 @@ async function main() {
await runTaskLog(id, message);
break;
}
case "logs": {
const id = args[2];
if (!id) { console.error("Usage: kb task logs <id> [--follow] [--limit <n>] [--type <type>]"); process.exit(1); }
// Parse flags
const follow = args.includes("--follow");
let limit: number | undefined;
const limitIdx = args.indexOf("--limit");
if (limitIdx !== -1 && limitIdx + 1 < args.length) {
const parsed = parseInt(args[limitIdx + 1], 10);
if (!isNaN(parsed)) {
limit = parsed;
}
}
let type: string | undefined;
const typeIdx = args.indexOf("--type");
if (typeIdx !== -1 && typeIdx + 1 < args.length) {
type = args[typeIdx + 1];
}
await runTaskLogs(id, { follow, limit, type: type as "text" | "thinking" | "tool" | "tool_result" | "tool_error" | undefined });
break;
}
case "merge": {
const id = args[2];
if (!id) { console.error("Usage: kb task merge <id>"); process.exit(1); }

View File

@@ -5,6 +5,15 @@ vi.mock("node:readline/promises", () => ({
createInterface: vi.fn(),
}));
// Mock node:fs for runTaskLogs tests
vi.mock("node:fs", () => ({
watchFile: vi.fn(),
unwatchFile: vi.fn(),
statSync: vi.fn(),
existsSync: vi.fn(),
readFileSync: vi.fn(),
}));
// Mock @kb/core before importing the module under test
vi.mock("@kb/core", () => {
const COLUMNS = ["triage", "specified", "in-progress", "review", "done"];
@@ -28,7 +37,8 @@ vi.mock("@kb/engine", () => ({ aiMergeTask: vi.fn() }));
import { createInterface } from "node:readline/promises";
import { TaskStore } from "@kb/core";
import { runTaskShow, runTaskCreate, runTaskDuplicate, runTaskRefine, runTaskDelete, runTaskRetry } from "./task.js";
import { watchFile, unwatchFile, statSync, existsSync, readFileSync } from "node:fs";
import { runTaskShow, runTaskCreate, runTaskDuplicate, runTaskRefine, runTaskDelete, runTaskRetry, runTaskLogs, type LogsOptions } from "./task.js";
function makeTask(overrides: Record<string, unknown> = {}) {
return {
@@ -1258,3 +1268,315 @@ describe("runTaskRetry", () => {
await expect(runTaskRetry("KB-001")).rejects.toThrow("Task KB-001 is not failed (status: paused)");
});
});
// --- Logs Tests ---
describe("runTaskLogs", () => {
let logSpy: ReturnType<typeof vi.spyOn>;
let errorSpy: ReturnType<typeof vi.spyOn>;
let mockGetTask: ReturnType<typeof vi.fn>;
let mockGetAgentLogs: ReturnType<typeof vi.fn>;
let mockWatchFile: ReturnType<typeof vi.fn>;
let mockUnwatchFile: ReturnType<typeof vi.fn>;
let mockStatSync: ReturnType<typeof vi.fn>;
let mockExistsSync: ReturnType<typeof vi.fn>;
let mockReadFileSync: ReturnType<typeof vi.fn>;
let sigintHandlers: Array<() => void> = [];
function makeAgentLogEntry(overrides: Record<string, unknown> = {}): import("@kb/core").AgentLogEntry {
return {
timestamp: new Date().toISOString(),
taskId: "KB-001",
text: "Test message",
type: "text" as const,
...overrides,
};
}
beforeEach(() => {
logSpy = vi.spyOn(console, "log").mockImplementation(() => {});
errorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
sigintHandlers = [];
mockGetTask = vi.fn();
mockGetAgentLogs = vi.fn().mockResolvedValue([]);
(TaskStore as unknown as ReturnType<typeof vi.fn>).mockImplementation(() => ({
init: vi.fn(),
getTask: mockGetTask,
getAgentLogs: mockGetAgentLogs,
}));
// Mock fs functions
mockWatchFile = vi.mocked(watchFile);
mockUnwatchFile = vi.mocked(unwatchFile);
mockStatSync = vi.mocked(statSync);
mockExistsSync = vi.mocked(existsSync);
mockReadFileSync = vi.mocked(readFileSync);
mockWatchFile.mockReturnValue(undefined);
mockExistsSync.mockReturnValue(true);
mockStatSync.mockReturnValue({ size: 0 });
// Mock process.on for SIGINT
vi.spyOn(process, "on").mockImplementation((event: string, handler: () => void) => {
if (event === "SIGINT") {
sigintHandlers.push(handler);
}
return process;
});
// Mock process.exit
vi.spyOn(process, "exit").mockImplementation((() => {}) as (code?: number) => never);
});
afterEach(() => {
vi.restoreAllMocks();
});
it("displays logs with various entry types", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([
makeAgentLogEntry({ type: "text", text: "Analyzing code" }),
makeAgentLogEntry({ type: "thinking", text: "Let me think" }),
makeAgentLogEntry({ type: "tool", text: "read", detail: "path/to/file.ts" }),
makeAgentLogEntry({ type: "tool_result", text: "read", detail: "success" }),
makeAgentLogEntry({ type: "tool_error", text: "read", detail: "File not found" }),
]);
await runTaskLogs("KB-001");
expect(mockGetTask).toHaveBeenCalledWith("KB-001");
expect(mockGetAgentLogs).toHaveBeenCalledWith("KB-001");
expect(logSpy).toHaveBeenCalledTimes(5);
// Check that each type is formatted
const calls = logSpy.mock.calls.map((call) => call[0] as string);
expect(calls[0]).toContain("Analyzing code");
expect(calls[1]).toContain("[THINK]");
expect(calls[2]).toContain("[TOOL]");
expect(calls[2]).toContain("path/to/file.ts");
expect(calls[3]).toContain("[RESULT]");
expect(calls[4]).toContain("[ERROR]");
});
it("displays agent role when present", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([
makeAgentLogEntry({ type: "text", text: "Starting execution", agent: "executor" }),
makeAgentLogEntry({ type: "text", text: "Reviewing code", agent: "reviewer" }),
]);
await runTaskLogs("KB-001");
const calls = logSpy.mock.calls.map((call) => call[0] as string);
expect(calls[0]).toContain("[EXECUTOR]");
expect(calls[1]).toContain("[REVIEWER]");
});
it("shows 'no logs found' message when logs are empty", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([]);
await runTaskLogs("KB-001");
expect(logSpy).toHaveBeenCalledWith("No agent logs found for KB-001");
});
it("exits with error when task not found", async () => {
mockGetTask.mockRejectedValueOnce(new Error("Task not found"));
const exitSpy = vi.spyOn(process, "exit").mockImplementation((() => {}) as (code?: number) => never);
await runTaskLogs("KB-999");
expect(errorSpy).toHaveBeenCalledWith("Task KB-999 not found");
expect(exitSpy).toHaveBeenCalledWith(1);
exitSpy.mockRestore();
});
it("respects --limit flag", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce(
Array.from({ length: 200 }, (_, i) => makeAgentLogEntry({ text: `Line ${i + 1}` }))
);
await runTaskLogs("KB-001", { limit: 50 });
// Should only show 50 entries (default is 100, we specified 50)
expect(logSpy).toHaveBeenCalledTimes(50);
// Check that we got the last 50 entries
const calls = logSpy.mock.calls.map((call) => call[0] as string);
expect(calls[0]).toContain("Line 151");
expect(calls[49]).toContain("Line 200");
});
it("enforces max limit of 1000", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce(
Array.from({ length: 1500 }, (_, i) => makeAgentLogEntry({ text: `Line ${i + 1}` }))
);
await runTaskLogs("KB-001", { limit: 2000 }); // Request 2000, should be capped at 1000
expect(logSpy).toHaveBeenCalledTimes(1000);
});
it("filters by --type flag", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([
makeAgentLogEntry({ type: "text", text: "Text 1" }),
makeAgentLogEntry({ type: "tool", text: "tool1" }),
makeAgentLogEntry({ type: "text", text: "Text 2" }),
makeAgentLogEntry({ type: "tool", text: "tool2" }),
makeAgentLogEntry({ type: "thinking", text: "Think 1" }),
]);
await runTaskLogs("KB-001", { type: "text" });
// Should only show 2 text entries
expect(logSpy).toHaveBeenCalledTimes(2);
const calls = logSpy.mock.calls.map((call) => call[0] as string);
expect(calls[0]).toContain("Text 1");
expect(calls[1]).toContain("Text 2");
});
it("filters by type with --limit combined", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
// Create 50 tool entries interspersed with text entries
const entries: import("@kb/core").AgentLogEntry[] = [];
for (let i = 0; i < 100; i++) {
entries.push(makeAgentLogEntry({
type: i % 2 === 0 ? "tool" : "text",
text: `Entry ${i + 1}`
}));
}
mockGetAgentLogs.mockResolvedValueOnce(entries);
await runTaskLogs("KB-001", { type: "tool", limit: 10 });
// Should show 10 tool entries (the last 10 tool entries: #50, #52, #54, #56, #58, #60, #62, #64, #66, #68... wait, that's not right)
// Actually it's #50, #52, #54, #56, #58, #60, #62, #64, #66, #68... no wait, tool entries are at indices 0, 2, 4...
// So last 10 tool entries would be indices 80, 82, 84, 86, 88, 90, 92, 94, 96, 98
// Which correspond to Entry 81, 83, 85, 87, 89, 91, 93, 95, 97, 99
expect(logSpy).toHaveBeenCalledTimes(10);
});
it("calls watchFile when --follow is set", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([
makeAgentLogEntry({ type: "text", text: "Existing log" }),
]);
// Don't await - follow mode keeps the promise pending
const logsPromise = runTaskLogs("KB-001", { follow: true });
// Give a tick for the async operations to start
await new Promise((resolve) => setTimeout(resolve, 10));
expect(mockWatchFile).toHaveBeenCalled();
expect(process.on).toHaveBeenCalledWith("SIGINT", expect.any(Function));
// Trigger SIGINT to clean up
sigintHandlers.forEach((handler) => handler());
});
it("calls unwatchFile in SIGINT handler", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([]);
// Start follow mode
runTaskLogs("KB-001", { follow: true });
await new Promise((resolve) => setTimeout(resolve, 10));
// Trigger SIGINT
sigintHandlers.forEach((handler) => handler());
expect(mockUnwatchFile).toHaveBeenCalled();
});
it("prints waiting message in follow mode when no log file exists", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([]);
mockExistsSync.mockReturnValue(false);
runTaskLogs("KB-001", { follow: true });
await new Promise((resolve) => setTimeout(resolve, 10));
const waitingMessage = logSpy.mock.calls.find(
(call) => typeof call[0] === "string" && call[0].includes("Waiting for log file")
);
expect(waitingMessage).toBeDefined();
// Clean up
sigintHandlers.forEach((handler) => handler());
});
it("reads and prints new entries in follow mode", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([
makeAgentLogEntry({ type: "text", text: "Initial" }),
]);
// Mock file to exist with size 0 initially (no content read yet)
mockStatSync.mockReturnValue({ size: 0 });
runTaskLogs("KB-001", { follow: true });
await new Promise((resolve) => setTimeout(resolve, 10));
// Get the watchFile callback
const watchCallback = mockWatchFile.mock.calls[0][2] as () => void;
// Simulate file growing with new content
mockStatSync.mockReturnValueOnce({ size: 100 });
mockReadFileSync.mockReturnValueOnce(JSON.stringify(makeAgentLogEntry({ type: "text", text: "New entry" })) + "\n");
// Trigger the watch callback
watchCallback();
// Check that new entry was printed
const newEntry = logSpy.mock.calls.find(
(call) => typeof call[0] === "string" && call[0].includes("New entry")
);
expect(newEntry).toBeDefined();
// Clean up
sigintHandlers.forEach((handler) => handler());
});
it("applies type filter in follow mode", async () => {
mockGetTask.mockResolvedValueOnce(makeTask({ id: "KB-001" }));
mockGetAgentLogs.mockResolvedValueOnce([]);
mockStatSync.mockReturnValue({ size: 0 });
runTaskLogs("KB-001", { follow: true, type: "tool" });
await new Promise((resolve) => setTimeout(resolve, 10));
const watchCallback = mockWatchFile.mock.calls[0][2] as () => void;
// Simulate new content
mockStatSync.mockReturnValueOnce({ size: 200 });
mockReadFileSync.mockReturnValueOnce(
JSON.stringify(makeAgentLogEntry({ type: "text", text: "Text entry" })) + "\n" +
JSON.stringify(makeAgentLogEntry({ type: "tool", text: "Tool entry" })) + "\n"
);
watchCallback();
// Should only print the tool entry
const toolEntry = logSpy.mock.calls.find(
(call) => typeof call[0] === "string" && call[0].includes("Tool entry")
);
expect(toolEntry).toBeDefined();
const textEntry = logSpy.mock.calls.find(
(call) => typeof call[0] === "string" && call[0].includes("Text entry")
);
expect(textEntry).toBeUndefined();
// Clean up
sigintHandlers.forEach((handler) => handler());
});
});

View File

@@ -1,8 +1,10 @@
import { TaskStore, COLUMNS, COLUMN_LABELS, type Column, type MergeResult, type StepStatus } from "@kb/core";
import { TaskStore, COLUMNS, COLUMN_LABELS, type Column, type MergeResult, type StepStatus, type AgentLogType, type AgentLogEntry } from "@kb/core";
import { aiMergeTask } from "@kb/engine";
import { createInterface } from "node:readline/promises";
import type { PlanningQuestion, PlanningSummary } from "@kb/core";
import { createSession, submitResponse, RateLimitError, SessionNotFoundError, InvalidSessionStateError } from "@kb/dashboard/planning";
import { watchFile, unwatchFile, statSync, existsSync, readFileSync } from "node:fs";
import { join } from "node:path";
const STEP_STATUSES: StepStatus[] = ["pending", "in-progress", "done", "skipped"];
@@ -136,6 +138,184 @@ export async function runTaskLog(id: string, message: string, outcome?: string)
console.log();
}
export interface LogsOptions {
follow?: boolean;
limit?: number;
type?: AgentLogType;
}
// ANSI color codes for terminal output
const ANSI = {
reset: "\x1b[0m",
dim: "\x1b[2m",
red: "\x1b[31m",
gray: "\x1b[90m",
};
/**
* Format a timestamp for display (locale time string)
*/
function formatTimestamp(timestamp: string): string {
return new Date(timestamp).toLocaleTimeString();
}
/**
* Format a single agent log entry for display
*/
function formatLogEntry(entry: AgentLogEntry): string {
const ts = formatTimestamp(entry.timestamp);
const agent = entry.agent ? `[${entry.agent.toUpperCase()}] ` : "";
switch (entry.type) {
case "text":
return ` ${ts} ${agent}${entry.text}`;
case "thinking":
return `${ANSI.dim}${ANSI.gray} ${ts} ${agent}[THINK] ${entry.text}${ANSI.reset}`;
case "tool":
return ` ${ts} ${agent}[TOOL] ${entry.text}${entry.detail ? ` (${entry.detail})` : ""}`;
case "tool_result":
return ` ${ts} ${agent}[RESULT] ${entry.text}${entry.detail ? ` (${entry.detail})` : ""}`;
case "tool_error":
return `${ANSI.red} ${ts} ${agent}[ERROR] ${entry.text}${entry.detail ? ` (${entry.detail})` : ""}${ANSI.reset}`;
default:
return ` ${ts} ${agent}${entry.text}`;
}
}
/**
* Print log entries to console
*/
function printEntries(entries: AgentLogEntry[]): void {
for (const entry of entries) {
console.log(formatLogEntry(entry));
}
}
/**
* Filter and limit entries based on options
*/
function filterEntries(entries: AgentLogEntry[], options: LogsOptions): AgentLogEntry[] {
let result = entries;
// Filter by type if specified
if (options.type) {
result = result.filter((e) => e.type === options.type);
}
// Apply limit (default 100, max 1000)
const limit = Math.min(options.limit ?? 100, 1000);
if (result.length > limit) {
result = result.slice(-limit);
}
return result;
}
export async function runTaskLogs(id: string, options: LogsOptions = {}) {
const store = await getStore();
// Verify task exists
try {
await store.getTask(id);
} catch {
console.error(`Task ${id} not found`);
process.exit(1);
}
// Get agent logs
const entries = await store.getAgentLogs(id);
if (entries.length === 0 && !options.follow) {
console.log(`No agent logs found for ${id}`);
return;
}
// Print existing entries (filtered)
const filteredEntries = filterEntries(entries, options);
printEntries(filteredEntries);
// Follow mode: watch for new entries
if (options.follow) {
const cwd = process.cwd();
const logPath = join(cwd, ".kb", "tasks", id, "agent.log");
if (!existsSync(logPath)) {
console.log(`\n Waiting for log file to be created...`);
}
let lastPosition = 0;
let lastSize = 0;
// Try to get initial file size
try {
const stats = statSync(logPath);
lastSize = stats.size;
lastPosition = lastSize;
} catch {
// File doesn't exist yet, will watch for creation
}
// Track if we're shutting down
let isShuttingDown = false;
// Set up SIGINT handler for clean exit
const sigintHandler = () => {
if (isShuttingDown) return;
isShuttingDown = true;
unwatchFile(logPath);
console.log("\n (stopped following logs)");
process.exit(0);
};
process.on("SIGINT", sigintHandler);
// Start watching the file
watchFile(logPath, { interval: 1000 }, () => {
if (isShuttingDown) return;
try {
const stats = statSync(logPath);
// File was truncated or recreated
if (stats.size < lastPosition) {
lastPosition = 0;
}
// New content available
if (stats.size > lastPosition) {
const content = readFileSync(logPath, "utf-8");
const lines = content.slice(lastPosition).split("\n");
for (const line of lines) {
if (!line.trim()) continue;
try {
const entry = JSON.parse(line) as AgentLogEntry;
// Apply type filter if specified
if (!options.type || entry.type === options.type) {
console.log(formatLogEntry(entry));
}
} catch {
// Skip malformed lines
}
}
lastPosition = stats.size;
}
lastSize = stats.size;
} catch {
// File may have been deleted, ignore
}
});
// Keep process alive
await new Promise(() => {
// Infinite wait - SIGINT handler will exit
});
}
}
export async function runTaskShow(id: string) {
const store = await getStore();
const task = await store.getTask(id);
@@ -339,6 +519,15 @@ export async function runTaskArchive(id: string) {
console.log();
}
export async function runTaskUnarchive(id: string) {
const store = await getStore();
const task = await store.unarchiveTask(id);
console.log();
console.log(` ✓ Unarchived ${task.id} → ${COLUMN_LABELS[task.column]}`);
console.log();
}
export async function runTaskRetry(id: string) {
const store = await getStore();