Compare commits
5 Commits
| Author | SHA1 | Date | |
|---|---|---|---|
| e48c74c653 | |||
| ce3308b3f1 | |||
| 61ae686422 | |||
| 905fdd2110 | |||
| bda15f4242 |
@@ -0,0 +1,397 @@
|
||||
/**
|
||||
* TaskLogService Unit Tests
|
||||
* ==========================
|
||||
* Tests the service-level bug fixes:
|
||||
* 1. mergeLogs() uses ?? to prefer worktree coding/validation even when pending with empty entries
|
||||
* 2. startWatching() poll skips emission when loadLogsFromPath returns cached data on parse failure
|
||||
* 3. clearCache() and stopWatching() clean up cacheVersions map
|
||||
*/
|
||||
|
||||
import { describe, it, expect, vi, beforeEach, afterEach } from 'vitest';
|
||||
import type { TaskLogs, TaskPhaseLog } from '../../shared/types';
|
||||
|
||||
// Mock fs before importing the service
|
||||
vi.mock('fs', () => ({
|
||||
existsSync: vi.fn(),
|
||||
readFileSync: vi.fn()
|
||||
}));
|
||||
|
||||
// Mock worktree-paths
|
||||
vi.mock('../worktree-paths', () => ({
|
||||
findTaskWorktree: vi.fn()
|
||||
}));
|
||||
|
||||
// Mock debug-logger
|
||||
vi.mock('../../shared/utils/debug-logger', () => ({
|
||||
debugLog: vi.fn(),
|
||||
debugWarn: vi.fn(),
|
||||
debugError: vi.fn()
|
||||
}));
|
||||
|
||||
function makePhaseLogs(overrides: Partial<TaskPhaseLog> = {}): TaskPhaseLog {
|
||||
return {
|
||||
phase: 'coding',
|
||||
status: 'pending',
|
||||
started_at: null,
|
||||
completed_at: null,
|
||||
entries: [],
|
||||
...overrides
|
||||
};
|
||||
}
|
||||
|
||||
function makeTaskLogs(overrides: Partial<TaskLogs> & { phases?: Partial<TaskLogs['phases']> } = {}): TaskLogs {
|
||||
const { phases, ...rest } = overrides;
|
||||
return {
|
||||
spec_id: '001-test',
|
||||
created_at: '2024-01-01T00:00:00Z',
|
||||
updated_at: '2024-01-01T01:00:00Z',
|
||||
phases: {
|
||||
planning: makePhaseLogs({ phase: 'planning', status: 'completed', entries: [{ type: 'text', content: 'Plan done', phase: 'planning', timestamp: '2024-01-01T00:00:00Z' }] }),
|
||||
coding: makePhaseLogs({ phase: 'coding' }),
|
||||
validation: makePhaseLogs({ phase: 'validation' }),
|
||||
...phases
|
||||
},
|
||||
...rest
|
||||
};
|
||||
}
|
||||
|
||||
describe('TaskLogService', () => {
|
||||
let TaskLogService: typeof import('../task-log-service').TaskLogService;
|
||||
let existsSync: ReturnType<typeof vi.fn>;
|
||||
let readFileSync: ReturnType<typeof vi.fn>;
|
||||
let findTaskWorktree: ReturnType<typeof vi.fn>;
|
||||
|
||||
beforeEach(async () => {
|
||||
vi.clearAllMocks();
|
||||
vi.useFakeTimers();
|
||||
|
||||
const fs = await import('fs');
|
||||
existsSync = fs.existsSync as ReturnType<typeof vi.fn>;
|
||||
readFileSync = fs.readFileSync as ReturnType<typeof vi.fn>;
|
||||
|
||||
const worktreePaths = await import('../worktree-paths');
|
||||
findTaskWorktree = worktreePaths.findTaskWorktree as ReturnType<typeof vi.fn>;
|
||||
|
||||
const mod = await import('../task-log-service');
|
||||
TaskLogService = mod.TaskLogService;
|
||||
});
|
||||
|
||||
afterEach(() => {
|
||||
vi.useRealTimers();
|
||||
vi.resetModules();
|
||||
});
|
||||
|
||||
describe('mergeLogs() - ?? operator fix for worktree phase preference', () => {
|
||||
it('should use worktree coding phase even when status is pending with empty entries', () => {
|
||||
const service = new TaskLogService();
|
||||
|
||||
// Main logs have coding phase with entries from a previous run
|
||||
const mainLogs = makeTaskLogs({
|
||||
phases: {
|
||||
planning: makePhaseLogs({ phase: 'planning', status: 'completed' }),
|
||||
coding: makePhaseLogs({
|
||||
phase: 'coding',
|
||||
status: 'completed',
|
||||
entries: [
|
||||
{ type: 'text', content: 'Old coding work', phase: 'coding', timestamp: '2024-01-01T00:30:00Z' }
|
||||
]
|
||||
}),
|
||||
validation: makePhaseLogs({
|
||||
phase: 'validation',
|
||||
status: 'completed',
|
||||
entries: [
|
||||
{ type: 'text', content: 'Old validation', phase: 'validation', timestamp: '2024-01-01T01:00:00Z' }
|
||||
]
|
||||
})
|
||||
}
|
||||
});
|
||||
|
||||
// Worktree logs have coding/validation reset to pending (agent retry scenario)
|
||||
const worktreeLogs = makeTaskLogs({
|
||||
phases: {
|
||||
planning: makePhaseLogs({ phase: 'planning', status: 'completed' }),
|
||||
coding: makePhaseLogs({
|
||||
phase: 'coding',
|
||||
status: 'pending',
|
||||
entries: []
|
||||
}),
|
||||
validation: makePhaseLogs({
|
||||
phase: 'validation',
|
||||
status: 'pending',
|
||||
entries: []
|
||||
})
|
||||
}
|
||||
});
|
||||
|
||||
// Use loadLogsFromPath to populate internal state, then test mergeLogs indirectly via loadLogs
|
||||
// We access mergeLogs through loadLogs by setting up the right conditions.
|
||||
// However, mergeLogs is private, so we test through the public API.
|
||||
|
||||
const mainSpecDir = '/project/.auto-claude/specs/001-test';
|
||||
const worktreeSpecDir = '/project/.auto-claude/worktrees/tasks/001-test/.auto-claude/specs/001-test';
|
||||
|
||||
// Set up fs mocks for both paths
|
||||
existsSync.mockImplementation((filePath: string) => {
|
||||
return filePath.includes('task_logs.json');
|
||||
});
|
||||
|
||||
readFileSync.mockImplementation((filePath: string) => {
|
||||
if (filePath.includes(worktreeSpecDir)) {
|
||||
return JSON.stringify(worktreeLogs);
|
||||
}
|
||||
return JSON.stringify(mainLogs);
|
||||
});
|
||||
|
||||
// Set up worktree discovery
|
||||
findTaskWorktree.mockReturnValue('/project/.auto-claude/worktrees/tasks/001-test');
|
||||
|
||||
// Load merged logs
|
||||
const result = service.loadLogs(mainSpecDir, '/project', '.auto-claude/specs', '001-test');
|
||||
|
||||
expect(result).not.toBeNull();
|
||||
// The key assertion: worktree's pending coding phase should be used (not main's completed one)
|
||||
// because ?? only falls back to main when worktree value is null/undefined, not when it's
|
||||
// a valid object with status 'pending'
|
||||
expect(result!.phases.coding.status).toBe('pending');
|
||||
expect(result!.phases.coding.entries).toHaveLength(0);
|
||||
expect(result!.phases.validation.status).toBe('pending');
|
||||
expect(result!.phases.validation.entries).toHaveLength(0);
|
||||
});
|
||||
|
||||
it('should fall back to main coding phase when worktree coding is null', () => {
|
||||
const service = new TaskLogService();
|
||||
|
||||
const mainLogs = makeTaskLogs({
|
||||
phases: {
|
||||
planning: makePhaseLogs({ phase: 'planning', status: 'completed' }),
|
||||
coding: makePhaseLogs({
|
||||
phase: 'coding',
|
||||
status: 'active',
|
||||
entries: [{ type: 'text', content: 'Main coding', phase: 'coding', timestamp: '2024-01-01T00:30:00Z' }]
|
||||
}),
|
||||
validation: makePhaseLogs({ phase: 'validation' })
|
||||
}
|
||||
});
|
||||
|
||||
// Worktree logs where coding is explicitly null (not yet started in worktree)
|
||||
const worktreeLogsRaw = {
|
||||
spec_id: '001-test',
|
||||
created_at: '2024-01-01T00:00:00Z',
|
||||
updated_at: '2024-01-01T01:00:00Z',
|
||||
phases: {
|
||||
planning: makePhaseLogs({ phase: 'planning', status: 'completed' }),
|
||||
coding: null,
|
||||
validation: null
|
||||
}
|
||||
};
|
||||
|
||||
const mainSpecDir = '/project/.auto-claude/specs/001-test';
|
||||
const worktreeSpecDir = '/project/.auto-claude/worktrees/tasks/001-test/.auto-claude/specs/001-test';
|
||||
|
||||
existsSync.mockReturnValue(true);
|
||||
readFileSync.mockImplementation((filePath: string) => {
|
||||
if (filePath.includes(worktreeSpecDir)) {
|
||||
return JSON.stringify(worktreeLogsRaw);
|
||||
}
|
||||
return JSON.stringify(mainLogs);
|
||||
});
|
||||
|
||||
findTaskWorktree.mockReturnValue('/project/.auto-claude/worktrees/tasks/001-test');
|
||||
|
||||
const result = service.loadLogs(mainSpecDir, '/project', '.auto-claude/specs', '001-test');
|
||||
|
||||
expect(result).not.toBeNull();
|
||||
// With null worktree coding, should fall back to main
|
||||
expect(result!.phases.coding.status).toBe('active');
|
||||
expect(result!.phases.coding.entries).toHaveLength(1);
|
||||
});
|
||||
});
|
||||
|
||||
describe('startWatching() - cacheVersions gating skips emission on parse failure', () => {
|
||||
it('should skip emission when loadLogsFromPath returns cached data due to parse failure', () => {
|
||||
const service = new TaskLogService();
|
||||
const specId = '001-test';
|
||||
const specDir = '/project/.auto-claude/specs/001-test';
|
||||
|
||||
const validLogs = makeTaskLogs();
|
||||
const validContent = JSON.stringify(validLogs);
|
||||
|
||||
// Track emissions
|
||||
const emittedEvents: Array<{ event: string; args: unknown[] }> = [];
|
||||
service.on('logs-changed', (...args: unknown[]) => {
|
||||
emittedEvents.push({ event: 'logs-changed', args });
|
||||
});
|
||||
|
||||
// Initial state: valid file exists
|
||||
let currentContent = validContent;
|
||||
existsSync.mockReturnValue(true);
|
||||
readFileSync.mockImplementation(() => currentContent);
|
||||
findTaskWorktree.mockReturnValue(null);
|
||||
|
||||
// Start watching
|
||||
service.startWatching(specId, specDir);
|
||||
|
||||
// Simulate file change to corrupted content (mid-write)
|
||||
// The raw content changes so the poll detects a change,
|
||||
// but JSON.parse fails, returning cached data instead
|
||||
currentContent = '{"spec_id": "001-test", CORRUPTED';
|
||||
readFileSync.mockImplementation(() => {
|
||||
// Simulate the loadLogsFromPath path: readFileSync returns corrupted content,
|
||||
// JSON.parse will throw, and the service returns cached data
|
||||
return currentContent;
|
||||
});
|
||||
|
||||
// Advance past one poll interval
|
||||
vi.advanceTimersByTime(1100);
|
||||
|
||||
// No emission should have occurred because the parse failure means
|
||||
// cacheVersions didn't increment — the service returned cached data
|
||||
expect(emittedEvents).toHaveLength(0);
|
||||
|
||||
// Now simulate recovery: file becomes valid again with new content
|
||||
const updatedLogs = makeTaskLogs({
|
||||
updated_at: '2024-01-01T02:00:00Z',
|
||||
phases: {
|
||||
planning: makePhaseLogs({ phase: 'planning', status: 'completed' }),
|
||||
coding: makePhaseLogs({
|
||||
phase: 'coding',
|
||||
status: 'active',
|
||||
entries: [{ type: 'text', content: 'Coding started', phase: 'coding', timestamp: '2024-01-01T01:30:00Z' }]
|
||||
}),
|
||||
validation: makePhaseLogs({ phase: 'validation' })
|
||||
}
|
||||
});
|
||||
const newValidContent = JSON.stringify(updatedLogs);
|
||||
currentContent = newValidContent;
|
||||
readFileSync.mockImplementation(() => currentContent);
|
||||
|
||||
// Advance past another poll interval
|
||||
vi.advanceTimersByTime(1100);
|
||||
|
||||
// Now emission should occur because a fresh parse succeeded
|
||||
expect(emittedEvents.length).toBeGreaterThanOrEqual(1);
|
||||
|
||||
// Clean up
|
||||
service.stopWatching(specId);
|
||||
});
|
||||
});
|
||||
|
||||
describe('clearCache() - cacheVersions cleanup', () => {
|
||||
it('should delete cacheVersions entry when clearing cache', () => {
|
||||
const service = new TaskLogService();
|
||||
const specDir = '/project/.auto-claude/specs/001-test';
|
||||
|
||||
// Load logs to populate both logCache and cacheVersions
|
||||
existsSync.mockReturnValue(true);
|
||||
readFileSync.mockReturnValue(JSON.stringify(makeTaskLogs()));
|
||||
findTaskWorktree.mockReturnValue(null);
|
||||
|
||||
const result = service.loadLogsFromPath(specDir);
|
||||
expect(result).not.toBeNull();
|
||||
|
||||
// Verify cache is populated
|
||||
expect(service.getCachedLogs(specDir)).not.toBeNull();
|
||||
|
||||
// Clear cache
|
||||
service.clearCache(specDir);
|
||||
|
||||
// Verify both logCache and cacheVersions are cleaned
|
||||
expect(service.getCachedLogs(specDir)).toBeNull();
|
||||
|
||||
// Verify cacheVersions was cleaned by loading again and checking version starts fresh
|
||||
// We do this by loading logs again - the version should start from 1 (not continue from previous)
|
||||
readFileSync.mockReturnValue(JSON.stringify(makeTaskLogs()));
|
||||
service.loadLogsFromPath(specDir);
|
||||
|
||||
// If clearCache properly cleaned cacheVersions, loading again resets the counter.
|
||||
// We can verify this indirectly: after clearCache + reload, the cache should be fresh
|
||||
expect(service.getCachedLogs(specDir)).not.toBeNull();
|
||||
});
|
||||
});
|
||||
|
||||
describe('stopWatching() - cacheVersions cleanup', () => {
|
||||
it('should delete cacheVersions entries for watched paths when stopping', () => {
|
||||
const service = new TaskLogService();
|
||||
const specId = '001-test';
|
||||
const specDir = '/project/.auto-claude/specs/001-test';
|
||||
const worktreeSpecDir = '/project/.auto-claude/worktrees/tasks/001-test/.auto-claude/specs/001-test';
|
||||
|
||||
existsSync.mockReturnValue(true);
|
||||
readFileSync.mockReturnValue(JSON.stringify(makeTaskLogs()));
|
||||
findTaskWorktree.mockReturnValue('/project/.auto-claude/worktrees/tasks/001-test');
|
||||
|
||||
// Start watching (this will load initial logs, populating cacheVersions)
|
||||
service.startWatching(specId, specDir, '/project', '.auto-claude/specs');
|
||||
|
||||
// Verify cache is populated for main spec dir
|
||||
expect(service.getCachedLogs(specDir)).not.toBeNull();
|
||||
|
||||
// Stop watching
|
||||
service.stopWatching(specId);
|
||||
|
||||
// After stopping, cacheVersions should be cleaned for both main and worktree paths.
|
||||
// We verify indirectly: loading from the same path should start fresh version counting.
|
||||
// The logCache may still have data (stopWatching doesn't clear logCache),
|
||||
// but the cacheVersions entries should be gone.
|
||||
|
||||
// Load again to verify versions start fresh
|
||||
const beforeSecondLoad = service.getCachedLogs(specDir);
|
||||
// logCache is NOT cleared by stopWatching (only cacheVersions), so this may still exist
|
||||
// The important thing is that cacheVersions was cleaned
|
||||
|
||||
// Start watching again - should not skip due to stale cacheVersions
|
||||
service.startWatching(specId, specDir, '/project', '.auto-claude/specs');
|
||||
|
||||
const emittedEvents: Array<{ event: string; args: unknown[] }> = [];
|
||||
service.on('logs-changed', (...args: unknown[]) => {
|
||||
emittedEvents.push({ event: 'logs-changed', args });
|
||||
});
|
||||
|
||||
// Change file content and advance timer
|
||||
const updatedLogs = makeTaskLogs({ updated_at: '2024-01-01T03:00:00Z' });
|
||||
readFileSync.mockReturnValue(JSON.stringify(updatedLogs));
|
||||
vi.advanceTimersByTime(1100);
|
||||
|
||||
// Should emit because cacheVersions was cleaned and fresh parse succeeds
|
||||
expect(emittedEvents.length).toBeGreaterThanOrEqual(1);
|
||||
|
||||
service.stopWatching(specId);
|
||||
});
|
||||
});
|
||||
|
||||
describe('loadLogsFromPath() - cache fallback on parse error', () => {
|
||||
it('should return cached logs when JSON parse fails', () => {
|
||||
const service = new TaskLogService();
|
||||
const specDir = '/project/.auto-claude/specs/001-test';
|
||||
|
||||
existsSync.mockReturnValue(true);
|
||||
|
||||
// First load: valid JSON
|
||||
const validLogs = makeTaskLogs();
|
||||
readFileSync.mockReturnValue(JSON.stringify(validLogs));
|
||||
const result1 = service.loadLogsFromPath(specDir);
|
||||
expect(result1).not.toBeNull();
|
||||
expect(result1!.spec_id).toBe('001-test');
|
||||
|
||||
// Second load: corrupted JSON
|
||||
readFileSync.mockReturnValue('NOT VALID JSON{{{');
|
||||
const result2 = service.loadLogsFromPath(specDir);
|
||||
|
||||
// Should return cached version
|
||||
expect(result2).not.toBeNull();
|
||||
expect(result2!.spec_id).toBe('001-test');
|
||||
expect(result2).toEqual(validLogs);
|
||||
});
|
||||
|
||||
it('should return null when JSON parse fails and no cache exists', () => {
|
||||
const service = new TaskLogService();
|
||||
const specDir = '/project/.auto-claude/specs/001-test';
|
||||
|
||||
existsSync.mockReturnValue(true);
|
||||
readFileSync.mockReturnValue('CORRUPTED JSON');
|
||||
|
||||
const result = service.loadLogsFromPath(specDir);
|
||||
expect(result).toBeNull();
|
||||
});
|
||||
});
|
||||
});
|
||||
@@ -480,6 +480,232 @@ describe('Task Logs Integration (IPC → Service → State)', () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe('Oscillation prevention (regression: worktree coding phase reset during agent retry)', () => {
|
||||
it('should return worktree coding phase even when status is pending and entries are empty', async () => {
|
||||
// Verifies that the IPC handler returns whatever the service returns without modification,
|
||||
// specifically when the worktree coding phase has been reset to pending (agent retry state).
|
||||
// The actual anti-oscillation fix lives in TaskLogService.mergeLogs() using ?? instead of
|
||||
// a status-based ternary condition. This test confirms the IPC layer does not interfere.
|
||||
const { projectStore } = await import('../../../project-store');
|
||||
const { taskLogService } = await import('../../../task-log-service');
|
||||
const { existsSync } = await import('fs');
|
||||
|
||||
const mockProject = {
|
||||
id: 'project-123',
|
||||
path: '/absolute/path/to/project',
|
||||
autoBuildPath: '.auto-claude'
|
||||
};
|
||||
|
||||
// Simulate the service returning merged logs where the worktree coding phase is
|
||||
// present but pending/empty (agent retried and reset coding phase to 'pending').
|
||||
// With the ?? fix, the service returns the worktree phase (not mainLogs fallback).
|
||||
const mockLogsWithPendingCoding: TaskLogs = {
|
||||
spec_id: '001-test-task',
|
||||
created_at: '2024-01-01T00:00:00Z',
|
||||
updated_at: '2024-01-01T00:31:00Z',
|
||||
phases: {
|
||||
planning: {
|
||||
phase: 'planning',
|
||||
status: 'completed',
|
||||
started_at: '2024-01-01T00:00:00Z',
|
||||
completed_at: '2024-01-01T00:30:00Z',
|
||||
entries: [
|
||||
{ type: 'text', content: 'Planning done', phase: 'planning', timestamp: '2024-01-01T00:00:00Z' }
|
||||
]
|
||||
},
|
||||
// Worktree coding phase is present but pending/empty — agent just reset it.
|
||||
// The ?? fix ensures this is returned, not the main coding phase.
|
||||
coding: {
|
||||
phase: 'coding',
|
||||
status: 'pending',
|
||||
started_at: null,
|
||||
completed_at: null,
|
||||
entries: []
|
||||
},
|
||||
validation: {
|
||||
phase: 'validation',
|
||||
status: 'pending',
|
||||
started_at: null,
|
||||
completed_at: null,
|
||||
entries: []
|
||||
}
|
||||
}
|
||||
};
|
||||
|
||||
(projectStore.getProject as Mock).mockReturnValue(mockProject);
|
||||
(existsSync as Mock).mockReturnValue(true);
|
||||
(taskLogService.loadLogs as Mock).mockReturnValue(mockLogsWithPendingCoding);
|
||||
|
||||
const handler = ipcHandlers['task:logsGet'];
|
||||
const result = await handler({}, 'project-123', '001-test-task') as IPCResult<TaskLogs>;
|
||||
|
||||
// IPC handler must return the service result as-is (no re-applying the old ternary logic)
|
||||
expect(result.success).toBe(true);
|
||||
expect(result.data).toEqual(mockLogsWithPendingCoding);
|
||||
// Coding phase should reflect the worktree's pending state, not oscillate to main
|
||||
expect(result.data?.phases.coding?.status).toBe('pending');
|
||||
expect(result.data?.phases.coding?.entries).toHaveLength(0);
|
||||
});
|
||||
|
||||
it('should return consistent coding status across multiple rapid calls (no flip-flop)', async () => {
|
||||
// Confirms that repeated calls with a pending worktree coding phase produce consistent
|
||||
// results. Old code would flip between worktree (when active) and main (when pending),
|
||||
// producing oscillation. The IPC handler must pass through the service result every time.
|
||||
const { projectStore } = await import('../../../project-store');
|
||||
const { taskLogService } = await import('../../../task-log-service');
|
||||
const { existsSync } = await import('fs');
|
||||
|
||||
const mockProject = {
|
||||
id: 'project-123',
|
||||
path: '/absolute/path/to/project',
|
||||
autoBuildPath: '.auto-claude'
|
||||
};
|
||||
|
||||
// Service always returns the same merged result (pending worktree coding phase)
|
||||
const pendingCodingLogs: TaskLogs = {
|
||||
spec_id: '001-test-task',
|
||||
created_at: '2024-01-01T00:00:00Z',
|
||||
updated_at: '2024-01-01T00:31:00Z',
|
||||
phases: {
|
||||
planning: { phase: 'planning', status: 'completed', started_at: null, completed_at: null, entries: [] },
|
||||
coding: { phase: 'coding', status: 'pending', started_at: null, completed_at: null, entries: [] },
|
||||
validation: { phase: 'validation', status: 'pending', started_at: null, completed_at: null, entries: [] }
|
||||
}
|
||||
};
|
||||
|
||||
(projectStore.getProject as Mock).mockReturnValue(mockProject);
|
||||
(existsSync as Mock).mockReturnValue(true);
|
||||
(taskLogService.loadLogs as Mock).mockReturnValue(pendingCodingLogs);
|
||||
|
||||
const handler = ipcHandlers['task:logsGet'];
|
||||
|
||||
// Call multiple times to simulate rapid polling (previously would cause oscillation)
|
||||
const results = await Promise.all([
|
||||
handler({}, 'project-123', '001-test-task') as Promise<IPCResult<TaskLogs>>,
|
||||
handler({}, 'project-123', '001-test-task') as Promise<IPCResult<TaskLogs>>,
|
||||
handler({}, 'project-123', '001-test-task') as Promise<IPCResult<TaskLogs>>
|
||||
]);
|
||||
|
||||
// All results must be consistent — no oscillation
|
||||
for (const result of results) {
|
||||
expect(result.success).toBe(true);
|
||||
expect(result.data?.phases.coding?.status).toBe('pending');
|
||||
expect(result.data?.phases.coding?.entries).toHaveLength(0);
|
||||
}
|
||||
});
|
||||
});
|
||||
|
||||
describe('Stale cache emission prevention (regression: mid-write JSON parse failures)', () => {
|
||||
it('should forward logs-changed events to renderer when service emits fresh data', async () => {
|
||||
// The service uses cacheVersions to gate emission: it only emits logs-changed when a
|
||||
// fresh parse succeeded (version incremented). This test verifies that when the service
|
||||
// DOES emit (fresh data available), the IPC handler correctly forwards it to the renderer.
|
||||
const { taskLogService } = await import('../../../task-log-service');
|
||||
|
||||
const freshLogs: TaskLogs = {
|
||||
spec_id: '001-test-task',
|
||||
created_at: '2024-01-01T00:00:00Z',
|
||||
updated_at: '2024-01-01T01:01:00Z',
|
||||
phases: {
|
||||
planning: { phase: 'planning', status: 'completed', started_at: null, completed_at: null, entries: [] },
|
||||
coding: {
|
||||
phase: 'coding',
|
||||
status: 'active',
|
||||
started_at: '2024-01-01T00:30:00Z',
|
||||
completed_at: null,
|
||||
entries: [
|
||||
{ type: 'text', content: 'Coding in progress', phase: 'coding', timestamp: '2024-01-01T01:00:00Z' }
|
||||
]
|
||||
},
|
||||
validation: { phase: 'validation', status: 'pending', started_at: null, completed_at: null, entries: [] }
|
||||
}
|
||||
};
|
||||
|
||||
const onCall = (taskLogService.on as Mock).mock.calls.find(
|
||||
call => call[0] === 'logs-changed'
|
||||
);
|
||||
expect(onCall).toBeDefined();
|
||||
if (!onCall) throw new Error('logs-changed handler not registered');
|
||||
const eventHandler = onCall[1];
|
||||
|
||||
// Service emits (fresh parse succeeded, cacheVersions incremented)
|
||||
eventHandler('001-test-task', freshLogs);
|
||||
|
||||
// IPC handler must forward it to the renderer exactly once
|
||||
expect(mockMainWindow.webContents?.send).toHaveBeenCalledTimes(1);
|
||||
expect(mockMainWindow.webContents?.send).toHaveBeenCalledWith(
|
||||
'task:logsChanged',
|
||||
'001-test-task',
|
||||
freshLogs
|
||||
);
|
||||
});
|
||||
|
||||
it('should NOT forward any update to renderer when service does not emit (parse failure)', async () => {
|
||||
// When a mid-write JSON parse failure occurs, the service's cacheVersions does NOT
|
||||
// increment, so the service skips the logs-changed emit. This test confirms the renderer
|
||||
// receives NO update when the service stays silent (no stale cache forwarded).
|
||||
const { taskLogService } = await import('../../../task-log-service');
|
||||
|
||||
const onCall = (taskLogService.on as Mock).mock.calls.find(
|
||||
call => call[0] === 'logs-changed'
|
||||
);
|
||||
expect(onCall).toBeDefined();
|
||||
if (!onCall) throw new Error('logs-changed handler not registered');
|
||||
|
||||
// Simulate parse failure: service does NOT call the event handler
|
||||
// (equivalent to the version check in startWatching() preventing the emit)
|
||||
|
||||
// Renderer should receive zero updates
|
||||
expect(mockMainWindow.webContents?.send).not.toHaveBeenCalled();
|
||||
});
|
||||
|
||||
it('should forward only the second event when first emission is suppressed (parse failure then success)', async () => {
|
||||
// Simulates: (1) parse failure → service silent, (2) next poll succeeds → service emits.
|
||||
// The renderer should only receive the second (fresh) emission, not stale data.
|
||||
const { taskLogService } = await import('../../../task-log-service');
|
||||
|
||||
const freshLogs: TaskLogs = {
|
||||
spec_id: '001-test-task',
|
||||
created_at: '2024-01-01T00:00:00Z',
|
||||
updated_at: '2024-01-01T01:02:00Z',
|
||||
phases: {
|
||||
planning: { phase: 'planning', status: 'completed', started_at: null, completed_at: null, entries: [] },
|
||||
coding: {
|
||||
phase: 'coding',
|
||||
status: 'active',
|
||||
started_at: '2024-01-01T00:30:00Z',
|
||||
completed_at: null,
|
||||
entries: [
|
||||
{ type: 'text', content: 'Coder making progress', phase: 'coding', timestamp: '2024-01-01T01:02:00Z' }
|
||||
]
|
||||
},
|
||||
validation: { phase: 'validation', status: 'pending', started_at: null, completed_at: null, entries: [] }
|
||||
}
|
||||
};
|
||||
|
||||
const onCall = (taskLogService.on as Mock).mock.calls.find(
|
||||
call => call[0] === 'logs-changed'
|
||||
);
|
||||
expect(onCall).toBeDefined();
|
||||
if (!onCall) throw new Error('logs-changed handler not registered');
|
||||
const eventHandler = onCall[1];
|
||||
|
||||
// Poll 1: parse failure — service does NOT emit (version not incremented)
|
||||
// (no eventHandler call here)
|
||||
|
||||
// Poll 2: fresh parse succeeds — service emits
|
||||
eventHandler('001-test-task', freshLogs);
|
||||
|
||||
// Renderer receives exactly one update (the fresh one)
|
||||
expect(mockMainWindow.webContents?.send).toHaveBeenCalledTimes(1);
|
||||
expect(mockMainWindow.webContents?.send).toHaveBeenCalledWith(
|
||||
'task:logsChanged',
|
||||
'001-test-task',
|
||||
freshLogs
|
||||
);
|
||||
});
|
||||
});
|
||||
|
||||
describe('Event forwarding to renderer', () => {
|
||||
it('should forward logs-changed events to renderer', async () => {
|
||||
const { taskLogService } = await import('../../../task-log-service');
|
||||
|
||||
@@ -28,6 +28,7 @@ function findWorktreeSpecDir(projectPath: string, specId: string, specsRelPath:
|
||||
*/
|
||||
export class TaskLogService extends EventEmitter {
|
||||
private logCache: Map<string, TaskLogs> = new Map();
|
||||
private cacheVersions: Map<string, number> = new Map();
|
||||
private pollIntervals: Map<string, NodeJS.Timeout> = new Map();
|
||||
// Store paths being watched for each specId (main + worktree)
|
||||
private watchedPaths: Map<string, { mainSpecDir: string; worktreeSpecDir: string | null; specsRelPath: string }> = new Map();
|
||||
@@ -69,6 +70,7 @@ export class TaskLogService extends EventEmitter {
|
||||
});
|
||||
|
||||
this.logCache.set(specDir, logs);
|
||||
this.cacheVersions.set(specDir, (this.cacheVersions.get(specDir) ?? 0) + 1);
|
||||
return logs;
|
||||
} catch (error) {
|
||||
// JSON parse error - file may be mid-write, return cached version if available
|
||||
@@ -130,13 +132,11 @@ export class TaskLogService extends EventEmitter {
|
||||
updated_at: worktreeLogs.updated_at > mainLogs.updated_at ? worktreeLogs.updated_at : mainLogs.updated_at,
|
||||
phases: {
|
||||
planning: mainLogs.phases.planning || worktreeLogs.phases.planning,
|
||||
// Use worktree logs for coding/validation if they have entries, otherwise fall back to main
|
||||
coding: (worktreeLogs.phases.coding?.entries?.length > 0 || worktreeLogs.phases.coding?.status !== 'pending')
|
||||
? worktreeLogs.phases.coding
|
||||
: mainLogs.phases.coding,
|
||||
validation: (worktreeLogs.phases.validation?.entries?.length > 0 || worktreeLogs.phases.validation?.status !== 'pending')
|
||||
? worktreeLogs.phases.validation
|
||||
: mainLogs.phases.validation
|
||||
// Use worktree logs for coding/validation if the worktree phase exists (not null/undefined),
|
||||
// otherwise fall back to main. The ?? operator avoids flip-flopping when the worktree
|
||||
// coding/validation phase resets to 'pending' during agent retries.
|
||||
coding: worktreeLogs.phases.coding ?? mainLogs.phases.coding,
|
||||
validation: worktreeLogs.phases.validation ?? mainLogs.phases.validation
|
||||
}
|
||||
};
|
||||
|
||||
@@ -149,8 +149,8 @@ export class TaskLogService extends EventEmitter {
|
||||
},
|
||||
source: {
|
||||
planning: mainLogs.phases.planning ? 'main' : 'worktree',
|
||||
coding: (worktreeLogs.phases.coding?.entries?.length > 0 || worktreeLogs.phases.coding?.status !== 'pending') ? 'worktree' : 'main',
|
||||
validation: (worktreeLogs.phases.validation?.entries?.length > 0 || worktreeLogs.phases.validation?.status !== 'pending') ? 'worktree' : 'main'
|
||||
coding: worktreeLogs.phases.coding != null ? 'worktree' : 'main',
|
||||
validation: worktreeLogs.phases.validation != null ? 'worktree' : 'main'
|
||||
}
|
||||
});
|
||||
|
||||
@@ -390,9 +390,22 @@ export class TaskLogService extends EventEmitter {
|
||||
});
|
||||
|
||||
const previousLogs = this.logCache.get(specDir);
|
||||
|
||||
// Capture version before load to detect whether a fresh parse succeeded
|
||||
const versionBefore =
|
||||
(this.cacheVersions.get(specDir) ?? 0) +
|
||||
(currentWorktreeSpecDir ? (this.cacheVersions.get(currentWorktreeSpecDir) ?? 0) : 0);
|
||||
|
||||
const logs = this.loadLogs(specDir);
|
||||
|
||||
if (logs) {
|
||||
// Only emit when at least one fresh parse succeeded (version increased).
|
||||
// If both paths returned cached data due to a mid-write JSON failure the
|
||||
// version stays unchanged and we skip the emit to avoid oscillation.
|
||||
const versionAfter =
|
||||
(this.cacheVersions.get(specDir) ?? 0) +
|
||||
(currentWorktreeSpecDir ? (this.cacheVersions.get(currentWorktreeSpecDir) ?? 0) : 0);
|
||||
|
||||
if (logs && versionAfter > versionBefore) {
|
||||
debugLog('[TaskLogService] Emitting logs-changed event:', {
|
||||
specId,
|
||||
entryCounts: {
|
||||
@@ -407,8 +420,10 @@ export class TaskLogService extends EventEmitter {
|
||||
|
||||
// Calculate and emit streaming updates for new entries
|
||||
this.emitNewEntries(specId, previousLogs, logs);
|
||||
} else {
|
||||
} else if (!logs) {
|
||||
debugWarn('[TaskLogService] No logs loaded after file change:', specId);
|
||||
} else {
|
||||
debugLog('[TaskLogService] Skipping emit - only cached data available (mid-write parse failure):', specId);
|
||||
}
|
||||
}
|
||||
}, this.POLL_INTERVAL_MS);
|
||||
@@ -431,6 +446,16 @@ export class TaskLogService extends EventEmitter {
|
||||
debugLog('[TaskLogService.stopWatching] Stopping watch for spec:', specId);
|
||||
clearInterval(interval);
|
||||
this.pollIntervals.delete(specId);
|
||||
|
||||
// Clean up cacheVersions for the watched paths to prevent stale version counters
|
||||
const watchedInfo = this.watchedPaths.get(specId);
|
||||
if (watchedInfo) {
|
||||
this.cacheVersions.delete(watchedInfo.mainSpecDir);
|
||||
if (watchedInfo.worktreeSpecDir) {
|
||||
this.cacheVersions.delete(watchedInfo.worktreeSpecDir);
|
||||
}
|
||||
}
|
||||
|
||||
this.watchedPaths.delete(specId);
|
||||
}
|
||||
}
|
||||
@@ -515,6 +540,7 @@ export class TaskLogService extends EventEmitter {
|
||||
*/
|
||||
clearCache(specDir: string): void {
|
||||
this.logCache.delete(specDir);
|
||||
this.cacheVersions.delete(specDir);
|
||||
}
|
||||
|
||||
/**
|
||||
|
||||
Reference in New Issue
Block a user