Skip to content

Commit 54bdcf1

Browse files
committed
chore(cli): add file logging for background errors
1 parent cc12e58 commit 54bdcf1

4 files changed

Lines changed: 194 additions & 32 deletions

File tree

.github/workflows/publish.yml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@ on:
77
workflow_dispatch:
88
inputs:
99
dist_tag:
10-
description: 'npm dist-tag channel (latest / beta / next). Git tag is auto-selected.'
10+
description: npm dist-tag channel (latest / beta / next). Git tag is auto-selected.
1111
required: false
1212
default: latest
1313

packages/cli/src/adapters/opencode.ts

Lines changed: 24 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -42,15 +42,35 @@ async function parseOpenCodeSessionFile(
4242
const events: CanonicalEvent[] = []
4343

4444
try {
45+
// Older OpenCode databases predate the `path` column on session.
46+
// Probe schema first and only select columns that exist.
47+
const sessionCols = new Set(
48+
(db.prepare('PRAGMA table_info(session)').all() as Array<{ name: string }>)
49+
.map(row => row.name),
50+
)
51+
const hasDirectory = sessionCols.has('directory')
52+
const hasPath = sessionCols.has('path')
53+
const hasArchived = sessionCols.has('time_archived')
54+
const selectCols = ['id', 'title', 'time_created']
55+
if (hasDirectory) {
56+
selectCols.push('directory')
57+
}
58+
if (hasPath) {
59+
selectCols.push('path')
60+
}
61+
if (hasArchived) {
62+
selectCols.push('time_archived')
63+
}
64+
4565
const sessions = db.prepare(
46-
'SELECT id, directory, path, title, time_created, time_archived FROM session WHERE time_created IS NOT NULL ORDER BY time_created',
66+
`SELECT ${selectCols.join(', ')} FROM session WHERE time_created IS NOT NULL ORDER BY time_created`,
4767
).all() as Array<{
4868
id: string
49-
directory: string | null
50-
path: string | null
69+
directory?: string | null
70+
path?: string | null
5171
title: string
5272
time_created: number
53-
time_archived: number | null
73+
time_archived?: number | null
5474
}>
5575

5676
for (const session of sessions) {

packages/cli/src/cli.ts

Lines changed: 92 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,6 @@ import type {
77
} from '@codetime/shared'
88
import type { BackfillSourceDefinition } from './lib/backfill.js'
99
import type { BackfillImportCounts, BackfillIncrementalState, BackfillSourceFile, ParsedArgs, RunContext, SyncLocalLock, SyncLocalTriggerState, WritableLike } from './lib/types.js'
10-
import { BACKFILL_STATE_SCHEMA_VERSION } from './lib/types.js'
1110
import { spawn } from 'node:child_process'
1211
import { mkdir, rm, stat, writeFile } from 'node:fs/promises'
1312
import os from 'node:os'
@@ -34,6 +33,7 @@ import { defaultMachineName, ensureLocalMachineId, readConfig, writeConfig } fro
3433
import { DEFAULT_API_URL, DEFAULT_BACKFILL_BATCH_BYTES, DEFAULT_BACKFILL_BATCH_SIZE, DEFAULT_HOOK_SYNC_MIN_INTERVAL_SECONDS, PACKAGE_VERSION } from './lib/constants.js'
3534
import { isPlainObject, numberOption, stringOption, valuesOption } from './lib/fields.js'
3635
import { countDirectoryEntries, listJsonlFiles, pathExists, readJsonIfExists } from './lib/fs.js'
36+
import { logError } from './lib/logger.js'
3737
import { ProgressBar } from './lib/progress.js'
3838
import {
3939
deleteMachine,
@@ -43,6 +43,7 @@ import {
4343
renameMachine,
4444
resolveRemote,
4545
} from './lib/remote.js'
46+
import { BACKFILL_STATE_SCHEMA_VERSION } from './lib/types.js'
4647

4748
// ── Registry ──
4849

@@ -98,6 +99,7 @@ export async function run(argv: string[], context: Partial<RunContext> = {}): Pr
9899
}
99100
catch (error) {
100101
write(ctx.stderr, `${(error as Error).message}\n`)
102+
await logError('cli', error, { argv })
101103
return 1
102104
}
103105
}
@@ -288,22 +290,33 @@ async function installCommand(options: ParsedArgs, ctx: RunContext, registry: Ad
288290
}
289291

290292
async function hookCommand(options: ParsedArgs, ctx: RunContext): Promise<number> {
291-
const agent = requiredOption(options, 'agent')
292-
const payload = await readHookPayload(ctx.stdin)
293-
const enrichment = await enrichFromTranscript(payload, claudeUsageFromMessage)
294-
const events = hookEventsFromPayload(agent, payload, options, enrichment, { tokenUsageFromPayload })
295-
assertValidEvents(events)
293+
const home = resolveHome(options, ctx)
294+
try {
295+
const agent = requiredOption(options, 'agent')
296+
const payload = await readHookPayload(ctx.stdin)
297+
const enrichment = await enrichFromTranscript(payload, claudeUsageFromMessage)
298+
const events = hookEventsFromPayload(agent, payload, options, enrichment, { tokenUsageFromPayload })
299+
assertValidEvents(events)
300+
301+
if (options['dry-run']) {
302+
write(ctx.stdout, `${JSON.stringify(events.length === 1 ? events[0] : events, null, 2)}\n`)
303+
return 0
304+
}
296305

297-
if (options['dry-run']) {
298-
write(ctx.stdout, `${JSON.stringify(events.length === 1 ? events[0] : events, null, 2)}\n`)
306+
return await syncLocalTriggerCommand({
307+
...options,
308+
agent,
309+
'min-interval': stringOption(options['min-interval']) || String(DEFAULT_HOOK_SYNC_MIN_INTERVAL_SECONDS),
310+
}, ctx)
311+
}
312+
catch (error) {
313+
// Hooks run inside the user's agent (Claude Code, Codex, etc).
314+
// Bubbling an error there spams the user with stderr; persist to the
315+
// log file and exit 0 so the agent isn't disturbed.
316+
await logError('hook', error, { agent: stringOption(options.agent) }, home)
317+
debug(ctx, `[codetime] hook failed: ${(error as Error).message}\n`)
299318
return 0
300319
}
301-
302-
return syncLocalTriggerCommand({
303-
...options,
304-
agent,
305-
'min-interval': stringOption(options['min-interval']) || String(DEFAULT_HOOK_SYNC_MIN_INTERVAL_SECONDS),
306-
}, ctx)
307320
}
308321

309322
async function syncLocalTriggerCommand(options: ParsedArgs, ctx: RunContext, _registry?: AdapterRegistry): Promise<number> {
@@ -369,6 +382,12 @@ async function syncLocalRunnerCommand(options: ParsedArgs, ctx: RunContext, _reg
369382
}, ctx)
370383
return exitCode
371384
}
385+
catch (error) {
386+
// The runner is spawned detached with stdio: 'ignore', so the stack
387+
// trace would be lost otherwise. Persist it so users can diagnose.
388+
await logError('sync-local-runner', error, { home }, home)
389+
throw error
390+
}
372391
finally {
373392
const nextState = await readSyncLocalTriggerState(statePath)
374393
nextState.lastStartedAt = state.lastStartedAt
@@ -506,23 +525,40 @@ async function createBackfillEventsFromDefs(
506525
overrideFiles?: string[],
507526
): Promise<CanonicalEvent[]> {
508527
const events: CanonicalEvent[] = []
528+
const home = resolveHome(options, ctx)
509529

530+
// Same isolation policy as the import path: one source blowing up
531+
// (e.g. older opencode SQLite schemas) must not poison the whole plan.
510532
for (const item of sourceDefs) {
511533
const parser = registry.getParser(item.id)
512534
if (!parser) {
513535
continue
514536
}
515537

516-
const sourceFiles = await listBackfillSourceFiles(item, options, ctx)
517-
const files = overrideFiles ?? sourceFiles.map(f => f.path)
538+
let files: string[]
539+
try {
540+
const sourceFiles = await listBackfillSourceFiles(item, options, ctx)
541+
files = overrideFiles ?? sourceFiles.map(f => f.path)
542+
}
543+
catch (error) {
544+
await logError('backfill.listFiles', error, { source: item.id, phase: 'plan' }, home)
545+
debug(ctx, `[codetime] skip ${item.id} in plan: list files failed: ${(error as Error).message}\n`)
546+
continue
547+
}
518548

519549
for (const filePath of files) {
520-
const parsed = await parser(filePath, options)
521-
for (const event of parsed) {
522-
if (matchesBackfillFilters(event, options)) {
523-
events.push(event)
550+
try {
551+
const parsed = await parser(filePath, options)
552+
for (const event of parsed) {
553+
if (matchesBackfillFilters(event, options)) {
554+
events.push(event)
555+
}
524556
}
525557
}
558+
catch (error) {
559+
await logError('backfill.parse', error, { source: item.id, file: filePath, phase: 'plan' }, home)
560+
debug(ctx, `[codetime] skip ${item.id} file ${filePath} in plan: ${(error as Error).message}\n`)
561+
}
526562
}
527563
}
528564

@@ -747,30 +783,59 @@ async function collectCanonicalEvents(
747783
}> {
748784
const selectedFilesBySource = new Map<BackfillSourceId, BackfillSourceFile[]>()
749785
const canonicalEvents: CanonicalEvent[] = []
786+
const home = resolveHome(options, ctx)
750787

751788
for (const item of sourceDefs) {
752789
const parser = registry.getParser(item.id)
753790
if (!parser) {
754791
continue
755792
}
756-
const sourceFiles = await listBackfillSourceFiles(item, options, ctx)
757-
const selectedFiles = selectBackfillFilesForImport(sourceFiles, incrementalState?.sources[item.id]?.watermarkTs)
793+
// Per-source isolation: a broken parser or missing history dir for
794+
// one source (e.g. opencode's older schemas) must not abort the
795+
// whole run. Failures land in ~/.codetime/logs/cli.log; the
796+
// watermark stays unadvanced because selectedFilesBySource only
797+
// gets populated on success.
798+
let selectedFiles: BackfillSourceFile[]
799+
try {
800+
const sourceFiles = await listBackfillSourceFiles(item, options, ctx)
801+
selectedFiles = selectBackfillFilesForImport(sourceFiles, incrementalState?.sources[item.id]?.watermarkTs)
802+
}
803+
catch (error) {
804+
await logError('backfill.listFiles', error, { source: item.id }, home)
805+
debug(ctx, `[codetime] skip ${item.id}: list files failed: ${(error as Error).message}\n`)
806+
continue
807+
}
758808
selectedFilesBySource.set(item.id, selectedFiles)
759809
const filePaths = selectedFiles.map(f => f.path)
760810
const sourceEvents: CanonicalEvent[] = []
811+
let sourceFailed = false
761812

762813
const bar = options.json ? undefined : new ProgressBar(ctx.stdout, `${item.id.padEnd(12)}`)
763814
bar?.init(filePaths.length, `0 events`)
764815
for (let fi = 0; fi < filePaths.length; fi += 1) {
765-
const parsed = await parser(filePaths[fi], options)
766-
for (const event of parsed) {
767-
if (matchesBackfillFilters(event, options)) {
768-
sourceEvents.push(event)
816+
try {
817+
const parsed = await parser(filePaths[fi], options)
818+
for (const event of parsed) {
819+
if (matchesBackfillFilters(event, options)) {
820+
sourceEvents.push(event)
821+
}
769822
}
770823
}
824+
catch (error) {
825+
sourceFailed = true
826+
await logError('backfill.parse', error, { source: item.id, file: filePaths[fi] }, home)
827+
debug(ctx, `[codetime] skip ${item.id} file ${filePaths[fi]}: ${(error as Error).message}\n`)
828+
}
771829
bar?.tick(`${fi + 1}/${filePaths.length} files, ${sourceEvents.length} events`)
772830
}
773-
bar?.finalize(`${sourceEvents.length} events`)
831+
bar?.finalize(`${sourceEvents.length} events${sourceFailed ? ' (partial — see logs)' : ''}`)
832+
833+
// If any file failed to parse, drop this source from the watermark
834+
// update set so we retry on the next run instead of marking it as
835+
// fully imported.
836+
if (sourceFailed) {
837+
selectedFilesBySource.delete(item.id)
838+
}
774839

775840
for (const event of sourceEvents) canonicalEvents.push(event)
776841
}

packages/cli/src/lib/logger.ts

Lines changed: 77 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,77 @@
1+
// File logger for the CLI. Hooks and the background sync-local runner
2+
// detach with stdio: 'ignore', so stderr is gone. Persist failures here
3+
// so users can diagnose problems after the fact.
4+
import { appendFile, mkdir, rename, stat } from 'node:fs/promises'
5+
import { homedir } from 'node:os'
6+
import path from 'node:path'
7+
8+
const MAX_BYTES = 1 * 1024 * 1024 // 1 MiB; rotate to .1 when exceeded
9+
10+
export function logDir(home: string = homedir()): string {
11+
return path.join(home, '.codetime', 'logs')
12+
}
13+
14+
export function logPath(home: string = homedir(), name = 'cli.log'): string {
15+
return path.join(logDir(home), name)
16+
}
17+
18+
function serializeError(error: unknown): Record<string, unknown> {
19+
if (error instanceof Error) {
20+
return { message: error.message, stack: error.stack, name: error.name }
21+
}
22+
return { value: String(error) }
23+
}
24+
25+
async function rotateIfNeeded(file: string): Promise<void> {
26+
try {
27+
const info = await stat(file)
28+
if (info.size > MAX_BYTES) {
29+
await rename(file, `${file}.1`).catch(() => {})
30+
}
31+
}
32+
catch { /* missing file is fine */ }
33+
}
34+
35+
export interface LogEntry {
36+
scope: string
37+
message?: string
38+
error?: unknown
39+
meta?: Record<string, unknown>
40+
level?: 'info' | 'warn' | 'error'
41+
}
42+
43+
export async function writeLog(entry: LogEntry, home: string = homedir(), fileName = 'cli.log'): Promise<void> {
44+
try {
45+
const dir = logDir(home)
46+
await mkdir(dir, { recursive: true })
47+
const file = logPath(home, fileName)
48+
await rotateIfNeeded(file)
49+
const record: Record<string, unknown> = {
50+
ts: new Date().toISOString(),
51+
level: entry.level || (entry.error ? 'error' : 'info'),
52+
scope: entry.scope,
53+
pid: process.pid,
54+
}
55+
if (entry.message) {
56+
record.message = entry.message
57+
}
58+
if (entry.meta) {
59+
Object.assign(record, entry.meta)
60+
}
61+
if (entry.error !== undefined) {
62+
record.error = serializeError(entry.error)
63+
}
64+
await appendFile(file, `${JSON.stringify(record)}\n`)
65+
}
66+
catch {
67+
// Never let logging crash the caller.
68+
}
69+
}
70+
71+
export async function logError(scope: string, error: unknown, meta: Record<string, unknown> = {}, home: string = homedir()): Promise<void> {
72+
await writeLog({ scope, error, meta, level: 'error' }, home)
73+
}
74+
75+
export async function logInfo(scope: string, message: string, meta: Record<string, unknown> = {}, home: string = homedir()): Promise<void> {
76+
await writeLog({ scope, message, meta, level: 'info' }, home)
77+
}

0 commit comments

Comments
 (0)