fix(FN-3175): reduce dashboard log stalls

This commit is contained in:
gsxdsm
2026-05-02 08:05:33 -07:00
parent 207d9d2524
commit d787a16a79
16 changed files with 209 additions and 43 deletions

View File

@@ -57,7 +57,7 @@ describe("Database", () => {
const journalSizeLimit = db.prepare("PRAGMA journal_size_limit").get() as { journal_size_limit: number };
expect(synchronous.synchronous).toBe(1); // NORMAL
expect(autoCheckpoint.wal_autocheckpoint).toBe(100);
expect(autoCheckpoint.wal_autocheckpoint).toBe(1000);
expect(journalSizeLimit.journal_size_limit).toBe(4_194_304);
});
@@ -267,6 +267,13 @@ describe("Database", () => {
expect(typeof result.log).toBe("number");
expect(typeof result.checkpointed).toBe("number");
});
it("supports explicit truncate checkpoints when requested", () => {
const result = db.walCheckpoint("TRUNCATE");
expect(result).toHaveProperty("busy");
expect(result).toHaveProperty("log");
expect(result).toHaveProperty("checkpointed");
});
});
describe("transactions", () => {

View File

@@ -4158,6 +4158,25 @@ Task with acceptance criteria
expect(events[1]).toMatchObject({ text: "tool", type: "tool", detail: "read file", agent: "executor" });
});
it("truncates oversized tool detail before persisting and emitting", async () => {
const task = await createTestTask();
const events: any[] = [];
const oversizedDetail = "X".repeat(5000);
const truncationMarker = "[tool output truncated to keep dashboard log views responsive]";
store.on("agent:log", (entry) => events.push(entry));
await store.appendAgentLogBatch([
{ taskId: task.id, text: "Bash", type: "tool_result", detail: oversizedDetail, agent: "executor" },
]);
const logs = await store.getAgentLogs(task.id);
expect(logs).toHaveLength(1);
expect(logs[0].detail).toContain(truncationMarker);
expect(logs[0].detail!.match(/\[tool output truncated to keep dashboard log views responsive\]/g)).toHaveLength(1);
expect(logs[0].detail!.length).toBeLessThan(oversizedDetail.length);
expect(events[0].detail).toBe(logs[0].detail);
});
it("appendAgentLogBatch with empty entries is a no-op", async () => {
const task = await createTestTask();
@@ -4304,6 +4323,28 @@ Task with acceptance criteria
expect(logs[0].detail!.length).toBe(longDetail.length);
});
it("clips oversized historical tool detail at read time", async () => {
const task = await createTestTask();
const oversizedDetail = "Y".repeat(7000);
const truncationMarker = "[tool output truncated to keep dashboard log views responsive]";
insertLogEntryWithTimestamp(
store,
task.id,
"Bash",
"tool_result",
"2026-04-24T12:00:00.000Z",
oversizedDetail,
"executor",
);
const logs = await store.getAgentLogs(task.id);
expect(logs).toHaveLength(1);
expect(logs[0].detail).toContain(truncationMarker);
expect(logs[0].detail!.match(/\[tool output truncated to keep dashboard log views responsive\]/g)).toHaveLength(1);
expect(logs[0].detail!.length).toBeLessThan(oversizedDetail.length);
});
it("appendAgentLog persists and reads back the agent field", async () => {
const task = await createTestTask();

View File

@@ -754,8 +754,9 @@ export class Database {
this.db.exec("PRAGMA busy_timeout = 5000");
// In WAL mode NORMAL is nearly as durable as FULL with much lower fsync cost.
this.db.exec("PRAGMA synchronous = NORMAL");
// Checkpoint aggressively to avoid large WAL growth under bursty writes.
this.db.exec("PRAGMA wal_autocheckpoint = 100");
// Let WAL grow to roughly the journal size limit before auto-checkpointing.
// This avoids frequent synchronous checkpoints on log-heavy workloads.
this.db.exec("PRAGMA wal_autocheckpoint = 1000");
// Bound WAL growth between checkpoints/maintenance cycles.
this.db.exec("PRAGMA journal_size_limit = 4194304");
} else {
@@ -2334,11 +2335,15 @@ export class Database {
}
/**
* Run a WAL checkpoint to truncate the WAL file and reclaim disk space.
* Safe to call periodically. Returns checkpoint stats.
* Run a WAL checkpoint and return checkpoint stats.
*
* TRUNCATE remains the default so explicit maintenance/compaction calls keep
* reclaiming disk space as before. Live engine maintenance should opt into
* PASSIVE to avoid forcing a blocking truncate on the shared event loop
* while tasks are actively writing logs.
*/
walCheckpoint(): { busy: number; log: number; checkpointed: number } {
const row = this.db.prepare("PRAGMA wal_checkpoint(TRUNCATE)").get() as
walCheckpoint(mode: "PASSIVE" | "TRUNCATE" = "TRUNCATE"): { busy: number; log: number; checkpointed: number } {
const row = this.db.prepare(`PRAGMA wal_checkpoint(${mode})`).get() as
| { busy?: number; log?: number; checkpointed?: number }
| undefined;
return { busy: row?.busy ?? 0, log: row?.log ?? 0, checkpointed: row?.checkpointed ?? 0 };

View File

@@ -168,6 +168,10 @@ const TASK_ACTIVITY_LOG_ENTRY_LIMIT = 1_000;
const TASK_ACTIVITY_LOG_OUTCOME_LIMIT = 4_000;
const ARCHIVE_AGENT_LOG_SNAPSHOT_LIMIT = 25;
const ARCHIVE_AGENT_LOG_SNIPPET_LIMIT = 160;
const AGENT_LOG_TOOL_DETAIL_LIMIT = 4_096;
const AGENT_LOG_TOOL_DETAIL_TRUNCATION_NOTICE =
"\n\n[tool output truncated to keep dashboard log views responsive]";
const AGENT_LOG_TOOL_TYPES = new Set<AgentLogEntry["type"]>(["tool", "tool_result", "tool_error"]);
const storeLog = createLogger("task-store");
/**
@@ -224,6 +228,16 @@ function truncateTaskLogOutcome(outcome: string | undefined): string | undefined
return `${outcome.slice(0, TASK_ACTIVITY_LOG_OUTCOME_LIMIT)}\n... outcome truncated to ${TASK_ACTIVITY_LOG_OUTCOME_LIMIT} characters ...`;
}
function truncateAgentLogDetail(
detail: string | null | undefined,
type: AgentLogEntry["type"],
): string | undefined {
if (detail == null) return undefined;
if (!AGENT_LOG_TOOL_TYPES.has(type)) return detail;
if (detail.length <= AGENT_LOG_TOOL_DETAIL_LIMIT) return detail;
return `${detail.slice(0, AGENT_LOG_TOOL_DETAIL_LIMIT)}${AGENT_LOG_TOOL_DETAIL_TRUNCATION_NOTICE}`;
}
function compactTaskActivityLog(entries: TaskLogEntry[]): TaskLogEntry[] {
const recentEntries = entries.slice(-TASK_ACTIVITY_LOG_ENTRY_LIMIT);
return recentEntries.map((entry) => ({
@@ -4507,19 +4521,20 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
agent?: AgentLogEntry["agent"],
): Promise<void> {
const timestamp = new Date().toISOString();
const normalizedDetail = truncateAgentLogDetail(detail, type);
const entry: AgentLogEntry = {
timestamp,
taskId,
text,
type,
...(detail !== undefined && { detail }),
...(normalizedDetail !== undefined && { detail: normalizedDetail }),
...(agent !== undefined && { agent }),
};
this.db.prepare(`
INSERT INTO agentLogEntries (taskId, timestamp, text, type, detail, agent)
VALUES (?, ?, ?, ?, ?, ?)
`).run(taskId, timestamp, text, type, detail ?? null, agent ?? null);
`).run(taskId, timestamp, text, type, normalizedDetail ?? null, agent ?? null);
this.db.bumpLastModified();
this.emit("agent:log", entry);
@@ -4539,13 +4554,17 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
}
const timestamp = new Date().toISOString();
const normalizedEntries = entries.map((entry) => ({
...entry,
detail: truncateAgentLogDetail(entry.detail, entry.type),
}));
const stmt = this.db.prepare(`
INSERT INTO agentLogEntries (taskId, timestamp, text, type, detail, agent)
VALUES (?, ?, ?, ?, ?, ?)
`);
this.db.transaction(() => {
for (const entry of entries) {
for (const entry of normalizedEntries) {
stmt.run(
entry.taskId,
timestamp,
@@ -4558,7 +4577,7 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
});
this.db.bumpLastModified();
for (const entry of entries) {
for (const entry of normalizedEntries) {
this.emit("agent:log", {
timestamp,
taskId: entry.taskId,
@@ -4571,16 +4590,36 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
}
private mapAgentLogRow(row: Record<string, unknown>): AgentLogEntry {
const type = row.type as AgentLogEntry["type"];
const detail = row.detail != null ? String(row.detail) : undefined;
return {
timestamp: row.timestamp as string,
taskId: row.taskId as string,
text: row.text as string,
type: row.type as AgentLogEntry["type"],
...(row.detail != null && { detail: row.detail as string }),
type,
...(detail !== undefined && { detail }),
...(row.agent != null && { agent: row.agent as AgentLogEntry["agent"] }),
};
}
private getAgentLogSelectClause(): string {
const escapedNotice = AGENT_LOG_TOOL_DETAIL_TRUNCATION_NOTICE.replace(/'/g, "''");
return `
taskId,
timestamp,
text,
type,
CASE
WHEN type IN ('tool', 'tool_result', 'tool_error')
AND detail IS NOT NULL
AND LENGTH(detail) > ${AGENT_LOG_TOOL_DETAIL_LIMIT}
THEN SUBSTR(detail, 1, ${AGENT_LOG_TOOL_DETAIL_LIMIT}) || '${escapedNotice}'
ELSE detail
END AS detail,
agent
`;
}
async addTaskComment(id: string, text: string, author: string): Promise<Task> {
// Delegate to unified addComment method
return this.addComment(id, text, author);
@@ -5180,9 +5219,10 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
* Read historical agent log entries for a task from SQLite.
* Returns entries in chronological order (oldest first).
*
* Each entry's `text` and `detail` fields are returned in full — there is
* no per-entry truncation at the persistence layer. The 500-entry cap
* (`MAX_LOG_ENTRIES`) in the dashboard hooks is a whole-list limit only.
* Tool-oriented detail payloads are clipped server-side to keep historical
* log reads responsive even when agents emit very large command results.
* The 500-entry cap (`MAX_LOG_ENTRIES`) in the dashboard hooks remains a
* whole-list limit only.
*
* @param taskId - The task ID (e.g. "KB-001")
* @param options - Optional pagination options
@@ -5203,10 +5243,12 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
if (limit === 0) return [];
const selectClause = this.getAgentLogSelectClause();
if (limit !== undefined) {
const readCount = offset > 0 ? limit + offset : limit;
const rows = this.db.prepare(`
SELECT * FROM agentLogEntries
SELECT ${selectClause} FROM agentLogEntries
WHERE taskId = ?
ORDER BY timestamp DESC, id DESC
LIMIT ?
@@ -5219,7 +5261,7 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
}
const rows = this.db.prepare(`
SELECT * FROM agentLogEntries
SELECT ${selectClause} FROM agentLogEntries
WHERE taskId = ?
ORDER BY timestamp ASC, id ASC
`).all(taskId) as Array<Record<string, unknown>>;
@@ -5257,8 +5299,9 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
endIso: string | null,
): Promise<AgentLogEntry[]> {
const end = endIso ?? new Date().toISOString();
const selectClause = this.getAgentLogSelectClause();
const rows = this.db.prepare(`
SELECT * FROM agentLogEntries
SELECT ${selectClause} FROM agentLogEntries
WHERE taskId = ? AND timestamp >= ? AND timestamp <= ?
ORDER BY timestamp ASC, id ASC
`).all(taskId, startIso, end) as Array<Record<string, unknown>>;
@@ -5296,8 +5339,12 @@ export class TaskStore extends EventEmitter<TaskStoreEvents> {
const text = typeof parsed.text === "string" ? parsed.text : "";
const detail = typeof parsed.detail === "string" ? parsed.detail : null;
const agent = typeof parsed.agent === "string" ? parsed.agent : null;
const normalizedDetail = truncateAgentLogDetail(
detail,
type as AgentLogEntry["type"],
);
insertStmt.run(parsedTaskId, timestamp, text, type, detail, agent);
insertStmt.run(parsedTaskId, timestamp, text, type, normalizedDetail ?? null, agent);
imported += 1;
} catch {
// Skip malformed JSONL lines.
@@ -5866,11 +5913,15 @@ ${stepsSection}`;
}
/**
* Run a WAL checkpoint to truncate the WAL file and reclaim disk space.
* Safe to call periodically from the self-healing maintenance timer.
* Run a WAL checkpoint and return checkpoint stats.
*
* The default preserves SQLite's aggressive TRUNCATE behavior for explicit
* maintenance/compaction calls. Live engine maintenance should request
* PASSIVE explicitly to avoid forcing a blocking truncate on the shared
* event loop.
*/
walCheckpoint(): { busy: number; log: number; checkpointed: number } {
return this.db.walCheckpoint();
walCheckpoint(mode?: "PASSIVE" | "TRUNCATE"): { busy: number; log: number; checkpointed: number } {
return this.db.walCheckpoint(mode);
}
getRootDir(): string {

View File

@@ -1445,10 +1445,11 @@ export interface GlobalSettings {
* triggers a vitest auto-kill. Clamped to [50, 99] in the UI.
* Default: 90. */
vitestKillThresholdPct?: number;
/** When true (default), persist detailed tool argument/result payloads in
* task agent logs (`agent.log`) for `tool`, `tool_result`, and
* `tool_error` entries. When false, tool timeline rows are still stored,
* but their verbose `detail` payload is omitted to reduce log size/noise. */
/** When true (default), persist tool argument/result payloads in task agent
* logs for `tool`, `tool_result`, and `tool_error` entries. Very large tool
* payloads may still be clipped server-side to keep dashboard log reads
* responsive. When false, tool timeline rows are still stored, but their
* verbose `detail` payload is omitted to reduce log size/noise. */
persistAgentToolOutput?: boolean;
/** Research defaults shared across all projects.
* Project settings may override these via `researchSettings`. */