From a71a90bc733cfdea28dbf8bbf1385a8476c66a8b Mon Sep 17 00:00:00 2001 From: ethernet Date: Thu, 23 Jul 2026 16:54:10 -0400 Subject: [PATCH] feat(desktop): add debug trace instrumentation MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A device-local toggle (Settings → Advanced → Debug trace logging) that, when enabled, dumps structured console.debug entries for every stateful event in the desktop app: - Session state transitions (busy/needsInput/storedSessionId edges) - Compaction start/finish per session - message.complete events (session id, message count, usage/billing) - Session switches (activeSessionId + selectedStoredSessionId changes) - Compression id rotation (the spookiest bug class — route/pin/draft key silently changes mid-turn) - Persistence writes (key, op, truncated value preview) - All gateway events (type, session id, payload — deltas summarized) - Gateway connection state (idle→open→closed) + connection mode/profile - Profile switches ($activeGatewayProfile changes) - Resume failures + exhaustion (the #1 'stuck on loading' signal) - Busy/awaitingResponse edges - Message array length changes (count only, not per-token) - Error boundary catches (React render crashes with componentStack) - Blocking prompts: clarify/approval/sudo/secret raised/cleared edges - Sessions list length changes (new/archive/delete/merge) Zero cost when disabled: every debugTrace() call early-returns on the $debugTraceEnabled atom, and the subscriptions (persistence, gateway events, atom watchers) are no-op closures when tracing is off. Pattern follows keep-awake: device-local localStorage atom, side-effect import in main.tsx, ToggleRow in Settings → Advanced. i18n strings in all four locales (en/ja/zh/zh-hant). --- .../hooks/use-message-stream/gateway-event.ts | 13 + .../src/app/settings/config-settings.tsx | 5 + .../desktop/src/components/error-boundary.tsx | 5 + apps/desktop/src/i18n/en.ts | 4 +- apps/desktop/src/i18n/ja.ts | 4 +- apps/desktop/src/i18n/types.ts | 2 + apps/desktop/src/i18n/zh-hant.ts | 4 +- apps/desktop/src/i18n/zh.ts | 4 +- apps/desktop/src/lib/debug-trace.ts | 328 ++++++++++++++++++ apps/desktop/src/main.tsx | 3 + apps/desktop/src/store/compaction.ts | 5 + apps/desktop/src/store/session-states.ts | 13 + 12 files changed, 386 insertions(+), 4 deletions(-) create mode 100644 apps/desktop/src/lib/debug-trace.ts diff --git a/apps/desktop/src/app/session/hooks/use-message-stream/gateway-event.ts b/apps/desktop/src/app/session/hooks/use-message-stream/gateway-event.ts index 30ceb151056..761d2c7ee9c 100644 --- a/apps/desktop/src/app/session/hooks/use-message-stream/gateway-event.ts +++ b/apps/desktop/src/app/session/hooks/use-message-stream/gateway-event.ts @@ -11,6 +11,7 @@ import { translateNow } from '@/i18n' import { type GatewayEventPayload, textPart } from '@/lib/chat-messages' import { coerceGatewayText, coerceThinkingText, normalizePersonalityValue } from '@/lib/chat-runtime' import { playCompletionSound } from '@/lib/completion-sound' +import { debugTrace } from '@/lib/debug-trace' import { resolveGatewayEventSessionId } from '@/lib/gateway-events' import { triggerHaptic } from '@/lib/haptics' import { modelOptionsQueryKey } from '@/lib/model-options' @@ -34,6 +35,7 @@ import { $currentCwd, $currentModel, $currentProvider, + $messages, sessionMatchesStoredId, setCurrentBranch, setCurrentCwd, @@ -541,6 +543,17 @@ export function useGatewayEventHandler(deps: GatewayEventDeps) { return } + debugTrace( + 'message', + `complete session=${sessionId}`, + { + isActive: isActiveEvent, + messageCount: $messages.get().length, + hasUsage: Boolean(payload?.usage), + hasBilling: Boolean(payload?.billing) + } + ) + // Turn ended — drop any blocking prompt still open for THIS session // (e.g. interrupted, or the approval already resolved). Scoped to the // session so a background turn finishing can't wipe the active chat's diff --git a/apps/desktop/src/app/settings/config-settings.tsx b/apps/desktop/src/app/settings/config-settings.tsx index 18fa33d744a..bd563662484 100644 --- a/apps/desktop/src/app/settings/config-settings.tsx +++ b/apps/desktop/src/app/settings/config-settings.tsx @@ -7,6 +7,7 @@ import { useSearchParams } from 'react-router-dom' import { Button } from '@/components/ui/button' import { getElevenLabsVoices, getHermesConfigSchema, saveHermesConfig } from '@/hermes' import { useI18n } from '@/i18n' +import { $debugTraceEnabled, setDebugTraceEnabled } from '@/lib/debug-trace' import { $keepAwake, setKeepAwake } from '@/store/keep-awake' import { notify, notifyError } from '@/store/notifications' import { repoDiscoveryPolicyFromConfig, repoDiscoveryPolicySignature, scanAndRecordRepos } from '@/store/projects' @@ -57,6 +58,7 @@ export function ConfigSettings({ const { t } = useI18n() const c = t.settings.config const keepAwake = useStore($keepAwake) + const debugTraceEnabled = useStore($debugTraceEnabled) // The editable draft is local (debounced autosave watches it), but it's seeded // from — and saved back through — the shared config cache, so edits are visible // in the MCP/model surfaces and reopening the page doesn't reload-flash. @@ -293,6 +295,9 @@ export function ConfigSettings({ {activeSectionId === 'advanced' && ( )} + {activeSectionId === 'advanced' && ( + + )} {visibleFields.length === 0 ? ( ) : ( diff --git a/apps/desktop/src/components/error-boundary.tsx b/apps/desktop/src/components/error-boundary.tsx index 87b6b7743c5..72763deb2f2 100644 --- a/apps/desktop/src/components/error-boundary.tsx +++ b/apps/desktop/src/components/error-boundary.tsx @@ -2,6 +2,7 @@ import { Component, type ErrorInfo, type ReactNode } from 'react' import { Button } from '@/components/ui/button' import { ErrorState } from '@/components/ui/error-state' +import { debugTrace } from '@/lib/debug-trace' import { useI18n } from '@/i18n' export interface ErrorBoundaryFallbackProps { @@ -30,6 +31,10 @@ export class ErrorBoundary extends Component( + typeof window === 'undefined' ? false : (() => { + try { + return window.localStorage.getItem(KEY) === 'true' + } catch { + return false + } + })() +) + +export function setDebugTraceEnabled(on: boolean): void { + $debugTraceEnabled.set(on) +} + +if (typeof window !== 'undefined') { + $debugTraceEnabled.subscribe(on => { + try { + window.localStorage.setItem(KEY, String(on)) + } catch { + // Storage best-effort. + } + }) +} + +export type DebugCategory = + | 'session-state' + | 'compaction' + | 'message' + | 'session-switch' + | 'persistence' + | 'gateway-event' + | 'connection' + | 'profile-switch' + | 'resume' + | 'busy' + | 'error-boundary' + | 'prompt' + | 'sessions-list' + +const CATEGORY_PREFIX: Record = { + 'session-state': '[trace:session-state]', + compaction: '[trace:compaction]', + message: '[trace:message]', + 'session-switch': '[trace:session-switch]', + persistence: '[trace:persistence]', + 'gateway-event': '[trace:gateway-event]', + connection: '[trace:connection]', + 'profile-switch': '[trace:profile-switch]', + resume: '[trace:resume]', + busy: '[trace:busy]', + 'error-boundary': '[trace:error-boundary]', + prompt: '[trace:prompt]', + 'sessions-list': '[trace:sessions-list]' +} + +/** + * Emit a debug trace entry. No-ops entirely when tracing is disabled. + * + * `data` is spread as additional console arguments (not stringified) so + * devtools can expand/inspect objects natively. + */ +export function debugTrace( + category: DebugCategory, + message: string, + ...data: unknown[] +): void { + if (!$debugTraceEnabled.get()) { + return + } + + const ts = new Date().toISOString() + + // eslint-disable-next-line no-console + console.debug(`${CATEGORY_PREFIX[category]} ${ts} ${message}`, ...data) +} + +// --------------------------------------------------------------------------- +// Subscriptions — attached once at module init, no-op when disabled. +// --------------------------------------------------------------------------- + +if (typeof window !== 'undefined') { + // --- Session switches --- + let prevActive: string | null = null + $activeSessionId.subscribe(id => { + if (id !== prevActive) { + debugTrace('session-switch', `activeSessionId ${prevActive ?? 'null'} → ${id ?? 'null'}`) + prevActive = id + } + }) + + let prevSelected: string | null = null + $selectedStoredSessionId.subscribe(id => { + if (id !== prevSelected) { + debugTrace('session-switch', `selectedStoredSessionId ${prevSelected ?? 'null'} → ${id ?? 'null'}`) + prevSelected = id + } + }) + + // --- Persistence events --- + onPersistenceEvent(event => { + const valuePreview = + event.value === null + ? 'null' + : event.value.length > 120 + ? `${event.value.slice(0, 120)}…(${event.value.length} chars)` + : event.value + + debugTrace('persistence', `${event.op} ${event.key}`, { value: valuePreview }) + }) + + // --- Gateway events (wildcard) --- + onGatewayEvent('*', event => { + const type = event.type ?? 'unknown' + const raw = event as unknown as Record + const sessionId = raw.session_id ?? raw.sessionId ?? null + + // Summarize — don't dump the full payload for high-frequency deltas. + const summary: Record = { type } + + if (sessionId) { + summary.sessionId = sessionId + } + + // For message.delta, just note it happened (they fire 30×/s during a turn). + // For everything else, include the payload for inspection. + if (type === 'message.delta') { + summary.note = 'delta (streaming)' + } else { + summary.payload = event + } + + debugTrace('gateway-event', type, summary) + }) + + // --- Gateway connection state --- + let prevGatewayState: string | undefined + $gatewayState.subscribe(state => { + if (state !== prevGatewayState) { + debugTrace('connection', `gatewayState ${prevGatewayState ?? 'undefined'} → ${state}`) + prevGatewayState = state + } + }) + + // --- Connection (mode/baseUrl/profile) --- + let prevConnMode: string | undefined + let prevConnProfile: string | undefined + $connection.subscribe(conn => { + const mode = conn?.mode ?? 'null' + const profile = conn?.profile ?? 'null' + + if (mode !== prevConnMode || profile !== prevConnProfile) { + debugTrace('connection', `connection mode=${mode} profile=${profile} baseUrl=${conn?.baseUrl ?? 'null'}`) + prevConnMode = mode + prevConnProfile = profile + } + }) + + // --- Profile switches --- + let prevProfile: string | undefined + $activeGatewayProfile.subscribe(profile => { + if (profile !== prevProfile) { + debugTrace('profile-switch', `${prevProfile ?? 'undefined'} → ${profile}`) + prevProfile = profile + } + }) + + // --- Resume failures + exhaustion --- + let prevResumeFailed: string | null = null + $resumeFailedSessionId.subscribe(id => { + if (id !== prevResumeFailed) { + debugTrace('resume', `resumeFailedSessionId ${prevResumeFailed ?? 'null'} → ${id ?? 'null'}`) + prevResumeFailed = id + } + }) + + let prevResumeExhausted: string | null = null + $resumeExhaustedSessionId.subscribe(id => { + if (id !== prevResumeExhausted) { + debugTrace('resume', `resumeExhaustedSessionId ${prevResumeExhausted ?? 'null'} → ${id ?? 'null'}`) + prevResumeExhausted = id + } + }) + + // --- Busy / awaitingResponse edges --- + let prevBusy = false + $busy.subscribe(busy => { + if (busy !== prevBusy) { + debugTrace('busy', `busy ${prevBusy} → ${busy}`, { activeSessionId: $activeSessionId.get() }) + prevBusy = busy + } + }) + + let prevAwaiting = false + $awaitingResponse.subscribe(awaiting => { + if (awaiting !== prevAwaiting) { + debugTrace('busy', `awaitingResponse ${prevAwaiting} → ${awaiting}`, { activeSessionId: $activeSessionId.get() }) + prevAwaiting = awaiting + } + }) + + // --- Message array length changes --- + // Not per-token (that'd be insane) — only when the count changes, which + // captures: new message added, transcript cleared, session switched, + // reconciliation replaced the array. + let prevMessageCount = -1 + $messages.subscribe(messages => { + const count = messages.length + + if (count !== prevMessageCount) { + debugTrace('message', `messages count ${prevMessageCount} → ${count}`, { + activeSessionId: $activeSessionId.get() + }) + prevMessageCount = count + } + }) + + // --- Compression id rotation --- + // Fires when auto-compaction rotates the active session's stored id mid-turn. + // One of the spookiest bug classes — the route / pin / draft key silently + // changes under the user. + $activeSessionStoredIdRotation.subscribe(rotation => { + if (rotation) { + debugTrace('session-switch', `compression id rotation`, { + prev: rotation.previousStoredSessionId, + next: rotation.nextStoredSessionId, + runtime: rotation.runtimeSessionId, + isActive: rotation.runtimeSessionId === $activeSessionId.get() + }) + } + }) + + // --- Blocking prompts (clarify / approval / sudo / secret) --- + // When these appear/disappear, the chat is blocked. Tracing the edges + // catches "agent silently stalled" bugs. + let prevClarify: unknown = null + $clarifyRequest.subscribe(req => { + if (req !== prevClarify) { + debugTrace('prompt', `clarify ${prevClarify ? 'cleared' : 'raised'}`, { + sessionId: $activeSessionId.get(), + requestId: req ? 'present' : 'null' + }) + prevClarify = req + } + }) + + let prevApproval: unknown = null + $approvalRequest.subscribe(req => { + if (req !== prevApproval) { + debugTrace('prompt', `approval ${prevApproval ? 'cleared' : 'raised'}`, { + sessionId: $activeSessionId.get() + }) + prevApproval = req + } + }) + + let prevSudo: unknown = null + $sudoRequest.subscribe(req => { + if (req !== prevSudo) { + debugTrace('prompt', `sudo ${prevSudo ? 'cleared' : 'raised'}`, { + sessionId: $activeSessionId.get() + }) + prevSudo = req + } + }) + + let prevSecret: unknown = null + $secretRequest.subscribe(req => { + if (req !== prevSecret) { + debugTrace('prompt', `secret ${prevSecret ? 'cleared' : 'raised'}`, { + sessionId: $activeSessionId.get() + }) + prevSecret = req + } + }) + + // --- Sessions list length changes --- + // Captures: new session created, session archived/deleted, sidebar merge + // kept/dropped a row. Not per-field — just the count edge. + let prevSessionsCount = -1 + $sessions.subscribe(list => { + const count = list.length + + if (count !== prevSessionsCount) { + debugTrace('sessions-list', `sessions count ${prevSessionsCount} → ${count}`) + prevSessionsCount = count + } + }) +} diff --git a/apps/desktop/src/main.tsx b/apps/desktop/src/main.tsx index b1dd657655b..bba97435120 100644 --- a/apps/desktop/src/main.tsx +++ b/apps/desktop/src/main.tsx @@ -1,6 +1,9 @@ import './styles.css' // Side-effect: applies the persisted window translucency on load. import './store/translucency' +// Side-effect: attaches debug trace subscriptions (persistence, gateway +// events, session switch watchers). No-ops entirely when tracing is disabled. +import './lib/debug-trace' import { QueryClientProvider } from '@tanstack/react-query' import { StrictMode } from 'react' diff --git a/apps/desktop/src/store/compaction.ts b/apps/desktop/src/store/compaction.ts index b35e35b4b69..e0f4bbb9cc1 100644 --- a/apps/desktop/src/store/compaction.ts +++ b/apps/desktop/src/store/compaction.ts @@ -1,5 +1,6 @@ import { atom, computed } from 'nanostores' +import { debugTrace } from '@/lib/debug-trace' import { $activeSessionId } from './session' // Per-session flag while auto-compaction runs mid-turn. Without it the @@ -25,6 +26,8 @@ export function setSessionCompacting(sessionId: string | null | undefined, activ $compactingSessions.set({ ...sessions, [key]: true }) + debugTrace('compaction', `started session=${key}`, { isActive: key === $activeSessionId.get() }) + return } @@ -35,4 +38,6 @@ export function setSessionCompacting(sessionId: string | null | undefined, activ const next = { ...sessions } delete next[key] $compactingSessions.set(next) + + debugTrace('compaction', `finished session=${key}`, { isActive: key === $activeSessionId.get() }) } diff --git a/apps/desktop/src/store/session-states.ts b/apps/desktop/src/store/session-states.ts index d8248f00d8e..f0d7aca6944 100644 --- a/apps/desktop/src/store/session-states.ts +++ b/apps/desktop/src/store/session-states.ts @@ -27,6 +27,7 @@ import { noteActiveTreeGroup, revealTreePane } from '@/components/pane-shell/tree/store' +import { debugTrace } from '@/lib/debug-trace' import { stableArray } from '@/lib/stable-array' import { readJson, writeJson } from '@/lib/storage' @@ -189,6 +190,18 @@ export function publishSessionState(runtimeId: string, state: ClientSessionState const prev = $sessionStates.get()[runtimeId] ?? null $sessionStates.set({ ...$sessionStates.get(), [runtimeId]: state }) handleTransition(prev, state, runtimeId) + + debugTrace( + 'session-state', + `publish ${runtimeId}`, + { + prev: prev + ? { storedSessionId: prev.storedSessionId, busy: prev.busy, needsInput: prev.needsInput } + : null, + next: { storedSessionId: state.storedSessionId, busy: state.busy, needsInput: state.needsInput }, + isActive: runtimeId === $activeSessionId.get() + } + ) } export function dropSessionState(runtimeId: string) {