From 102396b9bb7e3e4f8ff562cbe8d46fbac511145d Mon Sep 17 00:00:00 2001 From: "ellipsis-dev[bot]" <65095814+ellipsis-dev[bot]@users.noreply.github.com> Date: Sun, 5 Jul 2026 22:05:57 +0000 Subject: [PATCH] Hook observability: sync activity log, stats.json, `agent hooks logs/stats` MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit In hook mode `agent session sync` is a quiet no-op on every failure path by design, which made background sync failures invisible. Now every sync attempt appends one JSONL line to $ELLIPSIS_CONFIG_DIR/hooks/sync.log.jsonl (capped, best-effort — a logging failure never breaks the exit-0 guarantee) and atomically rewrites hooks/stats.json, a plain JSON object anything can read without invoking the CLI. - `agent hooks logs [--tail N] [--failures] [--json]`: did the background process fail, and why (outcomes: synced / skipped_unenrolled / not_logged_in / no_transcript / spooled / rejected) - `agent hooks stats [--json]`: last sync, last error, 24h synced/failed counts, pending spool, total synced, recent v1 session ids - `agent hooks status`: one-line sync summary appended --- src/commands/hooks.ts | 115 +++++++++++++++++++++++++++- src/commands/session.tsx | 44 ++++++++--- src/lib/laptop.ts | 159 +++++++++++++++++++++++++++++++++++++++ test/laptop.test.ts | 124 ++++++++++++++++++++++++++++++ 4 files changed, 429 insertions(+), 13 deletions(-) create mode 100644 test/laptop.test.ts diff --git a/src/commands/hooks.ts b/src/commands/hooks.ts index 0856a0a..5fe811a 100644 --- a/src/commands/hooks.ts +++ b/src/commands/hooks.ts @@ -1,14 +1,21 @@ import type { Command } from 'commander' -import { printJson, printTable, runAction } from '../lib/output' +import { formatTs, printJson, printTable, runAction } from '../lib/output' +import { toInt } from '../lib/args' import { claudeSettingsPath, enrollRepo, enrolledRepos, + hookStatsPath, hooksInstalled, installHooks, + readHookStats, + readSyncLog, repoFromCwd, + spooledPendingCount, + syncLogPath, unenrollRepo, uninstallHooks, + type HookSyncStats, } from '../lib/laptop' // `agent hooks …` — manage the Claude Code hooks + per-repo enrollment that @@ -76,8 +83,14 @@ export function registerHooks(program: Command): void { runAction(async () => { const installed = hooksInstalled() const enrolled = enrolledRepos() + const stats = readHookStats() if (opts.json) { - printJson({ settings: claudeSettingsPath(), hooks: installed, enrolled_repos: enrolled }) + printJson({ + settings: claudeSettingsPath(), + hooks: installed, + enrolled_repos: enrolled, + sync_stats: stats ?? null, + }) return } printTable( @@ -87,6 +100,91 @@ export function registerHooks(program: Command): void { console.log('') if (enrolled.length === 0) console.log('Enrolled repositories: none') else printTable(['ENROLLED REPOSITORY'], enrolled.map((r) => [r])) + if (stats?.last_sync_at) { + console.log('') + console.log( + `Last sync ${ago(stats.last_sync_at)} (${stats.last_outcome}) · ` + + `${stats.synced_24h} synced / ${stats.failed_24h} failed in 24h · ` + + `${spooledPendingCount()} spooled pending`, + ) + } + }), + ) + + hooks + .command('logs') + .description('Show the activity log the background `agent session sync` hooks write') + .option('-n, --tail ', 'show the last N entries', toInt, 20) + .option('--failures', 'only show entries whose outcome is not "synced"') + .option('--json', 'print NDJSON (one log entry per line)') + .action(async (opts: { tail: number; failures?: boolean; json?: boolean }) => + runAction(async () => { + let entries = readSyncLog() + if (opts.failures) entries = entries.filter((e) => e.outcome !== 'synced') + entries = entries.slice(-Math.max(0, opts.tail)) + if (opts.json) { + for (const e of entries) console.log(JSON.stringify(e)) + return + } + if (entries.length === 0) { + console.log( + opts.failures + ? 'No sync failures logged.' + : `No sync activity logged yet (${syncLogPath()}).`, + ) + return + } + printTable( + ['TIME', 'OUTCOME', 'REPO', 'REASON', 'DETAIL'], + entries.map((e) => [ + formatTs(e.ts), + e.outcome, + e.repo ?? '—', + e.reason ?? '—', + e.outcome === 'synced' + ? `${e.event_count ?? '?'} events → ${e.session_id ?? '?'}` + : e.error ?? '', + ]), + ) + }), + ) + + hooks + .command('stats') + .description('Show sync stats from the plain-JSON stats object the hooks maintain') + .option('--json', 'print the raw stats object') + .action(async (opts: { json?: boolean }) => + runAction(async () => { + const stats = readHookStats() + if (!stats) { + if (opts.json) { + printJson(null) + return + } + console.log(`No sync stats yet (${hookStatsPath()}). Nothing has attempted to sync.`) + return + } + // spooled_pending in the file is a snapshot from the last sync; the + // spool dir is cheap to count, so show it live. + const live: HookSyncStats = { ...stats, spooled_pending: spooledPendingCount() } + if (opts.json) { + printJson(live) + return + } + console.log(`stats file: ${hookStatsPath()}`) + console.log( + `last sync: ${live.last_sync_at ? `${formatTs(live.last_sync_at)} (${ago(live.last_sync_at)})` : '—'}`, + ) + console.log(`last outcome: ${live.last_outcome ?? '—'}`) + if (live.last_error) console.log(`last error: ${live.last_error}`) + console.log(`synced (24h): ${live.synced_24h}`) + console.log(`failed (24h): ${live.failed_24h}`) + console.log(`spooled pending: ${live.spooled_pending}`) + console.log(`total synced: ${live.total_synced}`) + if (live.recent_session_ids.length) { + console.log('recent sessions:') + for (const id of live.recent_session_ids) console.log(` ${id}`) + } }), ) @@ -116,3 +214,16 @@ export function registerHooks(program: Command): void { }), ) } + +// Coarse relative time ("4m ago") for the status/stats one-liners. +export function ago(iso: string): string { + const ms = Date.now() - Date.parse(iso) + if (!Number.isFinite(ms) || ms < 0) return iso + const s = Math.floor(ms / 1000) + if (s < 60) return `${s}s ago` + const m = Math.floor(s / 60) + if (m < 60) return `${m}m ago` + const h = Math.floor(m / 60) + if (h < 24) return `${h}h ago` + return `${Math.floor(h / 24)}d ago` +} diff --git a/src/commands/session.tsx b/src/commands/session.tsx index da44ab0..1a6179e 100644 --- a/src/commands/session.tsx +++ b/src/commands/session.tsx @@ -30,9 +30,11 @@ import { enrolledRepos, listSpooledSyncs, pushHandoffRef, + recordSyncOutcome, redactLine, repoFromCwd, spoolSync, + type SyncOutcome, } from '../lib/laptop' import { ApiError } from '../lib/api' import { resolveToken } from '../lib/config' @@ -625,9 +627,6 @@ async function syncTranscript(opts: { // Hook mode = driven by CC (stdin context, no explicit flags): all failure // paths are silent no-ops so they never surface into the session. const hookMode = hook !== undefined && !opts.transcript && !opts.sessionId - const quit = (message: string): void => { - if (!hookMode) throw new Error(message) - } const ccSessionId = opts.sessionId ?? hook?.session_id const transcriptPath = opts.transcript ?? hook?.transcript_path @@ -638,20 +637,33 @@ async function syncTranscript(opts: { : hook?.hook_event_name === 'SessionEnd' ? 'session_end' : 'stop' + const repo = repoFromCwd(cwd) + + // Hook mode is quiet on every failure path, so the local activity log + // (hooks/sync.log.jsonl + stats.json, surfaced by `agent hooks logs/stats`) + // is the only place a failed background sync is observable. Recording is + // best-effort and never throws, preserving the exit-0 guarantee. + const quit = (outcome: SyncOutcome, message: string): void => { + recordSyncOutcome({ outcome, cc_session_id: ccSessionId, repo, reason, error: message }) + if (!hookMode) throw new Error(message) + } + if (!ccSessionId || !transcriptPath) { - return quit('need --session-id and --transcript (or hook JSON on stdin)') + return quit('rejected', 'need --session-id and --transcript (or hook JSON on stdin)') } // Consent gate: per-repo opt-in, silently skipped otherwise. - const repo = repoFromCwd(cwd) if (!repo || !enrolledRepos().includes(repo.toLowerCase())) { - return quit(`repository ${repo ?? `at ${cwd}`} is not enrolled (agent hooks enroll)`) + return quit( + 'skipped_unenrolled', + `repository ${repo ?? `at ${cwd}`} is not enrolled (agent hooks enroll)`, + ) } if (!resolveToken()) { - return quit('not logged in. Run `agent login` first, or set ELLIPSIS_API_TOKEN.') + return quit('not_logged_in', 'not logged in. Run `agent login` first, or set ELLIPSIS_API_TOKEN.') } if (!existsSync(transcriptPath)) { - return quit(`transcript not found: ${transcriptPath}`) + return quit('no_transcript', `transcript not found: ${transcriptPath}`) } // Redact line-by-line (secrets never leave the laptop unredacted), then @@ -660,7 +672,9 @@ async function syncTranscript(opts: { .split('\n') .filter((l) => l.trim().length > 0) .map(redactLine) - if (lines.length === 0) return quit(`transcript is empty: ${transcriptPath}`) + if (lines.length === 0) { + return quit('no_transcript', `transcript is empty: ${transcriptPath}`) + } const req: SyncAgentSessionRequest = { cc_session_id: ccSessionId, @@ -674,6 +688,14 @@ async function syncTranscript(opts: { const api = new ApiClient() try { const res = await api.syncAgentSession(req) + recordSyncOutcome({ + outcome: 'synced', + cc_session_id: ccSessionId, + repo, + reason, + session_id: res.session_id, + event_count: res.event_count, + }) if (opts.json) printJson(res) else if (!hookMode) { console.log( @@ -686,11 +708,11 @@ async function syncTranscript(opts: { // Spool (latest snapshot per session wins) and stay quiet in hook mode — // the next sync flushes it. spoolSync(req) - if (!hookMode) throw err + quit('spooled', (err as Error).message) return } // Permanent rejection (auth, validation, payload too large): never spool. - if (!hookMode) throw err + quit('rejected', (err as Error).message) return } diff --git a/src/lib/laptop.ts b/src/lib/laptop.ts index 7578864..9313e50 100644 --- a/src/lib/laptop.ts +++ b/src/lib/laptop.ts @@ -15,6 +15,7 @@ import { mkdirSync, readFileSync, readdirSync, + renameSync, unlinkSync, writeFileSync, } from 'node:fs' @@ -266,6 +267,164 @@ export function dropSpooledSync(file: string): void { } } +// Cheap count of spooled (retriable, not-yet-delivered) syncs, without +// parsing them — used by the hook stats object. +export function spooledPendingCount(): number { + const dir = spoolDir() + if (!existsSync(dir)) return 0 + return readdirSync(dir).filter((n) => n.endsWith('.json')).length +} + +// --------------------------------------------------------------------------- +// Hook observability. In hook mode `agent session sync` is a quiet no-op on +// every failure path by design (async hooks' output is discarded and a broken +// sync must never disturb a Claude Code session), so nothing is visible in the +// session itself. Instead, every sync attempt appends one JSONL line to +// hooks/sync.log.jsonl (read by `agent hooks logs`) and atomically rewrites +// hooks/stats.json — a plain JSON object anything can read without invoking +// the CLI (read by `agent hooks stats`). All of it is best-effort: a logging +// failure stays silent so hook mode keeps its exit-0 guarantee. +// --------------------------------------------------------------------------- + +export type SyncOutcome = + | 'synced' // delivered to POST /v1/sessions/sync + | 'skipped_unenrolled' // consent gate: repo not enrolled (or no git remote) + | 'not_logged_in' // no token anywhere + | 'no_transcript' // transcript path missing/empty on disk + | 'spooled' // retriable failure (network / 5xx); queued for the next sync + | 'rejected' // permanent failure (4xx / bad invocation); never retried + +export interface SyncLogEntry { + ts: string // ISO-8601, when the attempt finished + outcome: SyncOutcome + cc_session_id?: string + repo?: string + reason?: string // stop | session_end + session_id?: string // v1 API session id (synced only) + event_count?: number // events the server acknowledged (synced only) + error?: string // failure detail (non-synced outcomes) +} + +// The stats object rewritten on every sync. 24h windows are derived from the +// activity log; total_synced is carried forward so the log cap can't shrink it. +export interface HookSyncStats { + last_sync_at?: string // ts of the most recent attempt (any outcome) + last_outcome?: SyncOutcome + last_error?: string // error of the most recent failed attempt + synced_24h: number + failed_24h: number // not_logged_in / no_transcript / spooled / rejected + spooled_pending: number + total_synced: number + recent_session_ids: string[] // distinct v1 session ids, most recent first +} + +// The log is an audit trail for "did that background sync fail, and why", +// not unbounded history — keep the newest N lines. +const SYNC_LOG_MAX_LINES = 1000 +const RECENT_SESSION_IDS_MAX = 10 + +const FAILURE_OUTCOMES: ReadonlySet = new Set([ + 'not_logged_in', + 'no_transcript', + 'spooled', + 'rejected', +]) + +function hooksDir(): string { + return join( + process.env.ELLIPSIS_CONFIG_DIR ?? join(homedir(), '.config', 'ellipsis'), + 'hooks', + ) +} + +export function syncLogPath(): string { + return join(hooksDir(), 'sync.log.jsonl') +} + +export function hookStatsPath(): string { + return join(hooksDir(), 'stats.json') +} + +// stats.json readers may race a hook's rewrite, so writes go through a +// same-directory temp file + rename (atomic on POSIX). +function writeFileAtomic(path: string, data: string): void { + const tmp = `${path}.${process.pid}.tmp` + writeFileSync(tmp, data, { mode: 0o600 }) + renameSync(tmp, path) +} + +export function readSyncLog(): SyncLogEntry[] { + const path = syncLogPath() + if (!existsSync(path)) return [] + const out: SyncLogEntry[] = [] + for (const line of readFileSync(path, 'utf8').split('\n')) { + if (!line.trim()) continue + try { + out.push(JSON.parse(line) as SyncLogEntry) + } catch { + // A torn line from a crashed hook — skip it, keep the rest. + } + } + return out +} + +export function readHookStats(): HookSyncStats | undefined { + try { + return JSON.parse(readFileSync(hookStatsPath(), 'utf8')) as HookSyncStats + } catch { + return undefined + } +} + +export function computeHookStats( + entries: SyncLogEntry[], + totalSynced: number, + now: Date = new Date(), +): HookSyncStats { + const dayAgo = now.getTime() - 24 * 60 * 60 * 1000 + const recent = entries.filter((e) => Date.parse(e.ts) >= dayAgo) + const last = entries[entries.length - 1] + const lastFailed = [...entries].reverse().find((e) => FAILURE_OUTCOMES.has(e.outcome)) + const recentIds: string[] = [] + for (const e of [...entries].reverse()) { + if (e.outcome !== 'synced' || !e.session_id) continue + if (recentIds.includes(e.session_id)) continue + recentIds.push(e.session_id) + if (recentIds.length >= RECENT_SESSION_IDS_MAX) break + } + return { + last_sync_at: last?.ts, + last_outcome: last?.outcome, + last_error: lastFailed?.error, + synced_24h: recent.filter((e) => e.outcome === 'synced').length, + failed_24h: recent.filter((e) => FAILURE_OUTCOMES.has(e.outcome)).length, + spooled_pending: spooledPendingCount(), + total_synced: totalSynced, + recent_session_ids: recentIds, + } +} + +// Append one attempt to the activity log (capped) and rewrite stats.json. +// Never throws: observability must not break the hook-mode exit-0 guarantee. +export function recordSyncOutcome(entry: Omit): void { + try { + mkdirSync(hooksDir(), { recursive: true }) + const full: SyncLogEntry = { ts: new Date().toISOString(), ...entry } + const entries = [...readSyncLog(), full].slice(-SYNC_LOG_MAX_LINES) + writeFileAtomic(syncLogPath(), entries.map((e) => JSON.stringify(e)).join('\n') + '\n') + // total_synced carries forward from the previous stats object (the log is + // capped, so recounting it would shrink the total); first write falls back + // to counting whatever history the log holds. + const prevTotal = + readHookStats()?.total_synced ?? + entries.filter((e) => e.outcome === 'synced' && e !== full).length + const total = prevTotal + (full.outcome === 'synced' ? 1 : 0) + writeFileAtomic(hookStatsPath(), JSON.stringify(computeHookStats(entries, total), null, 2) + '\n') + } catch { + // Best-effort by design. + } +} + // --------------------------------------------------------------------------- // Handoff (design §7.2): snapshot the dirty working tree WITHOUT disturbing it // and push it somewhere the cloud sandbox can fetch. diff --git a/test/laptop.test.ts b/test/laptop.test.ts new file mode 100644 index 0000000..f078eea --- /dev/null +++ b/test/laptop.test.ts @@ -0,0 +1,124 @@ +import { afterEach, beforeEach, describe, expect, it } from 'vitest' +import { existsSync, mkdirSync, mkdtempSync, readFileSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { + computeHookStats, + hookStatsPath, + readHookStats, + readSyncLog, + recordSyncOutcome, + spooledPendingCount, + syncLogPath, + type HookSyncStats, + type SyncLogEntry, +} from '../src/lib/laptop' + +// Each test gets a throwaway ELLIPSIS_CONFIG_DIR so the hook activity log and +// stats object are written to a known place, never the real ~/.config. +let dir: string + +beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'ellipsis-hooks-')) + process.env.ELLIPSIS_CONFIG_DIR = dir +}) + +afterEach(() => { + delete process.env.ELLIPSIS_CONFIG_DIR + rmSync(dir, { recursive: true, force: true }) +}) + +describe('recordSyncOutcome / readSyncLog', () => { + it('appends one JSONL entry per attempt with a timestamp', () => { + recordSyncOutcome({ outcome: 'synced', cc_session_id: 'cc1', repo: 'o/r', reason: 'stop', session_id: 's1', event_count: 3 }) + recordSyncOutcome({ outcome: 'spooled', cc_session_id: 'cc2', repo: 'o/r', reason: 'session_end', error: 'fetch failed' }) + const entries = readSyncLog() + expect(entries).toHaveLength(2) + expect(entries[0].outcome).toBe('synced') + expect(entries[0].session_id).toBe('s1') + expect(entries[1].outcome).toBe('spooled') + expect(entries[1].error).toBe('fetch failed') + expect(Date.parse(entries[0].ts)).not.toBeNaN() + }) + + it('skips torn lines instead of failing', () => { + recordSyncOutcome({ outcome: 'synced', session_id: 's1' }) + writeFileSync(syncLogPath(), readFileSync(syncLogPath(), 'utf8') + '{"truncat') + expect(readSyncLog()).toHaveLength(1) + }) + + it('returns [] when nothing has been logged', () => { + expect(readSyncLog()).toEqual([]) + expect(readHookStats()).toBeUndefined() + }) +}) + +describe('stats object', () => { + it('is rewritten on every attempt and readable as plain JSON', () => { + recordSyncOutcome({ outcome: 'synced', session_id: 's1', event_count: 2 }) + recordSyncOutcome({ outcome: 'rejected', error: 'boom' }) + expect(existsSync(hookStatsPath())).toBe(true) + const stats = JSON.parse(readFileSync(hookStatsPath(), 'utf8')) as HookSyncStats + expect(stats.last_outcome).toBe('rejected') + expect(stats.last_error).toBe('boom') + expect(stats.synced_24h).toBe(1) + expect(stats.failed_24h).toBe(1) + expect(stats.total_synced).toBe(1) + expect(stats.recent_session_ids).toEqual(['s1']) + expect(readHookStats()).toEqual(stats) + }) + + it('does not count skipped_unenrolled as a failure', () => { + recordSyncOutcome({ outcome: 'skipped_unenrolled', error: 'not enrolled' }) + const stats = readHookStats() + expect(stats?.failed_24h).toBe(0) + expect(stats?.synced_24h).toBe(0) + expect(stats?.last_outcome).toBe('skipped_unenrolled') + }) + + it('carries total_synced forward across writes', () => { + recordSyncOutcome({ outcome: 'synced', session_id: 's1' }) + recordSyncOutcome({ outcome: 'synced', session_id: 's2' }) + recordSyncOutcome({ outcome: 'spooled', error: 'offline' }) + expect(readHookStats()?.total_synced).toBe(2) + }) +}) + +describe('computeHookStats', () => { + const entry = (over: Partial): SyncLogEntry => ({ + ts: new Date().toISOString(), + outcome: 'synced', + ...over, + }) + + it('windows 24h counts and dedupes recent session ids (newest first)', () => { + const now = new Date('2026-07-05T12:00:00Z') + const old = '2026-07-01T12:00:00Z' + const fresh = '2026-07-05T11:00:00Z' + const stats = computeHookStats( + [ + entry({ ts: old, session_id: 'old' }), + entry({ ts: fresh, session_id: 'a' }), + entry({ ts: fresh, session_id: 'a' }), + entry({ ts: fresh, outcome: 'rejected', error: 'nope' }), + entry({ ts: fresh, session_id: 'b' }), + ], + 7, + now, + ) + expect(stats.synced_24h).toBe(3) + expect(stats.failed_24h).toBe(1) + expect(stats.total_synced).toBe(7) + expect(stats.recent_session_ids).toEqual(['b', 'a', 'old']) + expect(stats.last_outcome).toBe('synced') + expect(stats.last_error).toBe('nope') + }) + + it('counts pending spool files', () => { + mkdirSync(join(dir, 'spool'), { recursive: true }) + writeFileSync(join(dir, 'spool', 'cc1.json'), '{}') + writeFileSync(join(dir, 'spool', 'ignored.txt'), '') + expect(spooledPendingCount()).toBe(1) + expect(computeHookStats([], 0).spooled_pending).toBe(1) + }) +})