Skip to content
Merged
Show file tree
Hide file tree
Changes from 14 commits
Commits
Show all changes
19 commits
Select commit Hold shift + click to select a range
4a8805e
feat(compute): add `compute logs <id>` — container stdout/stderr from…
tonychang04 Aug 27, 2026
51e7e36
fix(compute-logs): sanitize terminal escapes in human output; documen…
tonychang04 Aug 27, 2026
7574fca
fix(compute-logs): address review round 2 — telemetry, C1 controls, f…
tonychang04 Aug 27, 2026
ae71eba
chore(compute-logs): lint — const result, drop unused test import
tonychang04 Aug 27, 2026
db86956
chore(compute-logs): type test callbacks for tsc
tonychang04 Aug 27, 2026
5e2168d
fix(compute-logs): follow-loop retry, readable multi-line messages, i…
tonychang04 Aug 27, 2026
7d29de0
fix(compute-logs): same-timestamp dedupe keys; sanitize region/instance
tonychang04 Aug 27, 2026
01f4759
fix(compute-logs): clear stale follow cursor when the server stops re…
tonychang04 Aug 27, 2026
6b0dcea
fix(compute-logs): dedupe every follow poll — frozen cursor can't rep…
tonychang04 Aug 27, 2026
6bbdf43
fix(compute-logs): boundary dedupe by occurrence count, region in key
tonychang04 Aug 27, 2026
525a8b7
fix(compute-logs): only dedupe when the cursor did not advance
tonychang04 Aug 27, 2026
bd25fde
fix(compute-logs): don't block the tail on telemetry flush; handle un…
tonychang04 Aug 27, 2026
cd3bb32
fix(compute-logs): guard the follow watermark against NaN, future, an…
tonychang04 Aug 27, 2026
2cb375d
fix(compute-logs): treat implausibly future timestamps as undated eve…
tonychang04 Aug 27, 2026
1b94f6f
fix(compute-logs): scope the future-timestamp bound per page, not to …
tonychang04 Aug 27, 2026
e514b59
fix(compute-logs): make clock trust sticky, not per-page
tonychang04 Aug 28, 2026
e1ca55c
fix(compute-logs): key the undated dedupe on timestamp too
tonychang04 Aug 28, 2026
e784f82
fix(compute-logs): retry the initial fetch in follow mode too
tonychang04 Aug 28, 2026
67ba77d
fix(compute-logs): announce the tail before the first fetch, and each…
tonychang04 Aug 28, 2026
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 11 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -1091,6 +1091,17 @@ Get compute service machine events (start/stop/exit/restart).
npx @insforge/cli compute events my-api --limit 50
```

#### `npx @insforge/cli compute logs <id>`

Get container stdout/stderr (application logs) — the same data as the dashboard's Logs panel. Use `compute events` for machine lifecycle events instead.

```bash
npx @insforge/cli compute logs my-api --limit 200
npx @insforge/cli compute logs my-api --follow # poll for new lines every 2s
npx @insforge/cli --json compute logs my-api # { lines, nextToken } — pass nextToken back via --next-token to page forward
npx @insforge/cli --json compute logs my-api --follow # NDJSON: one {timestamp, message, ...} object per line
```

#### `npx @insforge/cli compute delete <id>`

Delete a compute service and its Fly.io resources.
Expand Down
6 changes: 3 additions & 3 deletions src/commands/compute/events.ts
Original file line number Diff line number Diff line change
Expand Up @@ -7,9 +7,9 @@ import { reportCliUsage } from '../../lib/skills.js';
import { trackCommandUsage } from '../../lib/command-telemetry.js';

// `compute events <id>` returns Fly machine lifecycle events (start/stop/exit/
// restart) — not container stdout/stderr. The previous name `compute logs`
// was misleading; container log streaming is roadmap work and will reuse the
// freshly-vacated `logs` command name when it lands.
// restart) — not container stdout/stderr. For container logs use
// `compute logs <id>`. (This command was originally named `compute logs`,
// which was misleading.)
export function registerComputeEventsCommand(computeCmd: Command): void {
computeCmd
.command('events <id>')
Expand Down
350 changes: 350 additions & 0 deletions src/commands/compute/logs.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,350 @@
import { describe, expect, it, vi, beforeEach, afterEach } from 'vitest';
import type * as ErrorsModule from '../../lib/errors.js';
import { CLIError } from '../../lib/errors.js';

const ossFetchMock = vi.hoisted(() => vi.fn());
const outputJsonMock = vi.hoisted(() => vi.fn());
vi.mock('../../lib/api/oss.js', () => ({ ossFetch: ossFetchMock }));
vi.mock('../../lib/credentials.js', () => ({ requireAuth: vi.fn().mockResolvedValue(undefined) }));
const trackCommandUsageMock = vi.hoisted(() => vi.fn());
vi.mock('../../lib/command-telemetry.js', () => ({ trackCommandUsage: trackCommandUsageMock }));
vi.mock('../../lib/output.js', () => ({ outputJson: outputJsonMock }));
vi.mock('../../lib/errors.js', async (importOriginal) => {
const actual = await importOriginal<typeof ErrorsModule>();
return {
...actual,
handleError: (err: unknown) => { throw err; },
};
});

import { Command } from 'commander';
import { registerComputeLogsCommand, sanitizeLogMessage, parseLimit, formatLogLine } from './logs.js';

const ESC = String.fromCharCode(0x1b);
const BEL = String.fromCharCode(0x07);
const CSI_C1 = String.fromCharCode(0x9b); // 8-bit CSI

function run(args: string[]) {
const cmd = new Command();
cmd.exitOverride();
cmd.option('--json');
const compute = cmd.command('compute');
registerComputeLogsCommand(compute);
return cmd.parseAsync(['node', 'insforge', ...args]);
}

function page(lines: unknown[], nextToken: string | null = null) {
return { json: async () => ({ lines, nextToken }) };
}

describe('compute logs', () => {
Comment thread
cubic-dev-ai[bot] marked this conversation as resolved.
let logSpy: ReturnType<typeof vi.spyOn>;
let errSpy: ReturnType<typeof vi.spyOn>;
beforeEach(() => {
ossFetchMock.mockReset();
outputJsonMock.mockReset();
trackCommandUsageMock.mockReset();
logSpy = vi.spyOn(console, 'log').mockImplementation(() => {});
errSpy = vi.spyOn(console, 'error').mockImplementation(() => {});
});
afterEach(() => {
logSpy.mockRestore();
errSpy.mockRestore();
vi.useRealTimers();
});

it('calls the container logs endpoint with a clamped limit', async () => {
ossFetchMock.mockResolvedValueOnce(page([]));
await run(['compute', 'logs', 'my api', '--limit', '5000']);
expect(ossFetchMock).toHaveBeenCalledWith('/api/compute/services/my%20api/logs?limit=1000');
expect(logSpy).toHaveBeenCalledWith('No logs found.');
});

it('forwards --next-token as next_token', async () => {
ossFetchMock.mockResolvedValueOnce(page([]));
await run(['compute', 'logs', 'svc', '--next-token', 'abc']);
expect(ossFetchMock.mock.calls[0][0]).toBe('/api/compute/services/svc/logs?limit=100&next_token=abc');
});

it('prints formatted lines', async () => {
ossFetchMock.mockResolvedValueOnce(page(
[{ timestamp: 0, message: 'hello', region: 'sjc', instance: 'abc123' }], 'tok',
));
await run(['compute', 'logs', 'svc']);
expect(logSpy).toHaveBeenCalledWith('1970-01-01T00:00:00.000Z [sjc abc123] hello');
});

it('emits the full result (with cursor) under --json, sanitized', async () => {
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: `x${CSI_C1}31my` }], 'tok'));
await run(['--json', 'compute', 'logs', 'svc']);
expect(outputJsonMock).toHaveBeenCalledWith({
lines: [{ timestamp: 1, message: 'x31my' }],
nextToken: 'tok',
});
});

it('--follow forwards the cursor on the next poll and prints per batch', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: 'one' }], 'tokA'));
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 2, message: 'two' }], 'tokB'));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
expect(logSpy).toHaveBeenCalledWith('1970-01-01T00:00:00.001Z one');
await vi.advanceTimersByTimeAsync(2000);
expect(ossFetchMock.mock.calls[1][0]).toBe('/api/compute/services/svc/logs?limit=100&next_token=tokA');
expect(logSpy).toHaveBeenCalledWith('1970-01-01T00:00:00.002Z two');
await vi.advanceTimersByTimeAsync(2000);
expect(ossFetchMock.mock.calls[2][0]).toBe('/api/compute/services/svc/logs?limit=100&next_token=tokB');
});

it('--follow without a cursor drops already-printed lines on refetch', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 5, message: 'seen' }], null));
ossFetchMock.mockResolvedValueOnce(page([
{ timestamp: 5, message: 'seen' },
{ timestamp: 5, message: 'sibling' },
{ timestamp: 9, message: 'fresh' },
], null));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
expect(ossFetchMock.mock.calls[1][0]).toBe('/api/compute/services/svc/logs?limit=100');
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('seen'))).toHaveLength(1);
expect(printed.filter((l: string) => l.includes('sibling'))).toHaveLength(1);
expect(printed.some((l: string) => l.includes('fresh'))).toBe(true);
});

it('--follow does not reprint a frozen cursor batch', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: 'one' }], 'tokA'));
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: 'one' }], 'tokA'));
ossFetchMock.mockResolvedValueOnce(page([
{ timestamp: 1, message: 'one' },
{ timestamp: 2, message: 'two' },
], 'tokA'));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('one'))).toHaveLength(1);
expect(printed.filter((l: string) => l.includes('two'))).toHaveLength(1);
});

it('--follow clears a stale cursor when the server stops returning one', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: 'one' }], 'tokA'));
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 2, message: 'two' }], null));
ossFetchMock.mockResolvedValueOnce(page([
{ timestamp: 2, message: 'two' },
{ timestamp: 3, message: 'three' },
], null));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000); // poll 1: uses tokA, returns null cursor
await vi.advanceTimersByTimeAsync(2000); // poll 2: must NOT reuse tokA
expect(ossFetchMock.mock.calls[1][0]).toBe('/api/compute/services/svc/logs?limit=100&next_token=tokA');
expect(ossFetchMock.mock.calls[2][0]).toBe('/api/compute/services/svc/logs?limit=100');
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('two'))).toHaveLength(1);
expect(printed.some((l: string) => l.includes('three'))).toBe(true);
});

it('--follow keeps genuinely repeated identical lines at the boundary timestamp', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([
{ timestamp: 5, message: 'dup' },
{ timestamp: 5, message: 'dup' },
], null));
ossFetchMock.mockResolvedValueOnce(page([
{ timestamp: 5, message: 'dup' },
{ timestamp: 5, message: 'dup' },
{ timestamp: 5, message: 'dup' },
], null));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('dup'))).toHaveLength(3);
});

it('--follow prints an advancing-cursor page verbatim, even within one millisecond', async () => {
vi.useFakeTimers();
// Docker cursors are nanosecond precision; both pages share a millisecond.
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1000, message: 'tick' }], 'ns1'));
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1000, message: 'tick' }], 'ns2'));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('tick'))).toHaveLength(2);
});

it('--follow prints an older-timestamp line arriving behind a new cursor', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 5000, message: 'newer' }], 'ns1'));
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 0, message: 'unparseable-ts' }], 'ns2'));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.some((l: string) => l.includes('unparseable-ts'))).toBe(true);
});

it('--follow prints a line with an unusable timestamp instead of dropping it', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 5000, message: 'newer' }], null));
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: null, message: 'no-ts' }], null));
// Same window re-sent: the undated line must not repeat.
ossFetchMock.mockResolvedValue(page([{ timestamp: null, message: 'no-ts' }], null));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
await vi.advanceTimersByTimeAsync(2000);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('no-ts'))).toHaveLength(1);
});

it('--follow ignores an implausibly future timestamp when advancing the watermark', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([
{ timestamp: 1000, message: 'real' },
{ timestamp: 4102444800000, message: 'year-2100' },
], null));
ossFetchMock.mockResolvedValue(page([{ timestamp: 2000, message: 'later-real' }], null));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.some((l: string) => l.includes('later-real'))).toBe(true);
});

it('--follow does not reprint a future-dated line on every poll', async () => {
vi.useFakeTimers();
const future = Date.now() + 60 * 60 * 1000;
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1000, message: 'real' }], null));
ossFetchMock.mockResolvedValue(page([
{ timestamp: 1000, message: 'real' },
{ timestamp: future, message: 'from-the-future' },
], null));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
await vi.advanceTimersByTimeAsync(2000);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('from-the-future'))).toHaveLength(1);
});

it('--follow does not reprint dated lines when a page also carries an undated one', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1000, message: 'dated' }], null));
ossFetchMock.mockResolvedValue(page([
{ timestamp: 1000, message: 'dated' },
{ timestamp: null, message: 'undated' },
], null));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000);
await vi.advanceTimersByTimeAsync(2000);
const printed = logSpy.mock.calls.map((c: unknown[]) => String(c[0]));
expect(printed.filter((l: string) => l.includes('dated') && !l.includes('undated'))).toHaveLength(1);
});

it('emits stable telemetry for the command', async () => {
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: 'x' }], null));
await run(['compute', 'logs', 'svc']);
expect(trackCommandUsageMock).toHaveBeenCalledWith('compute', 'logs', true, {
result_count: 1,
follow: false,
});
});

it('--follow retries transient poll failures and keeps tailing', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: 'one' }], 'tokA'));
ossFetchMock.mockRejectedValueOnce(new CLIError('rate limited', 1, 'RATE_LIMITED', 429));
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 2, message: 'two' }], 'tokB'));
ossFetchMock.mockResolvedValue(page([]));
void run(['compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
await vi.advanceTimersByTimeAsync(2000); // poll 1 -> 429
await vi.advanceTimersByTimeAsync(4000); // backoff
await vi.advanceTimersByTimeAsync(2000); // poll 2 -> succeeds
expect(logSpy).toHaveBeenCalledWith('1970-01-01T00:00:00.002Z two');
});

it('--json --follow emits NDJSON per line', async () => {
vi.useFakeTimers();
ossFetchMock.mockResolvedValueOnce(page([{ timestamp: 1, message: 'a' }], 'tok'));
ossFetchMock.mockResolvedValue(page([]));
void run(['--json', 'compute', 'logs', 'svc', '--follow']);
await vi.advanceTimersByTimeAsync(0);
expect(logSpy).toHaveBeenCalledWith(JSON.stringify({ timestamp: 1, message: 'a' }));
expect(outputJsonMock).not.toHaveBeenCalled();
});
});

describe('fetchComputeLogs boundary', () => {
it('normalizes the shape, sanitizes strings, and drops an empty cursor to null', async () => {
ossFetchMock.mockResolvedValueOnce({
json: async () => ({
lines: [{ timestamp: 7, message: `a${ESC}[31mb`, region: `s${ESC}[0mjc`, instance: 'i1', extra: 'dropped' }],
nextToken: '',
}),
});
const { fetchComputeLogs } = await import('./logs.js');
const out = await fetchComputeLogs('svc', { limit: 10 });
expect(out).toEqual({
lines: [{ timestamp: 7, message: 'ab', region: 'sjc', instance: 'i1' }],
nextToken: null,
});
});

it('tolerates a malformed body', async () => {
ossFetchMock.mockResolvedValueOnce({ json: async () => null });
const { fetchComputeLogs } = await import('./logs.js');
expect(await fetchComputeLogs('svc', { limit: 10 })).toEqual({ lines: [], nextToken: null });
});
});

describe('sanitizeLogMessage', () => {
it('strips ANSI CSI/OSC sequences and control chars, keeps tabs', () => {
expect(sanitizeLogMessage(`${ESC}[31mred${ESC}[0m ok`)).toBe('red ok');
expect(sanitizeLogMessage(`${ESC}]0;evil title${BEL}text`)).toBe('text');
expect(sanitizeLogMessage('a\rb\nc')).toBe('a b c');
expect(sanitizeLogMessage('keep\ttabs')).toBe('keep\ttabs');
});

it('strips 8-bit C1 controls (CSI/OSC without ESC)', () => {
expect(sanitizeLogMessage(`x${CSI_C1}31my`)).toBe('x31my');
expect(sanitizeLogMessage(String.fromCharCode(0x90) + 'dcs')).toBe('dcs');
});
});

describe('formatLogLine', () => {
it('falls back to the raw value instead of throwing on a bad timestamp', () => {
expect(formatLogLine({ timestamp: Number.NaN, message: 'm' })).toContain('m');
expect(() => formatLogLine({ timestamp: undefined as unknown as number, message: 'm' })).not.toThrow();
});
});

describe('parseLimit', () => {
it('clamps into 1-1000 and defaults malformed input', () => {
expect(parseLimit('0')).toBe(1);
expect(parseLimit('5000')).toBe(1000);
expect(parseLimit('abc')).toBe(100);
expect(parseLimit('')).toBe(100);
expect(parseLimit(undefined)).toBe(100);
expect(parseLimit('250')).toBe(250);
});
});
Loading
Loading