diff --git a/DEVELOPMENT.md b/DEVELOPMENT.md index 1d5bdbc..76746d5 100644 --- a/DEVELOPMENT.md +++ b/DEVELOPMENT.md @@ -16,3 +16,58 @@ pnpm --filter @clawwork/desktop run build:dmg Output at `packages/desktop/dist/ClawWork--arm64.dmg`. Unsigned — on first launch, right-click → Open. + +## Debug Observability + +Structured debug logging across main process, gateway WS, and renderer. All events flow into a ring buffer (1000 entries) and daily ndjson files under `.clawwork-debug/`. + +- **Domains**: `app`, `gateway`, `ipc`, `renderer`, `db`, `workspace`, `artifact`, `debug` +- **Correlation**: every event supports `traceId` and `feature` fields to link a user action across IPC → gateway → renderer +- **Renderer bridge**: renderer debug events are sent to main via `debug:renderer-event` IPC channel, so the export bundle contains both sides +- **Export bundle**: `debug:export-bundle` IPC produces a timestamped directory with `recent-events.ndjson`, `timeline.json`, `gateway-status.json`, `config.sanitized.json`, `environment.json` + +Trigger export from renderer: + +```ts +const result = await window.clawwork.exportDebugBundle({ taskId, limit: 500 }); +// result.path → absolute path to the bundle directory +``` + +### Troubleshooting with debug events + +Debug log is at `.clawwork-debug/debug-YYYY-MM-DD.ndjson`, one JSON object per line. + +**Event naming convention**: `..` — e.g. `gateway.req.sent`, `gateway.res.received`, `ipc.ws.send-message.completed`, `renderer.chat.delta.applied`. + +**Healthy message send flow** (events in order): + +``` +ipc.ws.send-message.requested → user hit send +gateway.req.sent → WS frame dispatched (has requestId) +gateway.res.received → server acknowledged (same requestId, ok:true) +gateway.event.received → streaming events arrive (event:"chat") +renderer.chat.delta.applied → UI appended text +renderer.chat.finalized → stream complete +``` + +**Healthy connection flow**: + +``` +gateway.connect.start → WS connecting +gateway.ws.open → TCP established +gateway.challenge.received → auth challenge from server +gateway.connect.res.ok → authenticated, ready +gateway.heartbeat.start → keepalive active +``` + +**How to trace a single user action**: filter by `traceId` (when set) or by `requestId` + `sessionKey` to follow one request across layers. + +**Common failure patterns**: + +| Symptom | What to look for | +|---------|-----------------| +| Message sent, no response | `gateway.req.sent` present but no matching `gateway.res.received` → check `gateway.req.timeout` | +| Message sent, response OK but nothing in UI | `gateway.res.received` ok:true but no `renderer.chat.delta.applied` → event routing issue, check `renderer.event.dropped.*` | +| Connection drops | `gateway.ws.close` with code/reason, then `gateway.reconnect.scheduled` or `gateway.reconnect.giveup` | +| Auth failure | `gateway.challenge.received` followed by `gateway.challenge.invalid` instead of `gateway.connect.res.ok` | +| IPC call fails silently | `ipc.ws.send-message.requested` present but no `.completed` → check `ipc.ws.send-message.failed` for error | diff --git a/packages/desktop/src/main/debug/export.ts b/packages/desktop/src/main/debug/export.ts new file mode 100644 index 0000000..2cf766a --- /dev/null +++ b/packages/desktop/src/main/debug/export.ts @@ -0,0 +1,36 @@ +import { mkdirSync, writeFileSync } from 'node:fs'; +import { join } from 'node:path'; +import { sanitizeForLog } from '@clawwork/shared'; +import type { DebugEvent } from '@clawwork/shared'; +import type { DebugLogger } from './logger.js'; + +export interface ExportDebugBundleOptions { + outputDir: string; + logger: DebugLogger; + meta?: { + gatewayStatus?: Record; + config?: Record; + environment?: Record; + }; + filter?: { + gatewayId?: string; + sessionKey?: string; + taskId?: string; + limit?: number; + }; +} + +export function exportDebugBundle(options: ExportDebugBundleOptions): { bundlePath: string; events: DebugEvent[] } { + const stamp = new Date().toISOString().replace(/[:.]/g, '-'); + const bundlePath = join(options.outputDir, `bundle-${stamp}`); + mkdirSync(bundlePath, { recursive: true }); + + const events = options.logger.getRecentEvents(options.filter); + writeFileSync(join(bundlePath, 'recent-events.ndjson'), events.map((event) => JSON.stringify(event)).join('\n') + (events.length ? '\n' : ''), 'utf8'); + writeFileSync(join(bundlePath, 'timeline.json'), JSON.stringify({ events }, null, 2), 'utf8'); + writeFileSync(join(bundlePath, 'gateway-status.json'), JSON.stringify(sanitizeForLog(options.meta?.gatewayStatus ?? {}), null, 2), 'utf8'); + writeFileSync(join(bundlePath, 'config.sanitized.json'), JSON.stringify(sanitizeForLog(options.meta?.config ?? {}), null, 2), 'utf8'); + writeFileSync(join(bundlePath, 'environment.json'), JSON.stringify(sanitizeForLog(options.meta?.environment ?? {}), null, 2), 'utf8'); + + return { bundlePath, events }; +} diff --git a/packages/desktop/src/main/debug/index.ts b/packages/desktop/src/main/debug/index.ts new file mode 100644 index 0000000..eaf231f --- /dev/null +++ b/packages/desktop/src/main/debug/index.ts @@ -0,0 +1,33 @@ +import { BrowserWindow } from 'electron'; +import { join } from 'node:path'; +import type { DebugEvent } from '@clawwork/shared'; +import type { DebugLogger } from './logger.js'; +import { createDebugLogger } from './logger.js'; + +let debugLogger: DebugLogger = createDebugLogger({ + debugDir: join(process.cwd(), '.clawwork-debug'), + console: true, +}); + +export function initDebugLogger(debugDir: string): DebugLogger { + debugLogger = createDebugLogger({ + debugDir, + console: true, + onEvent: broadcastDebugEvent, + }); + return debugLogger; +} + +export function getDebugLogger(): DebugLogger { + return debugLogger; +} + +function broadcastDebugEvent(event: DebugEvent): void { + for (const win of BrowserWindow.getAllWindows()) { + try { + win.webContents.send('debug-event', event); + } catch { + // ignore broadcast failures for windows closing during dispatch + } + } +} diff --git a/packages/desktop/src/main/debug/logger.ts b/packages/desktop/src/main/debug/logger.ts new file mode 100644 index 0000000..c289384 --- /dev/null +++ b/packages/desktop/src/main/debug/logger.ts @@ -0,0 +1,119 @@ +import { appendFileSync, existsSync, mkdirSync } from 'node:fs'; +import { join } from 'node:path'; +import type { DebugDomain, DebugEvent, DebugLevel } from '@clawwork/shared'; +import { sanitizeForLog } from '@clawwork/shared'; + +export interface CreateDebugLoggerOptions { + debugDir: string; + maxEvents?: number; + console?: boolean; + onEvent?: (event: DebugEvent) => void; +} + +export interface DebugLogFilter { + level?: DebugLevel[]; + domain?: DebugDomain[]; + gatewayId?: string; + sessionKey?: string; + taskId?: string; + traceId?: string; + feature?: string; + limit?: number; +} + +export interface DebugLogger { + debug: (input: LogEventInput) => DebugEvent; + info: (input: LogEventInput) => DebugEvent; + warn: (input: LogEventInput) => DebugEvent; + error: (input: LogEventInput) => DebugEvent; + log: (input: LogEventInput & { level: DebugLevel }) => DebugEvent; + getRecentEvents: (filter?: DebugLogFilter) => DebugEvent[]; + currentFilePath: () => string; +} + +export interface LogEventInput { + domain: DebugDomain; + event: string; + traceId?: string; + feature?: string; + message?: string; + gatewayId?: string; + sessionKey?: string; + taskId?: string; + runId?: string; + requestId?: string; + wsFrameId?: string; + seq?: number; + attempt?: number; + durationMs?: number; + ok?: boolean; + error?: DebugEvent['error']; + data?: Record; +} + +export function createDebugLogger(options: CreateDebugLoggerOptions): DebugLogger { + const maxEvents = options.maxEvents ?? 1000; + const writeConsole = options.console ?? true; + const recentEvents: DebugEvent[] = []; + + ensureDir(options.debugDir); + + function log(input: LogEventInput & { level: DebugLevel }): DebugEvent { + const event: DebugEvent = sanitizeForLog({ + ts: new Date().toISOString(), + ...input, + }); + + recentEvents.push(event); + if (recentEvents.length > maxEvents) { + recentEvents.splice(0, recentEvents.length - maxEvents); + } + + appendFileSync(currentFilePath(), `${JSON.stringify(event)}\n`, 'utf8'); + + if (writeConsole) { + const line = `[${event.level}] [${event.domain}] ${event.event}`; + if (event.level === 'error') console.error(line, event); + else if (event.level === 'warn') console.warn(line, event); + else console.log(line, event); + } + + options.onEvent?.(event); + return event; + } + + return { + debug: (input) => log({ ...input, level: 'debug' }), + info: (input) => log({ ...input, level: 'info' }), + warn: (input) => log({ ...input, level: 'warn' }), + error: (input) => log({ ...input, level: 'error' }), + log, + getRecentEvents: (filter) => filterEvents(recentEvents, filter), + currentFilePath, + }; + + function currentFilePath(): string { + const day = new Date().toISOString().slice(0, 10); + return join(options.debugDir, `debug-${day}.ndjson`); + } +} + +function filterEvents(events: DebugEvent[], filter?: DebugLogFilter): DebugEvent[] { + let result = [...events]; + if (!filter) return result; + if (filter.level?.length) result = result.filter((event) => filter.level!.includes(event.level)); + if (filter.domain?.length) result = result.filter((event) => filter.domain!.includes(event.domain)); + if (filter.gatewayId) result = result.filter((event) => event.gatewayId === filter.gatewayId); + if (filter.sessionKey) result = result.filter((event) => event.sessionKey === filter.sessionKey); + if (filter.taskId) result = result.filter((event) => event.taskId === filter.taskId); + if (filter.traceId) result = result.filter((event) => event.traceId === filter.traceId); + if (filter.feature) result = result.filter((event) => event.feature === filter.feature); + if (filter.limit && filter.limit > 0) result = result.slice(-filter.limit); + return result; +} + +function ensureDir(dir: string): void { + if (!existsSync(dir)) { + mkdirSync(dir, { recursive: true }); + } +} diff --git a/packages/desktop/src/main/index.ts b/packages/desktop/src/main/index.ts index 7ccde9a..1346333 100644 --- a/packages/desktop/src/main/index.ts +++ b/packages/desktop/src/main/index.ts @@ -3,6 +3,7 @@ import { join } from 'path'; import { writeFileSync } from 'fs'; import { electronApp, optimizer, is } from '@electron-toolkit/utils'; import { initAllGateways, destroyAllGateways, rebindAllWindows } from './ws/index.js'; +import { initDebugLogger, getDebugLogger } from './debug/index.js'; import { registerWsHandlers } from './ipc/ws-handlers.js'; import { registerArtifactHandlers } from './ipc/artifact-handlers.js'; import { registerWorkspaceHandlers } from './ipc/workspace-handlers.js'; @@ -10,6 +11,7 @@ import { registerSettingsHandlers } from './ipc/settings-handlers.js'; import { registerSearchHandlers } from './ipc/search-handlers.js'; import { registerDataHandlers } from './ipc/data-handlers.js'; import { registerUpdateHandlers } from './ipc/update-handlers.js'; +import { registerDebugHandlers } from './ipc/debug-handlers.js'; import { getWorkspacePath, readConfig } from './workspace/config.js'; import { initDatabase, closeDatabase } from './db/index.js'; @@ -22,7 +24,11 @@ const SCREENSHOT_PATH = '/tmp/clawwork-screenshot.png'; async function captureScreenshot(win: BrowserWindow): Promise { const image = await win.webContents.capturePage(); writeFileSync(SCREENSHOT_PATH, image.toPNG()); - console.log(`[screenshot] saved to ${SCREENSHOT_PATH}`); + getDebugLogger().info({ + domain: 'app', + event: 'app.screenshot.saved', + data: { path: SCREENSHOT_PATH }, + }); return SCREENSHOT_PATH; } @@ -44,6 +50,7 @@ function setupDevScreenshot(win: BrowserWindow): void { } function createWindow(): BrowserWindow { + getDebugLogger().info({ domain: 'app', event: 'app.window.create' }); const mainWindow = new BrowserWindow({ width: 1280, height: 800, @@ -78,6 +85,8 @@ function createWindow(): BrowserWindow { } app.whenReady().then(() => { + initDebugLogger(join(app.getPath('userData'), 'debug')); + getDebugLogger().info({ domain: 'app', event: 'app.start', data: { userData: app.getPath('userData') } }); electronApp.setAppUserModelId('com.clawwork.app'); app.on('browser-window-created', (_, window) => { @@ -91,10 +100,24 @@ app.whenReady().then(() => { registerSearchHandlers(); registerDataHandlers(); registerUpdateHandlers(); + registerDebugHandlers(); const wsPath = getWorkspacePath(); if (wsPath) { - try { initDatabase(wsPath); } catch (e) { console.error('[startup] DB init failed:', e); } + getDebugLogger().info({ domain: 'workspace', event: 'workspace.detected', data: { workspacePath: wsPath } }); + try { + getDebugLogger().info({ domain: 'db', event: 'db.init.start', data: { workspacePath: wsPath } }); + initDatabase(wsPath); + getDebugLogger().info({ domain: 'db', event: 'db.init.ok', data: { workspacePath: wsPath } }); + } catch (e) { + const err = e instanceof Error ? e : new Error(String(e)); + getDebugLogger().error({ + domain: 'db', + event: 'db.init.failed', + data: { workspacePath: wsPath }, + error: { name: err.name, message: err.message, stack: err.stack }, + }); + } } const mainWindow = createWindow(); @@ -116,6 +139,7 @@ app.on('window-all-closed', () => { }); app.on('before-quit', () => { + getDebugLogger().info({ domain: 'app', event: 'app.before-quit' }); globalShortcut.unregisterAll(); destroyAllGateways(); closeDatabase(); diff --git a/packages/desktop/src/main/ipc/debug-handlers.ts b/packages/desktop/src/main/ipc/debug-handlers.ts new file mode 100644 index 0000000..ef7f217 --- /dev/null +++ b/packages/desktop/src/main/ipc/debug-handlers.ts @@ -0,0 +1,56 @@ +import { app, ipcMain } from 'electron'; +import { join } from 'node:path'; +import { exportDebugBundle } from '../debug/export.js'; +import { getDebugLogger } from '../debug/index.js'; +import { getAllGatewayClients } from '../ws/index.js'; +import { readConfig } from '../workspace/config.js'; + +export function registerDebugHandlers(): void { + ipcMain.on('debug:renderer-event', (_event, payload: { + domain: string; + event: string; + traceId?: string; + feature?: string; + data?: Record; + }) => { + const logger = getDebugLogger(); + logger.info({ + domain: (payload.domain || 'renderer') as 'renderer', + event: payload.event, + traceId: payload.traceId, + feature: payload.feature, + data: payload.data, + }); + }); + + ipcMain.handle('debug:export-bundle', async (_event, payload?: { + gatewayId?: string; + sessionKey?: string; + taskId?: string; + limit?: number; + }) => { + const clients = getAllGatewayClients(); + const gatewayStatus: Record = {}; + for (const [id, client] of clients) { + gatewayStatus[id] = { connected: client.isConnected, name: client.name }; + } + + const result = exportDebugBundle({ + outputDir: join(app.getPath('userData'), 'debug-bundles'), + logger: getDebugLogger(), + meta: { + gatewayStatus, + config: readConfig() as unknown as Record | undefined, + environment: { + platform: process.platform, + arch: process.arch, + node: process.version, + electron: process.versions.electron, + }, + }, + filter: payload, + }); + + return { ok: true, path: result.bundlePath, eventCount: result.events.length }; + }); +} diff --git a/packages/desktop/src/main/ipc/ws-handlers.ts b/packages/desktop/src/main/ipc/ws-handlers.ts index e371288..f89d0f4 100644 --- a/packages/desktop/src/main/ipc/ws-handlers.ts +++ b/packages/desktop/src/main/ipc/ws-handlers.ts @@ -3,6 +3,7 @@ import { getGatewayClient, getAllGatewayClients } from '../ws/index.js'; import { readConfig } from '../workspace/config.js'; import { isClawWorkSession, parseTaskIdFromSessionKey, parseAgentIdFromSessionKey } from '@clawwork/shared'; import type { ChatAttachment } from '@clawwork/shared'; +import { getDebugLogger } from '../debug/index.js'; interface GatewaySessionRow { key: string; @@ -55,15 +56,48 @@ export function registerWsHandlers(): void { content: string; attachments?: ChatAttachment[]; }) => { + const taskId = parseTaskIdFromSessionKey(payload.sessionKey) ?? undefined; + getDebugLogger().info({ + domain: 'ipc', + event: 'ipc.ws.send-message.requested', + gatewayId: payload.gatewayId, + sessionKey: payload.sessionKey, + taskId, + data: { contentLength: payload.content.length, attachmentCount: payload.attachments?.length ?? 0 }, + }); const gw = getGatewayClient(payload.gatewayId); if (!gw?.isConnected) { + getDebugLogger().error({ + domain: 'ipc', + event: 'ipc.ws.send-message.failed', + gatewayId: payload.gatewayId, + sessionKey: payload.sessionKey, + taskId, + error: { message: 'gateway not connected' }, + }); return { ok: false, error: 'gateway not connected' }; } try { await gw.sendChatMessage(payload.sessionKey, payload.content, payload.attachments); + getDebugLogger().info({ + domain: 'ipc', + event: 'ipc.ws.send-message.completed', + gatewayId: payload.gatewayId, + sessionKey: payload.sessionKey, + taskId, + ok: true, + }); return { ok: true }; } catch (err) { const msg = err instanceof Error ? err.message : 'unknown error'; + getDebugLogger().error({ + domain: 'ipc', + event: 'ipc.ws.send-message.failed', + gatewayId: payload.gatewayId, + sessionKey: payload.sessionKey, + taskId, + error: { message: msg }, + }); return { ok: false, error: msg }; } }); @@ -113,6 +147,11 @@ export function registerWsHandlers(): void { ipcMain.handle('ws:sync-sessions', async () => { const clients = getAllGatewayClients(); + getDebugLogger().info({ + domain: 'ipc', + event: 'ipc.ws.sync-sessions.started', + data: { gatewayCount: clients.size }, + }); const discovered: { gatewayId: string; @@ -216,10 +255,20 @@ export function registerWsHandlers(): void { } } catch (err) { const msg = err instanceof Error ? err.message : 'unknown error'; - console.error(`[ws] sync-sessions failed for gateway ${gatewayId}:`, msg); + getDebugLogger().error({ + domain: 'ipc', + event: 'ipc.ws.sync-sessions.gateway-failed', + gatewayId, + error: { message: msg }, + }); } } + getDebugLogger().info({ + domain: 'ipc', + event: 'ipc.ws.sync-sessions.completed', + data: { discoveredCount: discovered.length }, + }); return { ok: true, discovered }; }); diff --git a/packages/desktop/src/main/ws/gateway-client.ts b/packages/desktop/src/main/ws/gateway-client.ts index 1128997..373c69a 100644 --- a/packages/desktop/src/main/ws/gateway-client.ts +++ b/packages/desktop/src/main/ws/gateway-client.ts @@ -2,10 +2,11 @@ import WebSocket from 'ws'; import { app } from 'electron'; import { randomUUID } from 'crypto'; import { - GATEWAY_WS_PORT, HEARTBEAT_INTERVAL_MS, RECONNECT_DELAY_MS, MAX_RECONNECT_ATTEMPTS, + parseTaskIdFromSessionKey, + summarizePayload, } from '@clawwork/shared'; import type { GatewayFrame, @@ -25,11 +26,17 @@ import { loadDeviceToken, type DeviceIdentity, } from './device-identity.js'; +import { getDebugLogger } from '../debug/index.js'; type PendingReq = { resolve: (payload: Record) => void; reject: (err: Error) => void; timer: ReturnType; + method: string; + startedAt: number; + requestId: string; + sessionKey?: string; + taskId?: string; }; const REQ_TIMEOUT_MS = 15_000; @@ -85,11 +92,22 @@ export class GatewayClient { if (this.destroyed) return; this.cleanup(); - console.log(`[gateway:${this.gatewayId}] connecting to ${this.wsUrl}`); + getDebugLogger().info({ + domain: 'gateway', + event: 'gateway.connect.start', + gatewayId: this.gatewayId, + attempt: this.reconnectAttempts + 1, + data: { wsUrl: this.wsUrl }, + }); this.ws = new WebSocket(this.wsUrl); this.ws.on('open', () => { - console.log(`[gateway:${this.gatewayId}] ws open, waiting for challenge...`); + getDebugLogger().info({ + domain: 'gateway', + event: 'gateway.ws.open', + gatewayId: this.gatewayId, + message: 'Waiting for connect challenge', + }); }); this.ws.on('message', (raw) => { @@ -98,7 +116,16 @@ export class GatewayClient { this.ws.on('close', (code, reason) => { const reasonStr = reason.toString(); - console.log(`[gateway:${this.gatewayId}] closed: ${code} ${reasonStr}`); + getDebugLogger().warn({ + domain: 'gateway', + event: 'gateway.ws.close', + gatewayId: this.gatewayId, + data: { + code, + reason: reasonStr, + pendingRequests: this.pendingRequests.size, + }, + }); this.authenticated = false; this.stopHeartbeat(); if (this.mainWindow) { @@ -114,7 +141,12 @@ export class GatewayClient { }); this.ws.on('error', (err) => { - console.error(`[gateway:${this.gatewayId}] ws error: ${err.message}`); + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.ws.error', + gatewayId: this.gatewayId, + error: { name: err.name, message: err.message, stack: err.stack }, + }); }); } @@ -123,19 +155,33 @@ export class GatewayClient { try { frame = JSON.parse(raw) as GatewayFrame; } catch { - console.error(`[gateway:${this.gatewayId}] invalid JSON frame`); + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.frame.invalid-json', + gatewayId: this.gatewayId, + data: { raw }, + }); + return; + } + + if (frame.type === 'event') { + getDebugLogger().debug({ + domain: 'gateway', + event: 'gateway.event.received', + gatewayId: this.gatewayId, + seq: frame.seq, + data: { + name: frame.event, + payload: summarizePayload(frame.payload), + }, + }); + this.handleEvent(frame); return; } - switch (frame.type) { - case 'event': - this.handleEvent(frame); - break; - case 'res': - this.handleResponse(frame); - break; - case 'req': - break; + if (frame.type === 'res') { + this.handleResponse(frame); + return; } } @@ -146,19 +192,48 @@ export class GatewayClient { ? frame.payload.nonce.trim() : ''; if (!nonce) { - console.error(`[gateway:${this.gatewayId}] connect challenge missing nonce`); + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.challenge.invalid', + gatewayId: this.gatewayId, + data: { payload: summarizePayload(frame.payload) }, + }); this.ws?.close(1008, 'connect challenge missing nonce'); return; } this.connectNonce = nonce; + getDebugLogger().info({ + domain: 'gateway', + event: 'gateway.challenge.received', + gatewayId: this.gatewayId, + seq: frame.seq, + }); this.handleChallenge(nonce); return; } if (frame.event === 'tick') { + getDebugLogger().debug({ + domain: 'gateway', + event: 'gateway.tick.received', + gatewayId: this.gatewayId, + seq: frame.seq, + }); return; } + const sessionKey = typeof frame.payload.sessionKey === 'string' ? frame.payload.sessionKey : undefined; + const taskId = sessionKey ? parseTaskIdFromSessionKey(sessionKey) ?? undefined : undefined; + getDebugLogger().debug({ + domain: 'gateway', + event: `gateway.${frame.event.replace(/[^a-z0-9]+/gi, '.').toLowerCase()}`, + gatewayId: this.gatewayId, + sessionKey, + taskId, + seq: frame.seq, + data: { payload: summarizePayload(frame.payload) }, + }); + if (this.mainWindow) { sendToWindow(this.mainWindow, 'gateway-event', { gatewayId: this.gatewayId, @@ -209,11 +284,16 @@ export class GatewayClient { device, }; - this.sendReq('connect', params as unknown as Record) + this.sendReq('connect', params as unknown as Record, { requestId: 'connect-handshake' }) .then((payload) => { const pType = payload['type'] as string | undefined; if (pType === 'hello-ok') { - console.log(`[gateway:${this.gatewayId}] authenticated`); + getDebugLogger().info({ + domain: 'gateway', + event: 'gateway.connect.res.ok', + gatewayId: this.gatewayId, + requestId: 'connect-handshake', + }); this.authenticated = true; this.reconnectAttempts = 0; this.storeDeviceTokenFromPayload(payload); @@ -225,11 +305,23 @@ export class GatewayClient { }); } } else { - console.error(`[gateway:${this.gatewayId}] unexpected connect response:`, JSON.stringify(payload)); + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.connect.res.unexpected', + gatewayId: this.gatewayId, + requestId: 'connect-handshake', + data: { payload: summarizePayload(payload) }, + }); } }) .catch((err: Error) => { - console.log(`[gateway:${this.gatewayId}] connect handshake failed: ${err.message}`); + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.connect.failed', + gatewayId: this.gatewayId, + requestId: 'connect-handshake', + error: { name: err.name, message: err.message, stack: err.stack }, + }); this.ws?.close(); }); } @@ -247,39 +339,133 @@ export class GatewayClient { typeof role === 'string' ? role : 'operator', typeof issuedAtMs === 'number' ? issuedAtMs : Date.now(), ); + getDebugLogger().info({ + domain: 'gateway', + event: 'gateway.auth.device-token.saved', + gatewayId: this.gatewayId, + data: { role: typeof role === 'string' ? role : 'operator' }, + }); } } private handleResponse(frame: GatewayResFrame): void { const pending = this.pendingRequests.get(frame.id); - if (!pending) return; + if (!pending) { + getDebugLogger().warn({ + domain: 'gateway', + event: 'gateway.res.unmatched', + gatewayId: this.gatewayId, + wsFrameId: frame.id, + data: { ok: frame.ok }, + }); + return; + } this.pendingRequests.delete(frame.id); clearTimeout(pending.timer); + const durationMs = Date.now() - pending.startedAt; if (frame.ok && frame.payload) { + getDebugLogger().info({ + domain: 'gateway', + event: 'gateway.res.received', + gatewayId: this.gatewayId, + requestId: pending.requestId, + wsFrameId: frame.id, + sessionKey: pending.sessionKey, + taskId: pending.taskId, + durationMs, + ok: true, + data: { + method: pending.method, + payload: summarizePayload(frame.payload), + }, + }); pending.resolve(frame.payload); } else { const errMsg = frame.error?.message ?? 'request failed'; + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.res.error', + gatewayId: this.gatewayId, + requestId: pending.requestId, + wsFrameId: frame.id, + sessionKey: pending.sessionKey, + taskId: pending.taskId, + durationMs, + ok: false, + error: { message: errMsg, code: frame.error?.code }, + data: { method: pending.method }, + }); pending.reject(new Error(errMsg)); } } - sendReq(method: string, params: Record): Promise> { + sendReq( + method: string, + params: Record, + meta?: { requestId?: string; sessionKey?: string; taskId?: string }, + ): Promise> { return new Promise((resolve, reject) => { if (!this.ws || this.ws.readyState !== WebSocket.OPEN) { + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.req.rejected.not-connected', + gatewayId: this.gatewayId, + requestId: meta?.requestId, + sessionKey: meta?.sessionKey, + taskId: meta?.taskId, + data: { method }, + error: { message: 'not connected' }, + }); reject(new Error('not connected')); return; } const id = randomUUID(); + const requestId = meta?.requestId ?? randomUUID(); const frame: GatewayReqFrame = { type: 'req', id, method, params }; + const startedAt = Date.now(); const timer = setTimeout(() => { this.pendingRequests.delete(id); + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.req.timeout', + gatewayId: this.gatewayId, + requestId, + wsFrameId: id, + sessionKey: meta?.sessionKey, + taskId: meta?.taskId, + durationMs: Date.now() - startedAt, + data: { method }, + error: { message: `request timeout: ${method}` }, + }); reject(new Error(`request timeout: ${method}`)); }, REQ_TIMEOUT_MS); - this.pendingRequests.set(id, { resolve, reject, timer }); + this.pendingRequests.set(id, { + resolve, + reject, + timer, + method, + startedAt, + requestId, + sessionKey: meta?.sessionKey, + taskId: meta?.taskId, + }); + getDebugLogger().debug({ + domain: 'gateway', + event: 'gateway.req.sent', + gatewayId: this.gatewayId, + requestId, + wsFrameId: id, + sessionKey: meta?.sessionKey, + taskId: meta?.taskId, + data: { + method, + params: summarizePayload(params), + }, + }); this.ws.send(JSON.stringify(frame)); }); } @@ -298,19 +484,31 @@ export class GatewayClient { if (attachments?.length) { params.attachments = attachments; } - return this.sendReq('chat.send', params); + return this.sendReq('chat.send', params, { + requestId: randomUUID(), + sessionKey, + taskId: parseTaskIdFromSessionKey(sessionKey) ?? undefined, + }); } async abortChat(sessionKey: string): Promise> { - return this.sendReq('chat.abort', { sessionKey }); + return this.sendReq('chat.abort', { sessionKey }, { + requestId: randomUUID(), + sessionKey, + taskId: parseTaskIdFromSessionKey(sessionKey) ?? undefined, + }); } async getChatHistory(sessionKey: string, limit = 50): Promise> { - return this.sendReq('chat.history', { sessionKey, limit }); + return this.sendReq('chat.history', { sessionKey, limit }, { + requestId: randomUUID(), + sessionKey, + taskId: parseTaskIdFromSessionKey(sessionKey) ?? undefined, + }); } async listSessions(): Promise> { - return this.sendReq('sessions.list', {}); + return this.sendReq('sessions.list', {}, { requestId: randomUUID() }); } async listModels(): Promise> { @@ -331,10 +529,20 @@ export class GatewayClient { private startHeartbeat(): void { this.stopHeartbeat(); + getDebugLogger().info({ + domain: 'gateway', + event: 'gateway.heartbeat.start', + gatewayId: this.gatewayId, + }); this.heartbeatTimer = setInterval(() => { if (this.ws?.readyState === WebSocket.OPEN) { - this.sendReq('health', {}).catch(() => { - console.warn(`[gateway:${this.gatewayId}] heartbeat failed`); + this.sendReq('health', {}, { requestId: `heartbeat-${Date.now()}` }).catch((err) => { + getDebugLogger().warn({ + domain: 'gateway', + event: 'gateway.heartbeat.failed', + gatewayId: this.gatewayId, + error: { message: err instanceof Error ? err.message : 'heartbeat failed' }, + }); }); } }, HEARTBEAT_INTERVAL_MS); @@ -350,7 +558,13 @@ export class GatewayClient { private scheduleReconnect(): void { if (this.destroyed || this.noReconnect) return; if (this.reconnectAttempts >= MAX_RECONNECT_ATTEMPTS) { - console.error(`[gateway:${this.gatewayId}] max reconnect attempts reached`); + getDebugLogger().error({ + domain: 'gateway', + event: 'gateway.reconnect.give-up', + gatewayId: this.gatewayId, + attempt: this.reconnectAttempts, + error: { message: 'max reconnect attempts reached' }, + }); if (this.mainWindow) { sendToWindow(this.mainWindow, 'gateway-status', { gatewayId: this.gatewayId, @@ -363,7 +577,13 @@ export class GatewayClient { const delay = RECONNECT_DELAY_MS * Math.pow(2, Math.min(this.reconnectAttempts, 5)); this.reconnectAttempts++; - console.log(`[gateway:${this.gatewayId}] reconnecting in ${delay}ms (attempt ${this.reconnectAttempts})`); + getDebugLogger().warn({ + domain: 'gateway', + event: 'gateway.reconnect.scheduled', + gatewayId: this.gatewayId, + attempt: this.reconnectAttempts, + data: { delay }, + }); this.reconnectTimer = setTimeout(() => { this.connect(); @@ -379,6 +599,17 @@ export class GatewayClient { } for (const [id, pending] of this.pendingRequests) { clearTimeout(pending.timer); + getDebugLogger().warn({ + domain: 'gateway', + event: 'gateway.req.cancelled.connection-closed', + gatewayId: this.gatewayId, + requestId: pending.requestId, + wsFrameId: id, + sessionKey: pending.sessionKey, + taskId: pending.taskId, + data: { method: pending.method }, + error: { message: 'connection closed' }, + }); pending.reject(new Error('connection closed')); this.pendingRequests.delete(id); } diff --git a/packages/desktop/src/preload/clawwork.d.ts b/packages/desktop/src/preload/clawwork.d.ts index 18155e4..b3b9918 100644 --- a/packages/desktop/src/preload/clawwork.d.ts +++ b/packages/desktop/src/preload/clawwork.d.ts @@ -22,6 +22,23 @@ interface GatewayStatusEvent { error?: string; } +interface DebugEvent { + ts: string; + level: 'debug' | 'info' | 'warn' | 'error'; + domain: string; + event: string; + traceId?: string; + feature?: string; + message?: string; + gatewayId?: string; + sessionKey?: string; + taskId?: string; + requestId?: string; + durationMs?: number; + error?: { message: string; code?: string; stack?: string }; + data?: Record; +} + export interface GatewayServerConfig { id: string; name: string; @@ -149,6 +166,9 @@ export interface ClawWorkAPI { // Push events from main process onGatewayEvent: (callback: (data: GatewayEvent) => void) => (() => void); onGatewayStatus: (callback: (status: GatewayStatusEvent) => void) => (() => void); + onDebugEvent: (callback: (event: DebugEvent) => void) => (() => void); + exportDebugBundle: (filter?: { gatewayId?: string; sessionKey?: string; taskId?: string; limit?: number }) => Promise<{ ok: boolean; path?: string; eventCount?: number; error?: string }>; + reportDebugEvent: (event: { domain: string; event: string; traceId?: string; feature?: string; data?: Record }) => void; removeAllListeners: (channel: string) => void; // Data persistence diff --git a/packages/desktop/src/preload/index.ts b/packages/desktop/src/preload/index.ts index 2e56f69..f98860d 100644 --- a/packages/desktop/src/preload/index.ts +++ b/packages/desktop/src/preload/index.ts @@ -39,6 +39,15 @@ function buildApi(): ClawWorkAPI { ipcRenderer.on('gateway-status', listener); return () => { ipcRenderer.removeListener('gateway-status', listener); }; }, + onDebugEvent: (callback) => { + const listener = (_event: Electron.IpcRendererEvent, event: unknown): void => { + callback(event as { ts: string; level: 'debug' | 'info' | 'warn' | 'error'; domain: string; event: string; data?: Record }); + }; + ipcRenderer.on('debug-event', listener); + return () => { ipcRenderer.removeListener('debug-event', listener); }; + }, + exportDebugBundle: (filter) => ipcRenderer.invoke('debug:export-bundle', filter), + reportDebugEvent: (event) => ipcRenderer.send('debug:renderer-event', event), loadTasks: () => ipcRenderer.invoke('data:list-tasks'), diff --git a/packages/desktop/src/renderer/hooks/useGatewayDispatcher.ts b/packages/desktop/src/renderer/hooks/useGatewayDispatcher.ts index 77bff49..c210435 100644 --- a/packages/desktop/src/renderer/hooks/useGatewayDispatcher.ts +++ b/packages/desktop/src/renderer/hooks/useGatewayDispatcher.ts @@ -8,6 +8,17 @@ import { useTaskStore } from '../stores/taskStore'; import { useUiStore } from '../stores/uiStore'; import { hydrateFromLocal, syncFromGateway } from '../lib/session-sync'; +function debugEvent(event: string, data: Record, extra?: { traceId?: string; feature?: string }): void { + console.debug(`[debug] ${event}`, data); + window.clawwork.reportDebugEvent({ + domain: 'renderer', + event, + traceId: extra?.traceId, + feature: extra?.feature, + data, + }); +} + interface ChatContentBlock { type: string; text?: string; @@ -60,7 +71,16 @@ export function useGatewayEventDispatcher(): void { activeTaskIdRef.current = activeTaskId; useEffect(() => { + const removeDebug = window.clawwork.onDebugEvent((event) => { + console.debug(`[main-debug] ${event.event}`, event); + }); + const handler = (data: { event: string; payload: Record; gatewayId: string }): void => { + debugEvent('renderer.gateway.event.received', { + gatewayId: data.gatewayId, + event: data.event, + payloadKeys: Object.keys(data.payload ?? {}), + }); if (data.event === 'chat') { handleChatEvent(data.payload as unknown as ChatEventPayload); } else if (data.event === 'agent') { @@ -70,10 +90,16 @@ export function useGatewayEventDispatcher(): void { function handleChatEvent(payload: ChatEventPayload): void { const { sessionKey, state } = payload; - if (!sessionKey) return; + if (!sessionKey) { + debugEvent('renderer.event.dropped.missing_session', { state }); + return; + } const taskId = parseTaskIdFromSessionKey(sessionKey); - if (!taskId) return; + if (!taskId) { + debugEvent('renderer.event.dropped.invalid_task', { sessionKey, state }); + return; + } if (taskId !== activeTaskIdRef.current) { useUiStore.getState().markUnread(taskId); @@ -87,6 +113,7 @@ export function useGatewayEventDispatcher(): void { if (text) { store.setProcessing(taskId, false); store.appendStreamDelta(taskId, text); + debugEvent('renderer.chat.delta.applied', { taskId, sessionKey, chars: text.length }); } if (thinking) { store.appendThinkingDelta(taskId, thinking); @@ -104,18 +131,21 @@ export function useGatewayEventDispatcher(): void { if (thinking) { store.appendThinkingDelta(taskId, thinking); } + debugEvent('renderer.chat.final.received', { taskId, sessionKey, chars: text.length }); // Extract and attach any toolCall blocks before finalizing const toolCalls = extractToolCalls(payload); for (const tc of toolCalls) { store.upsertToolCall(taskId, tc); } store.finalizeStream(taskId); + debugEvent('renderer.chat.finalized', { taskId, sessionKey }); autoTitleIfNeeded(taskId); // Refresh session metadata to pick up token counts refreshSessionMetadata(sessionKey); } else if (state === 'error' || state === 'aborted') { store.setProcessing(taskId, false); store.finalizeStream(taskId); + debugEvent('renderer.chat.terminated', { taskId, sessionKey, state }); if (state === 'error') { const errText = extractText(payload) || i18n.t('errors.requestFailed'); store.addMessage(taskId, 'system', errText); @@ -125,10 +155,16 @@ export function useGatewayEventDispatcher(): void { function handleAgentEvent(payload: AgentToolEvent): void { const { sessionKey, stream, data } = payload; - if (stream !== 'tool' || !data || !sessionKey) return; + if (stream !== 'tool' || !data || !sessionKey) { + debugEvent('renderer.agent.dropped.invalid_payload', { stream, hasData: Boolean(data), hasSessionKey: Boolean(sessionKey) }); + return; + } const taskId = parseTaskIdFromSessionKey(sessionKey); - if (!taskId) return; + if (!taskId) { + debugEvent('renderer.agent.dropped.invalid_task', { sessionKey, stream }); + return; + } if (!data.name || !data.toolCallId) return; @@ -164,10 +200,14 @@ export function useGatewayEventDispatcher(): void { if (!tc.startedAt) tc.startedAt = new Date().toISOString(); store.upsertToolCall(taskId, tc); + debugEvent('renderer.toolcall.upserted', { taskId, sessionKey, toolCallId: tc.id, status: tc.status, name: tc.name }); } const removeGatewayEvent = window.clawwork.onGatewayEvent(handler); - return removeGatewayEvent; + return () => { + removeGatewayEvent(); + removeDebug(); + }; }, []); // Hydrate tasks + messages from local SQLite on mount diff --git a/packages/desktop/test/debug-export.test.ts b/packages/desktop/test/debug-export.test.ts new file mode 100644 index 0000000..7884b41 --- /dev/null +++ b/packages/desktop/test/debug-export.test.ts @@ -0,0 +1,52 @@ +import { describe, expect, it, beforeEach, afterEach } from 'vitest'; +import { mkdtempSync, readFileSync, rmSync, existsSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { createDebugLogger } from '../src/main/debug/logger'; +import { exportDebugBundle } from '../src/main/debug/export'; + +describe('debug export', () => { + let dir: string; + + beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'clawwork-debug-export-')); + }); + + afterEach(() => { + rmSync(dir, { recursive: true, force: true }); + }); + + it('exports recent events and metadata into a bundle directory', () => { + const logger = createDebugLogger({ + debugDir: dir, + maxEvents: 20, + console: false, + }); + + logger.info({ domain: 'gateway', event: 'gateway.req.sent', gatewayId: 'gw-1', sessionKey: 'agent:main:clawwork:task:task-1', taskId: 'task-1' }); + logger.error({ domain: 'ipc', event: 'ipc.ws.send-message.failed', gatewayId: 'gw-1', sessionKey: 'agent:main:clawwork:task:task-1', taskId: 'task-1', error: { message: 'timeout' } }); + + const result = exportDebugBundle({ + outputDir: join(dir, 'bundles'), + logger, + meta: { + gatewayStatus: { 'gw-1': { connected: false, name: 'Main Gateway' } }, + config: { token: 'secret-token', workspacePath: '/tmp/ws' }, + environment: { platform: 'darwin' }, + }, + filter: { gatewayId: 'gw-1', sessionKey: 'agent:main:clawwork:task:task-1' }, + }); + + expect(existsSync(result.bundlePath)).toBe(true); + expect(existsSync(join(result.bundlePath, 'recent-events.ndjson'))).toBe(true); + expect(existsSync(join(result.bundlePath, 'gateway-status.json'))).toBe(true); + expect(existsSync(join(result.bundlePath, 'config.sanitized.json'))).toBe(true); + expect(existsSync(join(result.bundlePath, 'environment.json'))).toBe(true); + + const config = JSON.parse(readFileSync(join(result.bundlePath, 'config.sanitized.json'), 'utf8')); + expect(config.token).toBe('***redacted***'); + + const timeline = JSON.parse(readFileSync(join(result.bundlePath, 'timeline.json'), 'utf8')); + expect(timeline.events).toHaveLength(2); + }); +}); diff --git a/packages/desktop/test/debug-observability.test.ts b/packages/desktop/test/debug-observability.test.ts new file mode 100644 index 0000000..e524bcd --- /dev/null +++ b/packages/desktop/test/debug-observability.test.ts @@ -0,0 +1,86 @@ +import { describe, expect, it, beforeEach, afterEach } from 'vitest'; +import { mkdtempSync, readFileSync, rmSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { createDebugLogger } from '../src/main/debug/logger'; +import { sanitizeForLog, summarizePayload } from '@clawwork/shared'; + +describe('debug observability foundation', () => { + it('redacts secrets and truncates long strings', () => { + const result = sanitizeForLog({ + token: 'secret-token', + nested: { password: 'pw123' }, + text: 'x'.repeat(520), + }) as Record; + + expect(result.token).toBe('***redacted***'); + expect((result.nested as Record).password).toBe('***redacted***'); + expect(result.text).toBe('x'.repeat(500) + '…'); + }); + + it('summarizes large payloads without leaking full content', () => { + const result = summarizePayload({ + message: 'hello world', + attachment: { + content: 'a'.repeat(900), + mimeType: 'text/plain', + }, + }) as Record; + + expect((result.attachment as Record).content).toBe('a'.repeat(500) + '…'); + expect(result.message).toBe('hello world'); + }); + + describe('createDebugLogger', () => { + let dir: string; + + beforeEach(() => { + dir = mkdtempSync(join(tmpdir(), 'clawwork-debug-')); + }); + + afterEach(() => { + rmSync(dir, { recursive: true, force: true }); + }); + + it('stores recent events and writes ndjson to disk', () => { + const seen: string[] = []; + const logger = createDebugLogger({ + debugDir: dir, + maxEvents: 3, + console: false, + onEvent: (event) => { + seen.push(event.event); + }, + }); + + logger.info({ domain: 'gateway', event: 'gateway.connect.start', gatewayId: 'gw-1' }); + logger.error({ domain: 'ipc', event: 'ipc.ws.send-message.failed', error: { message: 'not connected' } }); + + const events = logger.getRecentEvents(); + expect(events).toHaveLength(2); + expect(events[0]?.event).toBe('gateway.connect.start'); + expect(events[1]?.level).toBe('error'); + + const file = logger.currentFilePath(); + const lines = readFileSync(file, 'utf8').trim().split('\n'); + expect(lines).toHaveLength(2); + expect(JSON.parse(lines[1]!).error.message).toBe('not connected'); + expect(seen).toEqual(['gateway.connect.start', 'ipc.ws.send-message.failed']); + }); + + it('keeps only the newest events in memory', () => { + const logger = createDebugLogger({ + debugDir: dir, + maxEvents: 2, + console: false, + }); + + logger.debug({ domain: 'gateway', event: 'one' }); + logger.debug({ domain: 'gateway', event: 'two' }); + logger.debug({ domain: 'gateway', event: 'three' }); + + const events = logger.getRecentEvents(); + expect(events.map((event) => event.event)).toEqual(['two', 'three']); + }); + }); +}); diff --git a/packages/shared/src/debug.ts b/packages/shared/src/debug.ts new file mode 100644 index 0000000..0735e68 --- /dev/null +++ b/packages/shared/src/debug.ts @@ -0,0 +1,72 @@ +const REDACTED = '***redacted***'; +const TRUNCATE_AT = 500; +const SECRET_KEY_RE = /(token|password|secret|authorization|cookie)/i; + +export type DebugLevel = 'debug' | 'info' | 'warn' | 'error'; +export type DebugDomain = 'app' | 'gateway' | 'ipc' | 'renderer' | 'db' | 'workspace' | 'artifact' | 'debug'; + +export interface DebugError { + name?: string; + message: string; + stack?: string; + code?: string; +} + +export interface DebugEvent { + ts: string; + level: DebugLevel; + domain: DebugDomain; + event: string; + traceId?: string; + feature?: string; + message?: string; + gatewayId?: string; + sessionKey?: string; + taskId?: string; + runId?: string; + requestId?: string; + wsFrameId?: string; + seq?: number; + attempt?: number; + durationMs?: number; + ok?: boolean; + error?: DebugError; + data?: Record; +} + +export function truncateForLog(value: string, maxLen = TRUNCATE_AT): string { + if (value.length <= maxLen) return value; + return `${value.slice(0, maxLen)}…`; +} + +export function sanitizeForLog(value: T): T { + return sanitizeValue(value) as T; +} + +export function summarizePayload(value: T): T { + return sanitizeForLog(value); +} + +function sanitizeValue(value: unknown, key?: string): unknown { + if (key && SECRET_KEY_RE.test(key)) { + return REDACTED; + } + + if (typeof value === 'string') { + return truncateForLog(value); + } + + if (Array.isArray(value)) { + return value.map((item) => sanitizeValue(item)); + } + + if (!value || typeof value !== 'object') { + return value; + } + + const output: Record = {}; + for (const [entryKey, entryValue] of Object.entries(value)) { + output[entryKey] = sanitizeValue(entryValue, entryKey); + } + return output; +} diff --git a/packages/shared/src/index.ts b/packages/shared/src/index.ts index 5510a58..06ca5c2 100644 --- a/packages/shared/src/index.ts +++ b/packages/shared/src/index.ts @@ -1,3 +1,4 @@ export * from './types.js'; export * from './gateway-protocol.js'; export * from './constants.js'; +export * from './debug.js';