fix(logging): address review feedback on cleanup and log reader

This commit is contained in:
Tam Nhu Tran
2026-04-08 15:57:15 -04:00
parent 382aa04ca0
commit 42481c0bb9
7 changed files with 410 additions and 34 deletions
+6 -9
View File
@@ -1,7 +1,7 @@
/**
* Cleanup Command Handler
*
* Removes old CLIProxy logs to free up disk space.
* Removes old CCS and CLIProxy logs to free up disk space.
* Supports both main logs and error request logs with age-based filtering.
* Logs can accumulate to several GB without user awareness.
*/
@@ -32,23 +32,20 @@ function formatBytes(bytes: number): string {
return `${(bytes / Math.pow(1024, i)).toFixed(2)} ${units[i]}`;
}
/** Calculate total size of a directory */
/** Calculate total size of regular top-level files in a directory */
function getDirSize(dirPath: string): number {
if (!fs.existsSync(dirPath)) return 0;
let totalSize = 0;
const files = fs.readdirSync(dirPath);
const entries = fs.readdirSync(dirPath);
for (const file of files) {
const filePath = path.join(dirPath, file);
for (const entry of entries) {
const filePath = path.join(dirPath, entry);
try {
const stats = fs.lstatSync(filePath); // Use lstat to detect symlinks
const stats = fs.lstatSync(filePath);
if (stats.isFile() && !stats.isSymbolicLink()) {
totalSize += stats.size;
} else if (stats.isDirectory() && !stats.isSymbolicLink()) {
totalSize += getDirSize(filePath);
}
// Skip symlinks for safety
} catch {
// File may have been deleted between readdir and stat - skip
}
+1 -1
View File
@@ -137,7 +137,7 @@ export const ROOT_COMMAND_CATALOG: readonly RootCommandEntry[] = [
},
{
name: 'cleanup',
summary: 'Remove old CLIProxy logs',
summary: 'Remove old CCS and CLIProxy logs',
group: 'operations',
aliases: ['--cleanup'],
visibility: 'public',
+59 -20
View File
@@ -8,6 +8,15 @@ import {
type ReadLogEntriesOptions,
} from './log-types';
type CurrentLogCache = {
entries: LogEntry[];
mtimeNs: bigint;
path: string;
size: bigint;
} | null;
let currentLogCache: CurrentLogCache = null;
function parseLogLine(line: string): LogEntry | null {
try {
return JSON.parse(line) as LogEntry;
@@ -19,16 +28,62 @@ function parseLogLine(line: string): LogEntry | null {
function readCurrentFileEntries(): LogEntry[] {
const currentLogPath = getCurrentLogPath();
if (!fs.existsSync(currentLogPath)) {
currentLogCache = null;
return [];
}
return fs
const stats = fs.statSync(currentLogPath, { bigint: true });
if (
currentLogCache &&
currentLogCache.path === currentLogPath &&
currentLogCache.mtimeNs === stats.mtimeNs &&
currentLogCache.size === stats.size
) {
return [...currentLogCache.entries];
}
const entries = fs
.readFileSync(currentLogPath, 'utf8')
.split('\n')
.map((line) => line.trim())
.filter(Boolean)
.map(parseLogLine)
.filter((entry): entry is LogEntry => entry !== null);
currentLogCache = {
entries,
mtimeNs: stats.mtimeNs,
path: currentLogPath,
size: stats.size,
};
return [...entries];
}
function matchesLogQuery(entry: LogEntry, options: ReadLogEntriesOptions): boolean {
if (options.source && entry.source !== options.source) {
return false;
}
if (options.level && entry.level !== options.level) {
return false;
}
if (!options.search) {
return true;
}
const search = options.search.toLowerCase();
return (
entry.message.toLowerCase().includes(search) ||
entry.event.toLowerCase().includes(search) ||
entry.source.toLowerCase().includes(search) ||
String(entry.processId).toLowerCase().includes(search) ||
entry.runId.toLowerCase().includes(search) ||
JSON.stringify(entry.context || {})
.toLowerCase()
.includes(search)
);
}
function dedupeEntries(entries: LogEntry[]): LogEntry[] {
@@ -40,28 +95,12 @@ function dedupeEntries(entries: LogEntry[]): LogEntry[] {
}
export function readLogEntries(options: ReadLogEntriesOptions = {}): LogEntry[] {
const limit = options.limit ?? 200;
const entries = dedupeEntries([...readCurrentFileEntries(), ...getRecentLogEntries()])
.filter((entry) => (options.source ? entry.source === options.source : true))
.filter((entry) => (options.level ? entry.level === options.level : true))
.filter((entry) => {
if (!options.search) {
return true;
}
const search = options.search.toLowerCase();
return (
entry.message.toLowerCase().includes(search) ||
entry.event.toLowerCase().includes(search) ||
entry.source.toLowerCase().includes(search) ||
String(entry.processId).toLowerCase().includes(search) ||
entry.runId.toLowerCase().includes(search) ||
JSON.stringify(entry.context || {})
.toLowerCase()
.includes(search)
);
})
.filter((entry) => matchesLogQuery(entry, options))
.sort((a, b) => Date.parse(b.timestamp) - Date.parse(a.timestamp));
return entries.slice(0, options.limit ?? 200);
return entries.slice(0, limit);
}
export function readLogSourceSummaries(): LogSourceSummary[] {
@@ -0,0 +1,56 @@
import { afterEach, beforeEach, describe, expect, it, spyOn } from 'bun:test';
import * as fs from 'fs';
import * as os from 'os';
import * as path from 'path';
import { handleCleanupCommand } from '../../../src/commands/cleanup-command';
import { getCliproxyDir } from '../../../src/cliproxy/config-generator';
import { getNativeLogsDir } from '../../../src/services/logging';
describe('cleanup command', () => {
let tempHome = '';
let originalCcsHome: string | undefined;
beforeEach(() => {
originalCcsHome = process.env.CCS_HOME;
tempHome = fs.mkdtempSync(path.join(os.tmpdir(), 'ccs-cleanup-command-'));
process.env.CCS_HOME = tempHome;
});
afterEach(() => {
if (originalCcsHome !== undefined) {
process.env.CCS_HOME = originalCcsHome;
} else {
delete process.env.CCS_HOME;
}
fs.rmSync(tempHome, { recursive: true, force: true });
tempHome = '';
});
it('reports only top-level log sizes in dry-run mode', async () => {
const ccsLogsDir = getNativeLogsDir();
const archiveDir = path.join(ccsLogsDir, 'archive');
const cliproxyLogsDir = path.join(getCliproxyDir(), 'logs');
fs.mkdirSync(archiveDir, { recursive: true });
fs.mkdirSync(cliproxyLogsDir, { recursive: true });
fs.writeFileSync(path.join(ccsLogsDir, 'current.jsonl'), 'x'.repeat(100));
fs.writeFileSync(path.join(archiveDir, 'archived.jsonl.gz'), 'y'.repeat(2_000));
const logSpy = spyOn(console, 'log').mockImplementation(() => {});
try {
await handleCleanupCommand(['--dry-run']);
const output = logSpy.mock.calls
.flatMap((call) => call.map((value) => String(value)))
.join('\n');
expect(output).toContain('CCS Logs: 1 files (100.00 B)');
expect(output).toContain('Would delete 1 files (100.00 B)');
expect(output).not.toContain('1.95 KB');
} finally {
logSpy.mockRestore();
}
});
});
+13 -4
View File
@@ -1,6 +1,9 @@
import { describe, expect, test } from 'bun:test';
import { ROOT_COMMAND_CATALOG, getAllRootCommandTokens } from '../../../src/commands/command-catalog';
import {
ROOT_COMMAND_CATALOG,
getAllRootCommandTokens,
} from '../../../src/commands/command-catalog';
import { ROOT_COMMAND_ROUTES } from '../../../src/commands/root-command-router';
describe('command catalog', () => {
@@ -16,12 +19,18 @@ describe('command catalog', () => {
});
test('keeps hidden operational hooks out of the public help surface', () => {
const hiddenCommands = ROOT_COMMAND_CATALOG.filter((entry) => entry.visibility === 'hidden').map(
(entry) => entry.name
);
const hiddenCommands = ROOT_COMMAND_CATALOG.filter(
(entry) => entry.visibility === 'hidden'
).map((entry) => entry.name);
expect(hiddenCommands).toContain('--install');
expect(hiddenCommands).toContain('--uninstall');
expect(hiddenCommands).toContain('__complete');
});
test('describes cleanup as removing both CCS and CLIProxy logs', () => {
const cleanupCommand = ROOT_COMMAND_CATALOG.find((entry) => entry.name === 'cleanup');
expect(cleanupCommand?.summary).toBe('Remove old CCS and CLIProxy logs');
});
});
@@ -0,0 +1,172 @@
import { afterEach, beforeEach, describe, expect, it, spyOn } from 'bun:test';
import * as fs from 'fs';
import * as os from 'os';
import * as path from 'path';
import {
clearRecentLogEntries,
pushRecentLogEntry,
} from '../../../../src/services/logging/log-buffer';
import { getCurrentLogPath } from '../../../../src/services/logging/log-paths';
import { readLogEntries } from '../../../../src/services/logging/log-reader';
import type { LogEntry } from '../../../../src/services/logging/log-types';
function createEntry(overrides: Partial<LogEntry>): LogEntry {
return {
id: overrides.id ?? `entry-${Math.random().toString(36).slice(2, 8)}`,
timestamp: overrides.timestamp ?? new Date().toISOString(),
level: overrides.level ?? 'info',
source: overrides.source ?? 'unit:test',
event: overrides.event ?? 'test.event',
message: overrides.message ?? 'message',
processId: overrides.processId ?? 1234,
runId: overrides.runId ?? 'run-1',
context: overrides.context ?? {},
};
}
describe('log reader', () => {
let tempHome = '';
let originalCcsHome: string | undefined;
beforeEach(() => {
originalCcsHome = process.env.CCS_HOME;
tempHome = fs.mkdtempSync(path.join(os.tmpdir(), 'ccs-log-reader-'));
process.env.CCS_HOME = tempHome;
clearRecentLogEntries();
});
afterEach(() => {
if (originalCcsHome !== undefined) {
process.env.CCS_HOME = originalCcsHome;
} else {
delete process.env.CCS_HOME;
}
clearRecentLogEntries();
fs.rmSync(tempHome, { recursive: true, force: true });
tempHome = '';
});
it('caches unchanged current log file parses between reads', () => {
const currentLogPath = getCurrentLogPath();
fs.mkdirSync(path.dirname(currentLogPath), { recursive: true });
fs.writeFileSync(
currentLogPath,
`${JSON.stringify(
createEntry({
id: 'disk-entry',
message: 'Newest on-disk entry',
timestamp: '2026-04-08T11:00:00.000Z',
})
)}\n`
);
pushRecentLogEntry(
createEntry({
id: 'recent-1',
message: 'Buffered entry',
timestamp: '2026-04-08T10:00:00.000Z',
}),
250
);
const readSpy = spyOn(fs, 'readFileSync');
try {
const first = readLogEntries({ limit: 2 });
const second = readLogEntries({ limit: 2 });
expect(first.map((entry) => entry.id)).toEqual(['disk-entry', 'recent-1']);
expect(second.map((entry) => entry.id)).toEqual(['disk-entry', 'recent-1']);
expect(readSpy).toHaveBeenCalledTimes(1);
} finally {
readSpy.mockRestore();
}
});
it('refreshes the cached parse when the current log file changes', () => {
const currentLogPath = getCurrentLogPath();
fs.mkdirSync(path.dirname(currentLogPath), { recursive: true });
fs.writeFileSync(
currentLogPath,
`${JSON.stringify(
createEntry({
id: 'disk-old',
message: 'Older on-disk entry',
timestamp: '2026-04-08T11:00:00.000Z',
})
)}\n`
);
const readSpy = spyOn(fs, 'readFileSync');
try {
expect(readLogEntries({ limit: 1 }).map((entry) => entry.id)).toEqual(['disk-old']);
fs.writeFileSync(
currentLogPath,
`${JSON.stringify(
createEntry({
id: 'disk-new',
message: 'Newer on-disk entry',
timestamp: '2026-04-08T12:00:00.000Z',
})
)}\n`
);
expect(readLogEntries({ limit: 1 }).map((entry) => entry.id)).toEqual(['disk-new']);
expect(readSpy).toHaveBeenCalledTimes(2);
} finally {
readSpy.mockRestore();
}
});
it('keeps file-backed matches when buffered entries already satisfy the limit', () => {
const currentLogPath = getCurrentLogPath();
fs.mkdirSync(path.dirname(currentLogPath), { recursive: true });
fs.writeFileSync(
currentLogPath,
[
JSON.stringify(
createEntry({
id: 'disk-newest',
source: 'dashboard',
message: 'Newest dashboard entry on disk',
timestamp: '2026-04-08T12:30:00.000Z',
})
),
JSON.stringify(
createEntry({
id: 'disk-older',
source: 'dashboard',
message: 'Older dashboard entry on disk',
timestamp: '2026-04-08T10:30:00.000Z',
})
),
].join('\n') + '\n'
);
pushRecentLogEntry(
createEntry({
id: 'recent-middle',
source: 'dashboard',
message: 'Buffered dashboard entry',
timestamp: '2026-04-08T11:30:00.000Z',
}),
250
);
pushRecentLogEntry(
createEntry({
id: 'recent-oldest',
source: 'dashboard',
message: 'Oldest buffered dashboard entry',
timestamp: '2026-04-08T09:30:00.000Z',
}),
250
);
const entries = readLogEntries({ source: 'dashboard', limit: 2 });
expect(entries.map((entry) => entry.id)).toEqual(['disk-newest', 'recent-middle']);
});
});
@@ -0,0 +1,103 @@
import { describe, expect, it } from 'bun:test';
import { redactContext } from '../../../../src/services/logging/log-redaction';
describe('log redaction', () => {
it('redacts sensitive keys and preserves non-sensitive values', () => {
const redacted = redactContext({
token: 'secret-token',
api_key: 'secret-key',
safe: 'kept',
count: 3,
enabled: true,
});
expect(redacted).toEqual({
token: '[redacted]',
api_key: '[redacted]',
safe: 'kept',
count: 3,
enabled: true,
});
});
it('sanitizes nested objects and arrays recursively', () => {
const redacted = redactContext({
request: {
headers: {
authorization: 'Bearer abc',
cookie: 'session=123',
},
steps: [
{ secret: 'hidden' },
{ label: 'safe-step' },
['nested-array', { password_hash: 'hidden-hash' }],
],
},
});
expect(redacted).toEqual({
request: {
headers: {
authorization: '[redacted]',
cookie: '[redacted]',
},
steps: [
{ secret: '[redacted]' },
{ label: 'safe-step' },
['nested-array', { password_hash: '[redacted]' }],
],
},
});
});
it('caps recursive depth, truncates long strings, and preserves nullish values', () => {
const deeplyNested = {
first: {
second: {
third: {
fourth: {
fifth: {
sixth: 'too-deep',
},
},
},
},
},
};
const longValue = 'a'.repeat(2_500);
const redacted = redactContext({
nested: deeplyNested,
longValue,
nothing: null,
missing: undefined,
});
expect(redacted.nested).toEqual({
first: {
second: {
third: {
fourth: '[max-depth]',
},
},
},
});
expect(redacted.longValue).toBe(`${'a'.repeat(2_000)}...[truncated]`);
expect(redacted.nothing).toBeNull();
expect(redacted.missing).toBeUndefined();
});
it('reduces Error instances to safe name and message fields', () => {
const error = new Error('boom'.repeat(700));
error.name = 'ExplodedError';
const redacted = redactContext({ error });
expect(redacted).toEqual({
error: {
name: 'ExplodedError',
message: `${'boom'.repeat(500)}...[truncated]`,
},
});
});
});