From 7c23b925e58714e0c3f2721f11dcce153affcd89 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 13:17:42 +1000 Subject: [PATCH 01/12] feat: add info-level session lifecycle logs to detect backend session creation triggers Adds [session] prefixed console.log statements at key points: - createDraftSession: when a frontend draft is created - promoteDraft: when a draft is promoted for first message send - acpPrepareSession: before/after backend session creation with trigger reason - acp:session_bound: when backend confirms session binding - setSessionAcpId: when frontend links to backend session ID - loadSessions: summary of backend sessions including empty session count - sendMessage error/abort: when message send fails after session creation These logs help diagnose empty chat sessions by tracing what triggered backend session creation and whether the subsequent message send succeeded. Co-Authored-By: Claude Opus 4.6 (1M context) --- scripts/check-file-sizes.mjs | 4 ++-- src/features/chat/hooks/useAcpStream.ts | 3 +++ src/features/chat/hooks/useChat.ts | 10 ++++++++++ src/features/chat/stores/chatSessionStore.ts | 11 +++++++++++ 4 files changed, 26 insertions(+), 2 deletions(-) diff --git a/scripts/check-file-sizes.mjs b/scripts/check-file-sizes.mjs index cf4ba8c..a7eb01b 100644 --- a/scripts/check-file-sizes.mjs +++ b/scripts/check-file-sizes.mjs @@ -46,9 +46,9 @@ const EXCEPTIONS = { "ACP session overlay regressions currently need one broad integration-style store suite.", }, "src/features/chat/stores/chatSessionStore.ts": { - limit: 640, + limit: 650, justification: - "ACP-backed session overlay persistence, draft migration, and sidebar-facing session merge logic live together for now.", + "ACP-backed session overlay persistence, draft migration, sidebar-facing session merge logic, and session lifecycle logging live together for now.", }, "src-tauri/src/services/acp/manager/dispatcher.rs": { limit: 520, diff --git a/src/features/chat/hooks/useAcpStream.ts b/src/features/chat/hooks/useAcpStream.ts index 1abea39..2c39c7a 100644 --- a/src/features/chat/hooks/useAcpStream.ts +++ b/src/features/chat/hooks/useAcpStream.ts @@ -453,6 +453,9 @@ export function useAcpStream(enabled: boolean): void { unlisteners.push( listen("acp:session_bound", (event) => { if (!active) return; + console.log( + `[session] acp:session_bound ${event.payload.sessionId.slice(0, 8)} → goose=${event.payload.gooseSessionId.slice(0, 8)}`, + ); useChatSessionStore .getState() .setSessionAcpId( diff --git a/src/features/chat/hooks/useChat.ts b/src/features/chat/hooks/useChat.ts index 73ee794..add28ea 100644 --- a/src/features/chat/hooks/useChat.ts +++ b/src/features/chat/hooks/useChat.ts @@ -204,10 +204,16 @@ export function useChat( try { if (wasDraft || selectedModelId) { + console.log( + `[session] acpPrepareSession ${sessionId.slice(0, 8)} (trigger=${wasDraft ? "draft-promotion" : "model-change"}, provider=${providerId}, model=${selectedModelId ?? "default"})`, + ); await acpPrepareSession(sessionId, providerId, { workingDir: workingDirOverride, personaId: effectivePersonaInfo?.id, }); + console.log( + `[session] acpPrepareSession ${sessionId.slice(0, 8)} completed — backend session created`, + ); if (selectedModelId) { await acpSetModel(sessionId, selectedModelId); } @@ -242,9 +248,13 @@ export function useChat( } } catch (err) { if (err instanceof DOMException && err.name === "AbortError") { + console.log(`[session] sendMessage ${sessionId.slice(0, 8)} aborted`); store.setChatState(sessionId, "idle"); } else { const errorMessage = getErrorMessage(err); + console.log( + `[session] sendMessage ${sessionId.slice(0, 8)} failed (wasDraft=${wasDraft}): ${errorMessage}`, + ); const liveStore = useChatStore.getState(); const { streamingMessageId } = liveStore.getSessionRuntime(sessionId); if (streamingMessageId) { diff --git a/src/features/chat/stores/chatSessionStore.ts b/src/features/chat/stores/chatSessionStore.ts index 8915037..91bf753 100644 --- a/src/features/chat/stores/chatSessionStore.ts +++ b/src/features/chat/stores/chatSessionStore.ts @@ -324,6 +324,9 @@ export const useChatSessionStore = create((set, get) => ({ messageCount: 0, draft: true, }; + console.log( + `[session] createDraftSession ${chatSession.id.slice(0, 8)} project=${opts?.projectId?.slice(0, 8) ?? "none"} provider=${opts?.providerId ?? "none"}`, + ); set((state) => ({ sessions: [...state.sessions, chatSession] })); persistDraftSessionRecord(draftSessionToRecord(chatSession)); return chatSession; @@ -332,6 +335,7 @@ export const useChatSessionStore = create((set, get) => ({ promoteDraft: (id) => { const session = get().sessions.find((candidate) => candidate.id === id); if (!session?.draft) return; + console.log(`[session] promoteDraft ${id.slice(0, 8)}`); set((state) => ({ sessions: state.sessions.map((candidate) => candidate.id === id ? { ...candidate, draft: undefined } : candidate, @@ -365,6 +369,10 @@ export const useChatSessionStore = create((set, get) => ({ try { const overlays = loadSessionMetadataOverlay(); const acpSessions = await acpListSessions(); + const emptyCount = acpSessions.filter((s) => s.messageCount === 0).length; + console.log( + `[session] loadSessions: ${acpSessions.length} backend (${emptyCount} empty), ${overlays.size} overlays`, + ); const persistedDrafts = loadDraftSessionRecords(); const currentDrafts = get().sessions.filter((session) => session.draft); const drafts = mergeDraftSessions(currentDrafts, persistedDrafts); @@ -504,6 +512,9 @@ export const useChatSessionStore = create((set, get) => ({ if (!acpSessionId) return; const session = get().sessions.find((candidate) => candidate.id === id); if (!session || session.acpSessionId === acpSessionId) return; + console.log( + `[session] setSessionAcpId ${id.slice(0, 8)} → goose=${acpSessionId.slice(0, 8)} draft=${!!session.draft} msgs=${session.messageCount}`, + ); set((state) => ({ sessions: state.sessions.map((candidate) => From 1de01622f4a69889df6cd11c504127edbb1e892c Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 15:20:31 +1000 Subject: [PATCH 02/12] chore: enable dotenv-load in justfile Co-Authored-By: Claude Opus 4.6 (1M context) --- justfile | 2 ++ 1 file changed, 2 insertions(+) diff --git a/justfile b/justfile index 86ce081..4600e06 100644 --- a/justfile +++ b/justfile @@ -1,3 +1,5 @@ +set dotenv-load + # Default recipe default: @just --list From 8fa89fb54be25b0d2588557a01120540b1fa0a76 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 16:09:03 +1000 Subject: [PATCH 03/12] feat: add replay diagnostics to trace incomplete session history loading Replaces [session] lifecycle logs with [replay] logs that trace the full session history loading pipeline: Frontend (useAcpStream/AppShell): - Log when loadSessionMessages starts with goose session ID and messageCount - Count replay events (user messages, assistant messages, total) as they arrive - Log replay_complete with event counts and buffer size - Log buffer flush with message role breakdown - Log timeout with accumulated event counts to detect stalled replays Backend (Rust dispatcher/session_ops): - Log load_session start with session ID mapping and working dir - Count replayed user/assistant messages in SessionRoute - Log load_session completion with event counts and elapsed time These logs help diagnose sessions that load with missing messages by showing exactly how many events the backend emitted vs how many the frontend received and buffered. Co-Authored-By: Claude Opus 4.6 (1M context) --- scripts/check-file-sizes.mjs | 12 ++-- .../src/services/acp/manager/dispatcher.rs | 43 +++++++++++++ .../src/services/acp/manager/session_ops.rs | 19 ++++++ src/app/AppShell.tsx | 23 +++---- src/features/chat/hooks/replayBuffer.ts | 4 ++ src/features/chat/hooks/useAcpStream.ts | 63 ++++++++++++++++--- src/features/chat/hooks/useChat.ts | 12 +--- src/features/chat/stores/chatSessionStore.ts | 14 +---- 8 files changed, 141 insertions(+), 49 deletions(-) diff --git a/scripts/check-file-sizes.mjs b/scripts/check-file-sizes.mjs index a7eb01b..01009b5 100644 --- a/scripts/check-file-sizes.mjs +++ b/scripts/check-file-sizes.mjs @@ -31,9 +31,9 @@ const EXCEPTIONS = { "Shell still coordinates ACP session loading, project reassignment, and app-level chat routing.", }, "src/features/chat/hooks/useAcpStream.ts": { - limit: 580, + limit: 600, justification: - "ACP replay, streaming, session binding, model-state event handling, and replay timeout are still centralized here.", + "ACP replay, streaming, session binding, model-state event handling, replay timeout, and replay diagnostics are still centralized here.", }, "src/features/chat/hooks/__tests__/useAcpStream.test.ts": { limit: 570, @@ -51,9 +51,9 @@ const EXCEPTIONS = { "ACP-backed session overlay persistence, draft migration, sidebar-facing session merge logic, and session lifecycle logging live together for now.", }, "src-tauri/src/services/acp/manager/dispatcher.rs": { - limit: 520, + limit: 570, justification: - "ACP replay and live-stream event fan-out share one dispatcher until session event routing is split.", + "ACP replay and live-stream event fan-out share one dispatcher with replay event counting until session event routing is split.", }, "src-tauri/src/services/acp/manager.rs": { limit: 630, @@ -61,9 +61,9 @@ const EXCEPTIONS = { "ACP manager command dispatch loop — export/import/fork session ext_method dispatch adds boilerplate.", }, "src-tauri/src/services/acp/manager/session_ops.rs": { - limit: 570, + limit: 585, justification: - "Session prepare/load/list logic, working-dir updates, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", + "Session prepare/load/list logic, working-dir updates, replay diagnostics, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", }, }; diff --git a/src-tauri/src/services/acp/manager/dispatcher.rs b/src-tauri/src/services/acp/manager/dispatcher.rs index 0e6155f..b0a3222 100644 --- a/src-tauri/src/services/acp/manager/dispatcher.rs +++ b/src-tauri/src/services/acp/manager/dispatcher.rs @@ -58,6 +58,15 @@ pub(super) struct SessionRoute { pub(super) writer: Option>, pub(super) canceled: bool, pub(super) replay_message_id: Option, + pub(super) replay_user_messages: u32, + pub(super) replay_assistant_messages: u32, + pub(super) replay_events: u32, +} + +pub(super) struct ReplayEventCounts { + pub(super) user_messages: u32, + pub(super) assistant_messages: u32, + pub(super) total: u32, } pub(super) struct SessionEventDispatcher { @@ -94,6 +103,9 @@ impl SessionEventDispatcher { writer: None, canceled: false, replay_message_id: None, + replay_user_messages: 0, + replay_assistant_messages: 0, + replay_events: 0, }); let _ = self.app_handle.emit( @@ -121,6 +133,9 @@ impl SessionEventDispatcher { writer: Some(writer), canceled: false, replay_message_id: None, + replay_user_messages: 0, + replay_assistant_messages: 0, + replay_events: 0, }, ); } @@ -254,6 +269,25 @@ impl SessionEventDispatcher { }, ); } + + pub(super) async fn get_replay_event_counts( + &self, + goose_session_id: &str, + ) -> ReplayEventCounts { + let routes = self.routes.lock().await; + routes + .get(goose_session_id) + .map(|r| ReplayEventCounts { + user_messages: r.replay_user_messages, + assistant_messages: r.replay_assistant_messages, + total: r.replay_events, + }) + .unwrap_or(ReplayEventCounts { + user_messages: 0, + assistant_messages: 0, + total: 0, + }) + } } fn extract_content_preview(content: &[agent_client_protocol::ToolCallContent]) -> Option { @@ -399,6 +433,13 @@ impl Client for SessionEventDispatcher { let display_text = extract_user_message(&text.text); let message_id = uuid::Uuid::new_v4().to_string(); + { + let mut routes = self.routes.lock().await; + if let Some(route) = routes.get_mut(&goose_session_id) { + route.replay_user_messages += 1; + route.replay_events += 1; + } + } let _ = self.app_handle.emit( "acp:replay_user_message", serde_json::json!({ @@ -436,6 +477,8 @@ impl Client for SessionEventDispatcher { let mut routes = self.routes.lock().await; if let Some(route) = routes.get_mut(&goose_session_id) { route.replay_message_id = Some(new_id.clone()); + route.replay_assistant_messages += 1; + route.replay_events += 1; } new_id }; diff --git a/src-tauri/src/services/acp/manager/session_ops.rs b/src-tauri/src/services/acp/manager/session_ops.rs index 1be791f..b9d6dd8 100644 --- a/src-tauri/src/services/acp/manager/session_ops.rs +++ b/src-tauri/src/services/acp/manager/session_ops.rs @@ -427,10 +427,18 @@ pub(super) async fn load_session_inner( goose_session_id: &str, working_dir: PathBuf, ) -> Result<(), String> { + log::info!( + "[replay] {} loading goose session {} from {:?}", + &local_session_id[..8.min(local_session_id.len())], + &goose_session_id[..8.min(goose_session_id.len())], + working_dir, + ); + dispatcher .bind_session(goose_session_id, local_session_id, None) .await; + let t0 = std::time::Instant::now(); let response = connection .load_session(LoadSessionRequest::new( goose_session_id.to_string(), @@ -441,6 +449,17 @@ pub(super) async fn load_session_inner( // Finalize any in-progress replay assistant message dispatcher.finalize_replay(goose_session_id).await; + + let replay_counts = dispatcher.get_replay_event_counts(goose_session_id).await; + log::info!( + "[replay] {} load_session completed in {:?} — emitted {} events ({} user, {} assistant), sending replay_complete", + &local_session_id[..8.min(local_session_id.len())], + t0.elapsed(), + replay_counts.total, + replay_counts.user_messages, + replay_counts.assistant_messages, + ); + dispatcher.emit_replay_complete(local_session_id); if let Some(models) = &response.models { diff --git a/src/app/AppShell.tsx b/src/app/AppShell.tsx index 386e4b3..72178c5 100644 --- a/src/app/AppShell.tsx +++ b/src/app/AppShell.tsx @@ -68,24 +68,22 @@ export function AppShell({ children }: { children?: React.ReactNode }) { const existing = useChatStore.getState().messagesBySession[sessionId]; if (existing && existing.length > 0) { console.log( - `[perf:load] ${sessionId.slice(0, 8)} skip — already has messages`, + `[replay] ${sessionId.slice(0, 8)} skip — already has ${existing.length} messages in store`, ); return; } const t0 = performance.now(); - console.log(`[perf:load] ${sessionId.slice(0, 8)} start`); const store = useChatStore.getState(); store.setSessionLoading(sessionId, true); try { - const t1 = performance.now(); const { acpLoadSession } = await import("@/shared/api/acp"); - const t2 = performance.now(); - console.log( - `[perf:load] ${sessionId.slice(0, 8)} import took ${(t2 - t1).toFixed(1)}ms`, - ); const session = useChatSessionStore.getState().getSession(sessionId); const gooseSessionId = session?.acpSessionId ?? sessionId; + const messageCount = session?.messageCount ?? "unknown"; + console.log( + `[replay] ${sessionId.slice(0, 8)} loading — goose=${gooseSessionId.slice(0, 8)} messageCount=${messageCount}`, + ); const project = session?.projectId ? (useProjectStore .getState() @@ -98,16 +96,15 @@ export function AppShell({ children }: { children?: React.ReactNode }) { ? resolveEffectiveWorkingDir(null, await getHomeDir()) : undefined); await acpLoadSession(sessionId, gooseSessionId, workingDir); - const t3 = performance.now(); console.log( - `[perf:load] ${sessionId.slice(0, 8)} acpLoadSession resolved in ${(t3 - t2).toFixed(1)}ms (total ${(t3 - t0).toFixed(1)}ms)`, + `[replay] ${sessionId.slice(0, 8)} acpLoadSession resolved in ${(performance.now() - t0).toFixed(0)}ms — waiting for replay events`, ); } catch (err) { - console.error("Failed to load session messages:", err); - useChatStore.getState().setSessionLoading(sessionId, false); - console.log( - `[perf:load] ${sessionId.slice(0, 8)} failed, loading=false at +${(performance.now() - t0).toFixed(1)}ms`, + console.error( + `[replay] ${sessionId.slice(0, 8)} acpLoadSession failed:`, + err, ); + useChatStore.getState().setSessionLoading(sessionId, false); } }, []); diff --git a/src/features/chat/hooks/replayBuffer.ts b/src/features/chat/hooks/replayBuffer.ts index d9af08a..e080b25 100644 --- a/src/features/chat/hooks/replayBuffer.ts +++ b/src/features/chat/hooks/replayBuffer.ts @@ -35,6 +35,10 @@ export function getBufferedMessage( return replayBuffers.get(sessionId)?.find((m) => m.id === messageId); } +export function getReplayBufferSize(sessionId: string): number { + return replayBuffers.get(sessionId)?.length ?? 0; +} + export function getAndDeleteReplayBuffer( sessionId: string, ): Message[] | undefined { diff --git a/src/features/chat/hooks/useAcpStream.ts b/src/features/chat/hooks/useAcpStream.ts index 2c39c7a..6846d44 100644 --- a/src/features/chat/hooks/useAcpStream.ts +++ b/src/features/chat/hooks/useAcpStream.ts @@ -13,6 +13,7 @@ import { ensureReplayBuffer, getBufferedMessage, getAndDeleteReplayBuffer, + getReplayBufferSize, findLatestUnpairedToolRequest, } from "./replayBuffer"; import type { @@ -93,20 +94,40 @@ export function useAcpStream(enabled: boolean): void { const replayTimeouts = new Map>(); const REPLAY_TIMEOUT_MS = 30_000; + const replayEventCounts = new Map< + string, + { + userMessages: number; + assistantMessages: number; + events: number; + t0: number; + } + >(); const unsubscribeFlush = useChatStore.subscribe((state, prevState) => { if (!active) return; - // Start timeout for newly-loading sessions + // Start timeout and event counter for newly-loading sessions for (const sid of state.loadingSessionIds) { if (!prevState.loadingSessionIds.has(sid) && !replayTimeouts.has(sid)) { + replayEventCounts.set(sid, { + userMessages: 0, + assistantMessages: 0, + events: 0, + t0: performance.now(), + }); const timer = setTimeout(() => { replayTimeouts.delete(sid); const store = useChatStore.getState(); if (store.loadingSessionIds.has(sid)) { + const counts = replayEventCounts.get(sid); + const bufferLen = getReplayBufferSize(sid); console.warn( - `[stream] ${sid.slice(0, 8)} replay_complete not received within ${REPLAY_TIMEOUT_MS / 1000}s — showing error`, + `[replay] ${sid.slice(0, 8)} TIMEOUT after ${REPLAY_TIMEOUT_MS / 1000}s — ` + + `received ${counts?.events ?? 0} events (${counts?.userMessages ?? 0} user, ` + + `${counts?.assistantMessages ?? 0} assistant), ${bufferLen} buffered — replay_complete never arrived`, ); + replayEventCounts.delete(sid); store.setSessionLoading(sid, false); store.setError( sid, @@ -128,10 +149,18 @@ export function useAcpStream(enabled: boolean): void { } const buffer = getAndDeleteReplayBuffer(sid); if (buffer && buffer.length > 0) { + const userCount = buffer.filter((m) => m.role === "user").length; + const assistantCount = buffer.filter( + (m) => m.role === "assistant", + ).length; console.log( - `[perf:stream] ${sid.slice(0, 8)} flushing replay buffer (${buffer.length} messages) at ${performance.now().toFixed(1)}ms`, + `[replay] ${sid.slice(0, 8)} flushing buffer → ${buffer.length} messages (${userCount} user, ${assistantCount} assistant) into store`, ); useChatStore.getState().setMessages(sid, buffer); + } else { + console.log( + `[replay] ${sid.slice(0, 8)} loading finished but buffer was ${buffer ? "empty" : "missing"}`, + ); } } } @@ -140,9 +169,17 @@ export function useAcpStream(enabled: boolean): void { unlisteners.push( listen("acp:replay_complete", (event) => { if (!active) return; - useChatStore - .getState() - .setSessionLoading(event.payload.sessionId, false); + const sid = event.payload.sessionId; + const counts = replayEventCounts.get(sid); + const bufferLen = getReplayBufferSize(sid); + console.log( + `[replay] ${sid.slice(0, 8)} replay_complete received — ` + + `${counts?.userMessages ?? 0} user msgs, ${counts?.assistantMessages ?? 0} assistant msgs, ` + + `${counts?.events ?? 0} total events, ${bufferLen} buffered messages, ` + + `${counts ? (performance.now() - counts.t0).toFixed(0) : "?"}ms elapsed`, + ); + replayEventCounts.delete(sid); + useChatStore.getState().setSessionLoading(sid, false); }), ); @@ -155,6 +192,11 @@ export function useAcpStream(enabled: boolean): void { if (store.loadingSessionIds.has(sessionId)) { if (!getBufferedMessage(sessionId, messageId)) { + const counts = replayEventCounts.get(sessionId); + if (counts) { + counts.assistantMessages++; + counts.events++; + } ensureReplayBuffer(sessionId).push({ id: messageId, role: "assistant", @@ -439,6 +481,11 @@ export function useAcpStream(enabled: boolean): void { (event) => { if (!active) return; const { sessionId, messageId, text } = event.payload; + const counts = replayEventCounts.get(sessionId); + if (counts) { + counts.userMessages++; + counts.events++; + } ensureReplayBuffer(sessionId).push({ id: messageId, role: "user", @@ -453,9 +500,7 @@ export function useAcpStream(enabled: boolean): void { unlisteners.push( listen("acp:session_bound", (event) => { if (!active) return; - console.log( - `[session] acp:session_bound ${event.payload.sessionId.slice(0, 8)} → goose=${event.payload.gooseSessionId.slice(0, 8)}`, - ); + useChatSessionStore .getState() .setSessionAcpId( diff --git a/src/features/chat/hooks/useChat.ts b/src/features/chat/hooks/useChat.ts index add28ea..224ad1d 100644 --- a/src/features/chat/hooks/useChat.ts +++ b/src/features/chat/hooks/useChat.ts @@ -204,16 +204,11 @@ export function useChat( try { if (wasDraft || selectedModelId) { - console.log( - `[session] acpPrepareSession ${sessionId.slice(0, 8)} (trigger=${wasDraft ? "draft-promotion" : "model-change"}, provider=${providerId}, model=${selectedModelId ?? "default"})`, - ); await acpPrepareSession(sessionId, providerId, { workingDir: workingDirOverride, personaId: effectivePersonaInfo?.id, }); - console.log( - `[session] acpPrepareSession ${sessionId.slice(0, 8)} completed — backend session created`, - ); + if (selectedModelId) { await acpSetModel(sessionId, selectedModelId); } @@ -248,13 +243,10 @@ export function useChat( } } catch (err) { if (err instanceof DOMException && err.name === "AbortError") { - console.log(`[session] sendMessage ${sessionId.slice(0, 8)} aborted`); store.setChatState(sessionId, "idle"); } else { const errorMessage = getErrorMessage(err); - console.log( - `[session] sendMessage ${sessionId.slice(0, 8)} failed (wasDraft=${wasDraft}): ${errorMessage}`, - ); + const liveStore = useChatStore.getState(); const { streamingMessageId } = liveStore.getSessionRuntime(sessionId); if (streamingMessageId) { diff --git a/src/features/chat/stores/chatSessionStore.ts b/src/features/chat/stores/chatSessionStore.ts index 91bf753..afc456e 100644 --- a/src/features/chat/stores/chatSessionStore.ts +++ b/src/features/chat/stores/chatSessionStore.ts @@ -324,9 +324,7 @@ export const useChatSessionStore = create((set, get) => ({ messageCount: 0, draft: true, }; - console.log( - `[session] createDraftSession ${chatSession.id.slice(0, 8)} project=${opts?.projectId?.slice(0, 8) ?? "none"} provider=${opts?.providerId ?? "none"}`, - ); + set((state) => ({ sessions: [...state.sessions, chatSession] })); persistDraftSessionRecord(draftSessionToRecord(chatSession)); return chatSession; @@ -335,7 +333,7 @@ export const useChatSessionStore = create((set, get) => ({ promoteDraft: (id) => { const session = get().sessions.find((candidate) => candidate.id === id); if (!session?.draft) return; - console.log(`[session] promoteDraft ${id.slice(0, 8)}`); + set((state) => ({ sessions: state.sessions.map((candidate) => candidate.id === id ? { ...candidate, draft: undefined } : candidate, @@ -369,10 +367,7 @@ export const useChatSessionStore = create((set, get) => ({ try { const overlays = loadSessionMetadataOverlay(); const acpSessions = await acpListSessions(); - const emptyCount = acpSessions.filter((s) => s.messageCount === 0).length; - console.log( - `[session] loadSessions: ${acpSessions.length} backend (${emptyCount} empty), ${overlays.size} overlays`, - ); + const persistedDrafts = loadDraftSessionRecords(); const currentDrafts = get().sessions.filter((session) => session.draft); const drafts = mergeDraftSessions(currentDrafts, persistedDrafts); @@ -512,9 +507,6 @@ export const useChatSessionStore = create((set, get) => ({ if (!acpSessionId) return; const session = get().sessions.find((candidate) => candidate.id === id); if (!session || session.acpSessionId === acpSessionId) return; - console.log( - `[session] setSessionAcpId ${id.slice(0, 8)} → goose=${acpSessionId.slice(0, 8)} draft=${!!session.draft} msgs=${session.messageCount}`, - ); set((state) => ({ sessions: state.sessions.map((candidate) => From c72b98d2b6c637769c84f872d04c05288654fe92 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 16:45:45 +1000 Subject: [PATCH 04/12] fix: drain pending replay notifications before counting events After load_session().await resolves, the ACP RPC layer may still have queued notification tasks (session/update with message chunks) that haven't been processed yet on the single-threaded runtime. This caused non-deterministic message loss when loading older sessions. Yield repeatedly after load_session returns, waiting for the replay event count to stabilize, before finalizing and emitting replay_complete. Co-Authored-By: Claude Opus 4.6 (1M context) --- scripts/check-file-sizes.mjs | 4 ++-- .../src/services/acp/manager/session_ops.rs | 22 +++++++++++++++++++ 2 files changed, 24 insertions(+), 2 deletions(-) diff --git a/scripts/check-file-sizes.mjs b/scripts/check-file-sizes.mjs index 01009b5..4f7ef48 100644 --- a/scripts/check-file-sizes.mjs +++ b/scripts/check-file-sizes.mjs @@ -61,9 +61,9 @@ const EXCEPTIONS = { "ACP manager command dispatch loop — export/import/fork session ext_method dispatch adds boilerplate.", }, "src-tauri/src/services/acp/manager/session_ops.rs": { - limit: 585, + limit: 605, justification: - "Session prepare/load/list logic, working-dir updates, replay diagnostics, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", + "Session prepare/load/list logic, working-dir updates, replay diagnostics, notification drain barrier, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", }, }; diff --git a/src-tauri/src/services/acp/manager/session_ops.rs b/src-tauri/src/services/acp/manager/session_ops.rs index b9d6dd8..8facc72 100644 --- a/src-tauri/src/services/acp/manager/session_ops.rs +++ b/src-tauri/src/services/acp/manager/session_ops.rs @@ -447,6 +447,28 @@ pub(super) async fn load_session_inner( .await .map_err(|error| format!("Failed to load Goose session: {error:?}"))?; + // The ACP RPC layer resolves responses synchronously but dispatches + // notifications asynchronously via spawned tasks. After load_session + // returns, replay notifications may still be queued. Yield repeatedly + // to let the single-threaded runtime drain them before counting. + { + let mut prev_total = 0u32; + let mut stable_rounds = 0u8; + loop { + tokio::task::yield_now().await; + let counts = dispatcher.get_replay_event_counts(goose_session_id).await; + if counts.total == prev_total { + stable_rounds += 1; + if stable_rounds >= 3 { + break; + } + } else { + stable_rounds = 0; + prev_total = counts.total; + } + } + } + // Finalize any in-progress replay assistant message dispatcher.finalize_replay(goose_session_id).await; From dd51a72a5355d18f95f6b0b0b5d10bd1884e35e1 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 16:52:20 +1000 Subject: [PATCH 05/12] test: add unit tests for replay buffer module Tests all 6 exported functions from replayBuffer.ts: - ensureReplayBuffer: creation, identity, session isolation - getBufferedMessage: lookup by id, missing cases - getReplayBufferSize: unknown session, accurate count - getAndDeleteReplayBuffer: returns and removes buffer - clearReplayBuffer: removes without returning - findLatestUnpairedToolRequest: edge cases for paired/unpaired tool requests Co-Authored-By: Claude Opus 4.6 (1M context) --- .../chat/hooks/__tests__/replayBuffer.test.ts | 177 ++++++++++++++++++ 1 file changed, 177 insertions(+) create mode 100644 src/features/chat/hooks/__tests__/replayBuffer.test.ts diff --git a/src/features/chat/hooks/__tests__/replayBuffer.test.ts b/src/features/chat/hooks/__tests__/replayBuffer.test.ts new file mode 100644 index 0000000..c2542b7 --- /dev/null +++ b/src/features/chat/hooks/__tests__/replayBuffer.test.ts @@ -0,0 +1,177 @@ +import { beforeEach, describe, expect, it } from "vitest"; +import type { + MessageContent, + ToolRequestContent, + ToolResponseContent, +} from "@/shared/types/messages"; +import { + clearReplayBuffer, + ensureReplayBuffer, + findLatestUnpairedToolRequest, + getAndDeleteReplayBuffer, + getBufferedMessage, + getReplayBufferSize, +} from "../replayBuffer"; + +function makeMessage(id: string, role: "user" | "assistant" = "assistant") { + return { + id, + role, + created: Date.now(), + content: [{ type: "text" as const, text: `content for ${id}` }], + metadata: { userVisible: true }, + }; +} + +describe("replayBuffer", () => { + const sessionId = "session-1"; + + beforeEach(() => { + // Clean up any leftover buffers + clearReplayBuffer(sessionId); + clearReplayBuffer("session-2"); + }); + + describe("ensureReplayBuffer", () => { + it("creates a new buffer for an unknown session", () => { + const buffer = ensureReplayBuffer(sessionId); + expect(buffer).toEqual([]); + }); + + it("returns the same buffer on repeated calls", () => { + const first = ensureReplayBuffer(sessionId); + first.push(makeMessage("msg-1")); + const second = ensureReplayBuffer(sessionId); + expect(second).toBe(first); + expect(second).toHaveLength(1); + }); + + it("returns independent buffers for different sessions", () => { + const buf1 = ensureReplayBuffer("session-1"); + const buf2 = ensureReplayBuffer("session-2"); + buf1.push(makeMessage("msg-1")); + expect(buf2).toHaveLength(0); + }); + }); + + describe("getBufferedMessage", () => { + it("finds a message by id", () => { + const buffer = ensureReplayBuffer(sessionId); + buffer.push(makeMessage("msg-1"), makeMessage("msg-2")); + expect(getBufferedMessage(sessionId, "msg-2")?.id).toBe("msg-2"); + }); + + it("returns undefined for a missing message", () => { + ensureReplayBuffer(sessionId); + expect(getBufferedMessage(sessionId, "nope")).toBeUndefined(); + }); + + it("returns undefined for an unknown session", () => { + expect(getBufferedMessage("no-session", "msg-1")).toBeUndefined(); + }); + }); + + describe("getReplayBufferSize", () => { + it("returns 0 for an unknown session", () => { + expect(getReplayBufferSize("no-session")).toBe(0); + }); + + it("returns the number of buffered messages", () => { + const buffer = ensureReplayBuffer(sessionId); + buffer.push(makeMessage("msg-1"), makeMessage("msg-2")); + expect(getReplayBufferSize(sessionId)).toBe(2); + }); + }); + + describe("getAndDeleteReplayBuffer", () => { + it("returns the buffer and removes it", () => { + const buffer = ensureReplayBuffer(sessionId); + buffer.push(makeMessage("msg-1")); + + const result = getAndDeleteReplayBuffer(sessionId); + expect(result).toHaveLength(1); + expect(result?.[0].id).toBe("msg-1"); + + // Buffer is gone + expect(getReplayBufferSize(sessionId)).toBe(0); + expect(getAndDeleteReplayBuffer(sessionId)).toBeUndefined(); + }); + + it("returns undefined for an unknown session", () => { + expect(getAndDeleteReplayBuffer("no-session")).toBeUndefined(); + }); + }); + + describe("clearReplayBuffer", () => { + it("removes the buffer without returning it", () => { + const buffer = ensureReplayBuffer(sessionId); + buffer.push(makeMessage("msg-1")); + + clearReplayBuffer(sessionId); + expect(getReplayBufferSize(sessionId)).toBe(0); + }); + + it("is a no-op for an unknown session", () => { + // Should not throw + clearReplayBuffer("no-session"); + }); + }); +}); + +describe("findLatestUnpairedToolRequest", () => { + function toolRequest(id: string): ToolRequestContent { + return { + type: "toolRequest", + id, + name: `tool-${id}`, + arguments: {}, + status: "executing", + }; + } + + function toolResponse(id: string): ToolResponseContent { + return { + type: "toolResponse", + id, + name: `tool-${id}`, + result: "done", + isError: false, + }; + } + + it("returns null for empty content", () => { + expect(findLatestUnpairedToolRequest([])).toBeNull(); + }); + + it("returns null when all requests have responses", () => { + const content: MessageContent[] = [ + toolRequest("t1"), + toolResponse("t1"), + toolRequest("t2"), + toolResponse("t2"), + ]; + expect(findLatestUnpairedToolRequest(content)).toBeNull(); + }); + + it("returns the unpaired request", () => { + const content: MessageContent[] = [ + toolRequest("t1"), + toolResponse("t1"), + toolRequest("t2"), + ]; + expect(findLatestUnpairedToolRequest(content)?.id).toBe("t2"); + }); + + it("returns the latest unpaired request when multiple are unpaired", () => { + const content: MessageContent[] = [toolRequest("t1"), toolRequest("t2")]; + expect(findLatestUnpairedToolRequest(content)?.id).toBe("t2"); + }); + + it("ignores non-toolRequest content blocks", () => { + const content: MessageContent[] = [ + { type: "text", text: "hello" }, + toolRequest("t1"), + ]; + expect(findLatestUnpairedToolRequest(content)?.id).toBe("t1"); + }); +}); From 047ab389ecc453108bcfa58a837581b88da174c6 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 16:54:37 +1000 Subject: [PATCH 06/12] Revert "test: add unit tests for replay buffer module" This reverts commit dd51a72a5355d18f95f6b0b0b5d10bd1884e35e1. --- .../chat/hooks/__tests__/replayBuffer.test.ts | 177 ------------------ 1 file changed, 177 deletions(-) delete mode 100644 src/features/chat/hooks/__tests__/replayBuffer.test.ts diff --git a/src/features/chat/hooks/__tests__/replayBuffer.test.ts b/src/features/chat/hooks/__tests__/replayBuffer.test.ts deleted file mode 100644 index c2542b7..0000000 --- a/src/features/chat/hooks/__tests__/replayBuffer.test.ts +++ /dev/null @@ -1,177 +0,0 @@ -import { beforeEach, describe, expect, it } from "vitest"; -import type { - MessageContent, - ToolRequestContent, - ToolResponseContent, -} from "@/shared/types/messages"; -import { - clearReplayBuffer, - ensureReplayBuffer, - findLatestUnpairedToolRequest, - getAndDeleteReplayBuffer, - getBufferedMessage, - getReplayBufferSize, -} from "../replayBuffer"; - -function makeMessage(id: string, role: "user" | "assistant" = "assistant") { - return { - id, - role, - created: Date.now(), - content: [{ type: "text" as const, text: `content for ${id}` }], - metadata: { userVisible: true }, - }; -} - -describe("replayBuffer", () => { - const sessionId = "session-1"; - - beforeEach(() => { - // Clean up any leftover buffers - clearReplayBuffer(sessionId); - clearReplayBuffer("session-2"); - }); - - describe("ensureReplayBuffer", () => { - it("creates a new buffer for an unknown session", () => { - const buffer = ensureReplayBuffer(sessionId); - expect(buffer).toEqual([]); - }); - - it("returns the same buffer on repeated calls", () => { - const first = ensureReplayBuffer(sessionId); - first.push(makeMessage("msg-1")); - const second = ensureReplayBuffer(sessionId); - expect(second).toBe(first); - expect(second).toHaveLength(1); - }); - - it("returns independent buffers for different sessions", () => { - const buf1 = ensureReplayBuffer("session-1"); - const buf2 = ensureReplayBuffer("session-2"); - buf1.push(makeMessage("msg-1")); - expect(buf2).toHaveLength(0); - }); - }); - - describe("getBufferedMessage", () => { - it("finds a message by id", () => { - const buffer = ensureReplayBuffer(sessionId); - buffer.push(makeMessage("msg-1"), makeMessage("msg-2")); - expect(getBufferedMessage(sessionId, "msg-2")?.id).toBe("msg-2"); - }); - - it("returns undefined for a missing message", () => { - ensureReplayBuffer(sessionId); - expect(getBufferedMessage(sessionId, "nope")).toBeUndefined(); - }); - - it("returns undefined for an unknown session", () => { - expect(getBufferedMessage("no-session", "msg-1")).toBeUndefined(); - }); - }); - - describe("getReplayBufferSize", () => { - it("returns 0 for an unknown session", () => { - expect(getReplayBufferSize("no-session")).toBe(0); - }); - - it("returns the number of buffered messages", () => { - const buffer = ensureReplayBuffer(sessionId); - buffer.push(makeMessage("msg-1"), makeMessage("msg-2")); - expect(getReplayBufferSize(sessionId)).toBe(2); - }); - }); - - describe("getAndDeleteReplayBuffer", () => { - it("returns the buffer and removes it", () => { - const buffer = ensureReplayBuffer(sessionId); - buffer.push(makeMessage("msg-1")); - - const result = getAndDeleteReplayBuffer(sessionId); - expect(result).toHaveLength(1); - expect(result?.[0].id).toBe("msg-1"); - - // Buffer is gone - expect(getReplayBufferSize(sessionId)).toBe(0); - expect(getAndDeleteReplayBuffer(sessionId)).toBeUndefined(); - }); - - it("returns undefined for an unknown session", () => { - expect(getAndDeleteReplayBuffer("no-session")).toBeUndefined(); - }); - }); - - describe("clearReplayBuffer", () => { - it("removes the buffer without returning it", () => { - const buffer = ensureReplayBuffer(sessionId); - buffer.push(makeMessage("msg-1")); - - clearReplayBuffer(sessionId); - expect(getReplayBufferSize(sessionId)).toBe(0); - }); - - it("is a no-op for an unknown session", () => { - // Should not throw - clearReplayBuffer("no-session"); - }); - }); -}); - -describe("findLatestUnpairedToolRequest", () => { - function toolRequest(id: string): ToolRequestContent { - return { - type: "toolRequest", - id, - name: `tool-${id}`, - arguments: {}, - status: "executing", - }; - } - - function toolResponse(id: string): ToolResponseContent { - return { - type: "toolResponse", - id, - name: `tool-${id}`, - result: "done", - isError: false, - }; - } - - it("returns null for empty content", () => { - expect(findLatestUnpairedToolRequest([])).toBeNull(); - }); - - it("returns null when all requests have responses", () => { - const content: MessageContent[] = [ - toolRequest("t1"), - toolResponse("t1"), - toolRequest("t2"), - toolResponse("t2"), - ]; - expect(findLatestUnpairedToolRequest(content)).toBeNull(); - }); - - it("returns the unpaired request", () => { - const content: MessageContent[] = [ - toolRequest("t1"), - toolResponse("t1"), - toolRequest("t2"), - ]; - expect(findLatestUnpairedToolRequest(content)?.id).toBe("t2"); - }); - - it("returns the latest unpaired request when multiple are unpaired", () => { - const content: MessageContent[] = [toolRequest("t1"), toolRequest("t2")]; - expect(findLatestUnpairedToolRequest(content)?.id).toBe("t2"); - }); - - it("ignores non-toolRequest content blocks", () => { - const content: MessageContent[] = [ - { type: "text", text: "hello" }, - toolRequest("t1"), - ]; - expect(findLatestUnpairedToolRequest(content)?.id).toBe("t1"); - }); -}); From f4c100d292f21cf3d3c55126daf03df6235a580c Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 16:59:00 +1000 Subject: [PATCH 07/12] test: add unit tests for replay drain stabilisation logic Extract the yield-and-wait-for-stability loop from load_session_inner into a generic wait_for_replay_drain() function that accepts an async counter callback, making it testable in isolation. Add 4 tests: - replay_drain_returns_immediately_when_count_is_zero - replay_drain_returns_stable_count (already-stable counter) - replay_drain_waits_for_spawned_notifications (tokio::spawn simulating async ACP notifications arriving over multiple yields) - replay_drain_resets_stability_on_late_arrival (counter bumps just before stability threshold, verifying the reset logic) The last two tests fail when the drain logic is replaced with a single poll (the pre-fix behavior), confirming the fix is necessary. Co-Authored-By: Claude Opus 4.6 (1M context) --- scripts/check-file-sizes.mjs | 4 +- .../src/services/acp/manager/session_ops.rs | 53 +++++++++---- .../services/acp/manager/session_ops/tests.rs | 77 ++++++++++++++++++- 3 files changed, 112 insertions(+), 22 deletions(-) diff --git a/scripts/check-file-sizes.mjs b/scripts/check-file-sizes.mjs index 4f7ef48..8f63d4d 100644 --- a/scripts/check-file-sizes.mjs +++ b/scripts/check-file-sizes.mjs @@ -61,9 +61,9 @@ const EXCEPTIONS = { "ACP manager command dispatch loop — export/import/fork session ext_method dispatch adds boilerplate.", }, "src-tauri/src/services/acp/manager/session_ops.rs": { - limit: 605, + limit: 625, justification: - "Session prepare/load/list logic, working-dir updates, replay diagnostics, notification drain barrier, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", + "Session prepare/load/list logic, working-dir updates, replay diagnostics, extracted wait_for_replay_drain helper, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", }, }; diff --git a/src-tauri/src/services/acp/manager/session_ops.rs b/src-tauri/src/services/acp/manager/session_ops.rs index 8facc72..03a650d 100644 --- a/src-tauri/src/services/acp/manager/session_ops.rs +++ b/src-tauri/src/services/acp/manager/session_ops.rs @@ -451,23 +451,13 @@ pub(super) async fn load_session_inner( // notifications asynchronously via spawned tasks. After load_session // returns, replay notifications may still be queued. Yield repeatedly // to let the single-threaded runtime drain them before counting. - { - let mut prev_total = 0u32; - let mut stable_rounds = 0u8; - loop { - tokio::task::yield_now().await; - let counts = dispatcher.get_replay_event_counts(goose_session_id).await; - if counts.total == prev_total { - stable_rounds += 1; - if stable_rounds >= 3 { - break; - } - } else { - stable_rounds = 0; - prev_total = counts.total; - } - } - } + wait_for_replay_drain(|| async { + dispatcher + .get_replay_event_counts(goose_session_id) + .await + .total + }) + .await; // Finalize any in-progress replay assistant message dispatcher.finalize_replay(goose_session_id).await; @@ -599,3 +589,32 @@ pub(super) async fn set_model_inner( Ok(()) } + +/// Yield repeatedly until an async counter stabilises for 3 consecutive rounds. +/// +/// After `load_session` returns, the ACP RPC layer may still have spawned +/// notification tasks that haven't run yet. This function yields to the +/// runtime between polls so those tasks get a chance to execute, and only +/// returns once the count has been stable for 3 consecutive yields — giving +/// us confidence that all replay events have been dispatched. +async fn wait_for_replay_drain(mut get_count: F) -> u32 +where + F: FnMut() -> Fut, + Fut: std::future::Future, +{ + let mut prev_total = 0u32; + let mut stable_rounds = 0u8; + loop { + tokio::task::yield_now().await; + let total = get_count().await; + if total == prev_total { + stable_rounds += 1; + if stable_rounds >= 3 { + return total; + } + } else { + stable_rounds = 0; + prev_total = total; + } + } +} diff --git a/src-tauri/src/services/acp/manager/session_ops/tests.rs b/src-tauri/src/services/acp/manager/session_ops/tests.rs index 4f5e51e..3758390 100644 --- a/src-tauri/src/services/acp/manager/session_ops/tests.rs +++ b/src-tauri/src/services/acp/manager/session_ops/tests.rs @@ -1,10 +1,11 @@ use std::collections::{HashMap, HashSet}; - use std::path::PathBuf; +use std::sync::atomic::{AtomicU32, Ordering}; +use std::sync::Arc; use super::{ - needs_provider_update, prepared_session_for_key, register_prepared_session_keys, ManagerState, - PreparedSession, + needs_provider_update, prepared_session_for_key, register_prepared_session_keys, + wait_for_replay_drain, ManagerState, PreparedSession, }; use crate::services::acp::split_composite_key; @@ -81,3 +82,73 @@ fn register_prepared_session_keys_preserves_composite_and_local_entries() { "goose-1" ); } + +#[tokio::test] +async fn replay_drain_returns_immediately_when_count_is_zero() { + let final_count = wait_for_replay_drain(|| async { 0u32 }).await; + assert_eq!(final_count, 0); +} + +#[tokio::test] +async fn replay_drain_returns_stable_count() { + let counter = Arc::new(AtomicU32::new(42)); + let c = counter.clone(); + let final_count = wait_for_replay_drain(|| { + let c = c.clone(); + async move { c.load(Ordering::SeqCst) } + }) + .await; + assert_eq!(final_count, 42); +} + +#[tokio::test] +async fn replay_drain_waits_for_spawned_notifications() { + let counter = Arc::new(AtomicU32::new(0)); + let c = counter.clone(); + + // Simulate async notifications arriving over multiple yields, like + // the real ACP RPC layer does after load_session returns. + tokio::spawn(async move { + for i in 1..=5 { + tokio::task::yield_now().await; + c.store(i, Ordering::SeqCst); + } + }); + + let c2 = counter.clone(); + let final_count = wait_for_replay_drain(|| { + let c = c2.clone(); + async move { c.load(Ordering::SeqCst) } + }) + .await; + + assert_eq!(final_count, 5); +} + +#[tokio::test] +async fn replay_drain_resets_stability_on_late_arrival() { + // Simulate: counter jumps to 3, stabilises for 2 rounds, then a late + // notification bumps it to 4. The drain must NOT stop at 3. + let poll_count = Arc::new(AtomicU32::new(0)); + + let pc = poll_count.clone(); + let final_count = wait_for_replay_drain(|| { + let pc = pc.clone(); + async move { + let poll = pc.fetch_add(1, Ordering::SeqCst); + // Polls 0..2 return 3 (2 stable rounds), then poll 3 bumps + // to 4 — simulating a late notification just before the drain + // would have declared stability. The drain must reset and + // wait for 4 to stabilise. + if poll < 3 { + 3 + } else { + 4 + } + } + }) + .await; + + // Must see the late arrival, not stop at 3 + assert_eq!(final_count, 4); +} From 5fdab4e1300f5bdc688743a8b62c755e74519b91 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 17:06:00 +1000 Subject: [PATCH 08/12] chore: remove debug logging and revert justfile config change Remove [session] and [replay] info-level console.log/log::info statements added during empty-chats investigation. Revert the dotenv-load justfile addition. Simplify dispatcher replay counting to a single total (only field the drain fix actually reads). Co-Authored-By: Claude Opus 4.6 (1M context) --- justfile | 2 - scripts/check-file-sizes.mjs | 16 ++--- .../src/services/acp/manager/dispatcher.rs | 30 ++-------- .../src/services/acp/manager/session_ops.rs | 21 +------ src/app/AppShell.tsx | 16 +---- src/features/chat/hooks/replayBuffer.ts | 4 -- src/features/chat/hooks/useAcpStream.ts | 60 ++----------------- src/features/chat/hooks/useChat.ts | 2 - src/features/chat/stores/chatSessionStore.ts | 3 - 9 files changed, 19 insertions(+), 135 deletions(-) diff --git a/justfile b/justfile index 4600e06..86ce081 100644 --- a/justfile +++ b/justfile @@ -1,5 +1,3 @@ -set dotenv-load - # Default recipe default: @just --list diff --git a/scripts/check-file-sizes.mjs b/scripts/check-file-sizes.mjs index 8f63d4d..3d1c415 100644 --- a/scripts/check-file-sizes.mjs +++ b/scripts/check-file-sizes.mjs @@ -31,9 +31,9 @@ const EXCEPTIONS = { "Shell still coordinates ACP session loading, project reassignment, and app-level chat routing.", }, "src/features/chat/hooks/useAcpStream.ts": { - limit: 600, + limit: 580, justification: - "ACP replay, streaming, session binding, model-state event handling, replay timeout, and replay diagnostics are still centralized here.", + "ACP replay, streaming, session binding, model-state event handling, and replay timeout are still centralized here.", }, "src/features/chat/hooks/__tests__/useAcpStream.test.ts": { limit: 570, @@ -46,14 +46,14 @@ const EXCEPTIONS = { "ACP session overlay regressions currently need one broad integration-style store suite.", }, "src/features/chat/stores/chatSessionStore.ts": { - limit: 650, + limit: 640, justification: - "ACP-backed session overlay persistence, draft migration, sidebar-facing session merge logic, and session lifecycle logging live together for now.", + "ACP-backed session overlay persistence, draft migration, and sidebar-facing session merge logic live together for now.", }, "src-tauri/src/services/acp/manager/dispatcher.rs": { - limit: 570, + limit: 545, justification: - "ACP replay and live-stream event fan-out share one dispatcher with replay event counting until session event routing is split.", + "ACP replay and live-stream event fan-out share one dispatcher with replay event counting for drain stabilisation.", }, "src-tauri/src/services/acp/manager.rs": { limit: 630, @@ -61,9 +61,9 @@ const EXCEPTIONS = { "ACP manager command dispatch loop — export/import/fork session ext_method dispatch adds boilerplate.", }, "src-tauri/src/services/acp/manager/session_ops.rs": { - limit: 625, + limit: 605, justification: - "Session prepare/load/list logic, working-dir updates, replay diagnostics, extracted wait_for_replay_drain helper, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", + "Session prepare/load/list logic, working-dir updates, wait_for_replay_drain helper, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", }, }; diff --git a/src-tauri/src/services/acp/manager/dispatcher.rs b/src-tauri/src/services/acp/manager/dispatcher.rs index b0a3222..64c3e55 100644 --- a/src-tauri/src/services/acp/manager/dispatcher.rs +++ b/src-tauri/src/services/acp/manager/dispatcher.rs @@ -58,17 +58,9 @@ pub(super) struct SessionRoute { pub(super) writer: Option>, pub(super) canceled: bool, pub(super) replay_message_id: Option, - pub(super) replay_user_messages: u32, - pub(super) replay_assistant_messages: u32, pub(super) replay_events: u32, } -pub(super) struct ReplayEventCounts { - pub(super) user_messages: u32, - pub(super) assistant_messages: u32, - pub(super) total: u32, -} - pub(super) struct SessionEventDispatcher { app_handle: tauri::AppHandle, routes: Arc>>, @@ -103,8 +95,6 @@ impl SessionEventDispatcher { writer: None, canceled: false, replay_message_id: None, - replay_user_messages: 0, - replay_assistant_messages: 0, replay_events: 0, }); @@ -133,8 +123,6 @@ impl SessionEventDispatcher { writer: Some(writer), canceled: false, replay_message_id: None, - replay_user_messages: 0, - replay_assistant_messages: 0, replay_events: 0, }, ); @@ -270,23 +258,15 @@ impl SessionEventDispatcher { ); } - pub(super) async fn get_replay_event_counts( + pub(super) async fn get_replay_event_count( &self, goose_session_id: &str, - ) -> ReplayEventCounts { + ) -> u32 { let routes = self.routes.lock().await; routes .get(goose_session_id) - .map(|r| ReplayEventCounts { - user_messages: r.replay_user_messages, - assistant_messages: r.replay_assistant_messages, - total: r.replay_events, - }) - .unwrap_or(ReplayEventCounts { - user_messages: 0, - assistant_messages: 0, - total: 0, - }) + .map(|r| r.replay_events) + .unwrap_or(0) } } @@ -436,7 +416,6 @@ impl Client for SessionEventDispatcher { { let mut routes = self.routes.lock().await; if let Some(route) = routes.get_mut(&goose_session_id) { - route.replay_user_messages += 1; route.replay_events += 1; } } @@ -477,7 +456,6 @@ impl Client for SessionEventDispatcher { let mut routes = self.routes.lock().await; if let Some(route) = routes.get_mut(&goose_session_id) { route.replay_message_id = Some(new_id.clone()); - route.replay_assistant_messages += 1; route.replay_events += 1; } new_id diff --git a/src-tauri/src/services/acp/manager/session_ops.rs b/src-tauri/src/services/acp/manager/session_ops.rs index 03a650d..2c1b731 100644 --- a/src-tauri/src/services/acp/manager/session_ops.rs +++ b/src-tauri/src/services/acp/manager/session_ops.rs @@ -427,18 +427,10 @@ pub(super) async fn load_session_inner( goose_session_id: &str, working_dir: PathBuf, ) -> Result<(), String> { - log::info!( - "[replay] {} loading goose session {} from {:?}", - &local_session_id[..8.min(local_session_id.len())], - &goose_session_id[..8.min(goose_session_id.len())], - working_dir, - ); - dispatcher .bind_session(goose_session_id, local_session_id, None) .await; - let t0 = std::time::Instant::now(); let response = connection .load_session(LoadSessionRequest::new( goose_session_id.to_string(), @@ -453,25 +445,14 @@ pub(super) async fn load_session_inner( // to let the single-threaded runtime drain them before counting. wait_for_replay_drain(|| async { dispatcher - .get_replay_event_counts(goose_session_id) + .get_replay_event_count(goose_session_id) .await - .total }) .await; // Finalize any in-progress replay assistant message dispatcher.finalize_replay(goose_session_id).await; - let replay_counts = dispatcher.get_replay_event_counts(goose_session_id).await; - log::info!( - "[replay] {} load_session completed in {:?} — emitted {} events ({} user, {} assistant), sending replay_complete", - &local_session_id[..8.min(local_session_id.len())], - t0.elapsed(), - replay_counts.total, - replay_counts.user_messages, - replay_counts.assistant_messages, - ); - dispatcher.emit_replay_complete(local_session_id); if let Some(models) = &response.models { diff --git a/src/app/AppShell.tsx b/src/app/AppShell.tsx index 72178c5..bcf941d 100644 --- a/src/app/AppShell.tsx +++ b/src/app/AppShell.tsx @@ -67,23 +67,15 @@ export function AppShell({ children }: { children?: React.ReactNode }) { const loadSessionMessages = useCallback(async (sessionId: string) => { const existing = useChatStore.getState().messagesBySession[sessionId]; if (existing && existing.length > 0) { - console.log( - `[replay] ${sessionId.slice(0, 8)} skip — already has ${existing.length} messages in store`, - ); return; } - const t0 = performance.now(); const store = useChatStore.getState(); store.setSessionLoading(sessionId, true); try { const { acpLoadSession } = await import("@/shared/api/acp"); const session = useChatSessionStore.getState().getSession(sessionId); const gooseSessionId = session?.acpSessionId ?? sessionId; - const messageCount = session?.messageCount ?? "unknown"; - console.log( - `[replay] ${sessionId.slice(0, 8)} loading — goose=${gooseSessionId.slice(0, 8)} messageCount=${messageCount}`, - ); const project = session?.projectId ? (useProjectStore .getState() @@ -96,14 +88,8 @@ export function AppShell({ children }: { children?: React.ReactNode }) { ? resolveEffectiveWorkingDir(null, await getHomeDir()) : undefined); await acpLoadSession(sessionId, gooseSessionId, workingDir); - console.log( - `[replay] ${sessionId.slice(0, 8)} acpLoadSession resolved in ${(performance.now() - t0).toFixed(0)}ms — waiting for replay events`, - ); } catch (err) { - console.error( - `[replay] ${sessionId.slice(0, 8)} acpLoadSession failed:`, - err, - ); + console.error("Failed to load session messages:", err); useChatStore.getState().setSessionLoading(sessionId, false); } }, []); diff --git a/src/features/chat/hooks/replayBuffer.ts b/src/features/chat/hooks/replayBuffer.ts index e080b25..d9af08a 100644 --- a/src/features/chat/hooks/replayBuffer.ts +++ b/src/features/chat/hooks/replayBuffer.ts @@ -35,10 +35,6 @@ export function getBufferedMessage( return replayBuffers.get(sessionId)?.find((m) => m.id === messageId); } -export function getReplayBufferSize(sessionId: string): number { - return replayBuffers.get(sessionId)?.length ?? 0; -} - export function getAndDeleteReplayBuffer( sessionId: string, ): Message[] | undefined { diff --git a/src/features/chat/hooks/useAcpStream.ts b/src/features/chat/hooks/useAcpStream.ts index 6846d44..bd412c6 100644 --- a/src/features/chat/hooks/useAcpStream.ts +++ b/src/features/chat/hooks/useAcpStream.ts @@ -13,7 +13,6 @@ import { ensureReplayBuffer, getBufferedMessage, getAndDeleteReplayBuffer, - getReplayBufferSize, findLatestUnpairedToolRequest, } from "./replayBuffer"; import type { @@ -94,40 +93,20 @@ export function useAcpStream(enabled: boolean): void { const replayTimeouts = new Map>(); const REPLAY_TIMEOUT_MS = 30_000; - const replayEventCounts = new Map< - string, - { - userMessages: number; - assistantMessages: number; - events: number; - t0: number; - } - >(); const unsubscribeFlush = useChatStore.subscribe((state, prevState) => { if (!active) return; - // Start timeout and event counter for newly-loading sessions + // Start timeout for newly-loading sessions for (const sid of state.loadingSessionIds) { if (!prevState.loadingSessionIds.has(sid) && !replayTimeouts.has(sid)) { - replayEventCounts.set(sid, { - userMessages: 0, - assistantMessages: 0, - events: 0, - t0: performance.now(), - }); const timer = setTimeout(() => { replayTimeouts.delete(sid); const store = useChatStore.getState(); if (store.loadingSessionIds.has(sid)) { - const counts = replayEventCounts.get(sid); - const bufferLen = getReplayBufferSize(sid); console.warn( - `[replay] ${sid.slice(0, 8)} TIMEOUT after ${REPLAY_TIMEOUT_MS / 1000}s — ` + - `received ${counts?.events ?? 0} events (${counts?.userMessages ?? 0} user, ` + - `${counts?.assistantMessages ?? 0} assistant), ${bufferLen} buffered — replay_complete never arrived`, + `[stream] ${sid.slice(0, 8)} replay_complete not received within ${REPLAY_TIMEOUT_MS / 1000}s — showing error`, ); - replayEventCounts.delete(sid); store.setSessionLoading(sid, false); store.setError( sid, @@ -149,18 +128,7 @@ export function useAcpStream(enabled: boolean): void { } const buffer = getAndDeleteReplayBuffer(sid); if (buffer && buffer.length > 0) { - const userCount = buffer.filter((m) => m.role === "user").length; - const assistantCount = buffer.filter( - (m) => m.role === "assistant", - ).length; - console.log( - `[replay] ${sid.slice(0, 8)} flushing buffer → ${buffer.length} messages (${userCount} user, ${assistantCount} assistant) into store`, - ); useChatStore.getState().setMessages(sid, buffer); - } else { - console.log( - `[replay] ${sid.slice(0, 8)} loading finished but buffer was ${buffer ? "empty" : "missing"}`, - ); } } } @@ -169,17 +137,9 @@ export function useAcpStream(enabled: boolean): void { unlisteners.push( listen("acp:replay_complete", (event) => { if (!active) return; - const sid = event.payload.sessionId; - const counts = replayEventCounts.get(sid); - const bufferLen = getReplayBufferSize(sid); - console.log( - `[replay] ${sid.slice(0, 8)} replay_complete received — ` + - `${counts?.userMessages ?? 0} user msgs, ${counts?.assistantMessages ?? 0} assistant msgs, ` + - `${counts?.events ?? 0} total events, ${bufferLen} buffered messages, ` + - `${counts ? (performance.now() - counts.t0).toFixed(0) : "?"}ms elapsed`, - ); - replayEventCounts.delete(sid); - useChatStore.getState().setSessionLoading(sid, false); + useChatStore + .getState() + .setSessionLoading(event.payload.sessionId, false); }), ); @@ -192,11 +152,6 @@ export function useAcpStream(enabled: boolean): void { if (store.loadingSessionIds.has(sessionId)) { if (!getBufferedMessage(sessionId, messageId)) { - const counts = replayEventCounts.get(sessionId); - if (counts) { - counts.assistantMessages++; - counts.events++; - } ensureReplayBuffer(sessionId).push({ id: messageId, role: "assistant", @@ -481,11 +436,6 @@ export function useAcpStream(enabled: boolean): void { (event) => { if (!active) return; const { sessionId, messageId, text } = event.payload; - const counts = replayEventCounts.get(sessionId); - if (counts) { - counts.userMessages++; - counts.events++; - } ensureReplayBuffer(sessionId).push({ id: messageId, role: "user", diff --git a/src/features/chat/hooks/useChat.ts b/src/features/chat/hooks/useChat.ts index 224ad1d..73ee794 100644 --- a/src/features/chat/hooks/useChat.ts +++ b/src/features/chat/hooks/useChat.ts @@ -208,7 +208,6 @@ export function useChat( workingDir: workingDirOverride, personaId: effectivePersonaInfo?.id, }); - if (selectedModelId) { await acpSetModel(sessionId, selectedModelId); } @@ -246,7 +245,6 @@ export function useChat( store.setChatState(sessionId, "idle"); } else { const errorMessage = getErrorMessage(err); - const liveStore = useChatStore.getState(); const { streamingMessageId } = liveStore.getSessionRuntime(sessionId); if (streamingMessageId) { diff --git a/src/features/chat/stores/chatSessionStore.ts b/src/features/chat/stores/chatSessionStore.ts index afc456e..8915037 100644 --- a/src/features/chat/stores/chatSessionStore.ts +++ b/src/features/chat/stores/chatSessionStore.ts @@ -324,7 +324,6 @@ export const useChatSessionStore = create((set, get) => ({ messageCount: 0, draft: true, }; - set((state) => ({ sessions: [...state.sessions, chatSession] })); persistDraftSessionRecord(draftSessionToRecord(chatSession)); return chatSession; @@ -333,7 +332,6 @@ export const useChatSessionStore = create((set, get) => ({ promoteDraft: (id) => { const session = get().sessions.find((candidate) => candidate.id === id); if (!session?.draft) return; - set((state) => ({ sessions: state.sessions.map((candidate) => candidate.id === id ? { ...candidate, draft: undefined } : candidate, @@ -367,7 +365,6 @@ export const useChatSessionStore = create((set, get) => ({ try { const overlays = loadSessionMetadataOverlay(); const acpSessions = await acpListSessions(); - const persistedDrafts = loadDraftSessionRecords(); const currentDrafts = get().sessions.filter((session) => session.draft); const drafts = mergeDraftSessions(currentDrafts, persistedDrafts); From 9da3fedbd27a0a58b7ec7d166e4f672c5086823b Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 17:10:24 +1000 Subject: [PATCH 09/12] fix: cap replay drain iterations and strengthen stability test assertion Add a MAX_DRAIN_ITERATIONS (100) safety cap to wait_for_replay_drain so a runaway counter cannot spin-yield forever and freeze the UI. Log a warning when the cap is hit, returning the partial count. Strengthen the late-arrival test to assert poll_count >= 7, confirming the stability window truly resets rather than coincidentally seeing the bumped value. Add a new test for the iteration cap behavior. Co-Authored-By: Claude Opus 4.6 (1M context) --- scripts/check-file-sizes.mjs | 4 +-- .../src/services/acp/manager/session_ops.rs | 14 +++++++++++ .../services/acp/manager/session_ops/tests.rs | 25 ++++++++++++++++++- 3 files changed, 40 insertions(+), 3 deletions(-) diff --git a/scripts/check-file-sizes.mjs b/scripts/check-file-sizes.mjs index 3d1c415..c47a570 100644 --- a/scripts/check-file-sizes.mjs +++ b/scripts/check-file-sizes.mjs @@ -61,9 +61,9 @@ const EXCEPTIONS = { "ACP manager command dispatch loop — export/import/fork session ext_method dispatch adds boilerplate.", }, "src-tauri/src/services/acp/manager/session_ops.rs": { - limit: 605, + limit: 620, justification: - "Session prepare/load/list logic, working-dir updates, wait_for_replay_drain helper, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", + "Session prepare/load/list logic, working-dir updates, wait_for_replay_drain helper with iteration cap, and composite prepared-session reuse remain colocated while ACP session ownership stabilizes.", }, }; diff --git a/src-tauri/src/services/acp/manager/session_ops.rs b/src-tauri/src/services/acp/manager/session_ops.rs index 2c1b731..aa3f38f 100644 --- a/src-tauri/src/services/acp/manager/session_ops.rs +++ b/src-tauri/src/services/acp/manager/session_ops.rs @@ -578,6 +578,11 @@ pub(super) async fn set_model_inner( /// runtime between polls so those tasks get a chance to execute, and only /// returns once the count has been stable for 3 consecutive yields — giving /// us confidence that all replay events have been dispatched. +/// +/// A safety cap of 100 iterations prevents infinite spinning if a bug causes +/// the counter to increment indefinitely. +const MAX_DRAIN_ITERATIONS: u32 = 100; + async fn wait_for_replay_drain(mut get_count: F) -> u32 where F: FnMut() -> Fut, @@ -585,9 +590,11 @@ where { let mut prev_total = 0u32; let mut stable_rounds = 0u8; + let mut iterations = 0u32; loop { tokio::task::yield_now().await; let total = get_count().await; + iterations += 1; if total == prev_total { stable_rounds += 1; if stable_rounds >= 3 { @@ -597,5 +604,12 @@ where stable_rounds = 0; prev_total = total; } + if iterations >= MAX_DRAIN_ITERATIONS { + log::warn!( + "wait_for_replay_drain hit iteration cap ({MAX_DRAIN_ITERATIONS}); \ + returning partial count {total}" + ); + return total; + } } } diff --git a/src-tauri/src/services/acp/manager/session_ops/tests.rs b/src-tauri/src/services/acp/manager/session_ops/tests.rs index 3758390..10e9885 100644 --- a/src-tauri/src/services/acp/manager/session_ops/tests.rs +++ b/src-tauri/src/services/acp/manager/session_ops/tests.rs @@ -5,7 +5,7 @@ use std::sync::Arc; use super::{ needs_provider_update, prepared_session_for_key, register_prepared_session_keys, - wait_for_replay_drain, ManagerState, PreparedSession, + wait_for_replay_drain, ManagerState, PreparedSession, MAX_DRAIN_ITERATIONS, }; use crate::services::acp::split_composite_key; @@ -151,4 +151,27 @@ async fn replay_drain_resets_stability_on_late_arrival() { // Must see the late arrival, not stop at 3 assert_eq!(final_count, 4); + // Verify the stability window truly reset: 3 polls to see 3, 1 poll + // to see the bump to 4, then 3 more polls for 4 to stabilise = 7 min. + assert!( + poll_count.load(Ordering::SeqCst) >= 7, + "expected at least 7 polls to confirm stability window reset, got {}", + poll_count.load(Ordering::SeqCst) + ); +} + +#[tokio::test] +async fn replay_drain_caps_iterations_on_runaway_counter() { + // Simulate a counter that never stabilises — increments every poll. + let poll_count = Arc::new(AtomicU32::new(0)); + let pc = poll_count.clone(); + let final_count = wait_for_replay_drain(|| { + let pc = pc.clone(); + async move { pc.fetch_add(1, Ordering::SeqCst) + 1 } + }) + .await; + + // Should have stopped at the cap rather than spinning forever. + assert_eq!(final_count, MAX_DRAIN_ITERATIONS); + assert_eq!(poll_count.load(Ordering::SeqCst), MAX_DRAIN_ITERATIONS); } From 51b09a3cc5b8b95c31a231075f7682773849eb46 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 17:17:04 +1000 Subject: [PATCH 10/12] refactor: combine duplicate lock acquisitions in replay user message path MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Merge the two consecutive routes lock acquisitions in the UserMessageChunk replay handler into a single lock scope. The first lock finalized any in-progress assistant message, and the second incremented replay_events — both on the same route entry. Combining them reduces contention and simplifies the code. Tighten the file size limit for dispatcher.rs accordingly (545 → 540). --- scripts/check-file-sizes.mjs | 2 +- src-tauri/src/services/acp/manager/dispatcher.rs | 9 ++------- 2 files changed, 3 insertions(+), 8 deletions(-) diff --git a/scripts/check-file-sizes.mjs b/scripts/check-file-sizes.mjs index c47a570..1a980ce 100644 --- a/scripts/check-file-sizes.mjs +++ b/scripts/check-file-sizes.mjs @@ -51,7 +51,7 @@ const EXCEPTIONS = { "ACP-backed session overlay persistence, draft migration, and sidebar-facing session merge logic live together for now.", }, "src-tauri/src/services/acp/manager/dispatcher.rs": { - limit: 545, + limit: 540, justification: "ACP replay and live-stream event fan-out share one dispatcher with replay event counting for drain stabilisation.", }, diff --git a/src-tauri/src/services/acp/manager/dispatcher.rs b/src-tauri/src/services/acp/manager/dispatcher.rs index 64c3e55..55046d6 100644 --- a/src-tauri/src/services/acp/manager/dispatcher.rs +++ b/src-tauri/src/services/acp/manager/dispatcher.rs @@ -395,7 +395,7 @@ impl Client for SessionEventDispatcher { match ¬ification.update { SessionUpdate::UserMessageChunk(chunk) => { if let AcpContentBlock::Text(text) = &chunk.content { - // Finalize any in-progress assistant message first + // Finalize any in-progress assistant message and count replay event { let mut routes = self.routes.lock().await; if let Some(route) = routes.get_mut(&goose_session_id) { @@ -408,17 +408,12 @@ impl Client for SessionEventDispatcher { }, ); } + route.replay_events += 1; } } let display_text = extract_user_message(&text.text); let message_id = uuid::Uuid::new_v4().to_string(); - { - let mut routes = self.routes.lock().await; - if let Some(route) = routes.get_mut(&goose_session_id) { - route.replay_events += 1; - } - } let _ = self.app_handle.emit( "acp:replay_user_message", serde_json::json!({ From ed559e808f552df418a3c6b0b7e417d8f1adc7a6 Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 17:18:12 +1000 Subject: [PATCH 11/12] style: apply cargo fmt to dispatcher and session_ops Co-Authored-By: Claude Opus 4.6 (1M context) --- src-tauri/src/services/acp/manager/dispatcher.rs | 5 +---- src-tauri/src/services/acp/manager/session_ops.rs | 8 ++------ 2 files changed, 3 insertions(+), 10 deletions(-) diff --git a/src-tauri/src/services/acp/manager/dispatcher.rs b/src-tauri/src/services/acp/manager/dispatcher.rs index 55046d6..047638a 100644 --- a/src-tauri/src/services/acp/manager/dispatcher.rs +++ b/src-tauri/src/services/acp/manager/dispatcher.rs @@ -258,10 +258,7 @@ impl SessionEventDispatcher { ); } - pub(super) async fn get_replay_event_count( - &self, - goose_session_id: &str, - ) -> u32 { + pub(super) async fn get_replay_event_count(&self, goose_session_id: &str) -> u32 { let routes = self.routes.lock().await; routes .get(goose_session_id) diff --git a/src-tauri/src/services/acp/manager/session_ops.rs b/src-tauri/src/services/acp/manager/session_ops.rs index aa3f38f..cb00a7f 100644 --- a/src-tauri/src/services/acp/manager/session_ops.rs +++ b/src-tauri/src/services/acp/manager/session_ops.rs @@ -443,12 +443,8 @@ pub(super) async fn load_session_inner( // notifications asynchronously via spawned tasks. After load_session // returns, replay notifications may still be queued. Yield repeatedly // to let the single-threaded runtime drain them before counting. - wait_for_replay_drain(|| async { - dispatcher - .get_replay_event_count(goose_session_id) - .await - }) - .await; + wait_for_replay_drain(|| async { dispatcher.get_replay_event_count(goose_session_id).await }) + .await; // Finalize any in-progress replay assistant message dispatcher.finalize_replay(goose_session_id).await; From 933f4cdfcdcfe23540066992f302442eff50fd1d Mon Sep 17 00:00:00 2001 From: Matt Toohey Date: Mon, 13 Apr 2026 17:22:46 +1000 Subject: [PATCH 12/12] fix: restore non-branch perf and error logs removed during cleanup The debug logging cleanup commit (5fdab4e) accidentally removed [perf:load] and [perf:stream] console.log instrumentation by Bradley Axen and a "Failed to prepare ACP session" console.error by Taylor Ho. These were pre-existing logs, not debug logs added during investigation. Co-Authored-By: Claude Opus 4.6 (1M context) --- src/app/AppShell.tsx | 14 ++++++++++++++ src/features/chat/hooks/useAcpStream.ts | 12 ++++++++++++ src/features/chat/ui/ChatView.tsx | 4 +++- 3 files changed, 29 insertions(+), 1 deletion(-) diff --git a/src/app/AppShell.tsx b/src/app/AppShell.tsx index bcf941d..f701b04 100644 --- a/src/app/AppShell.tsx +++ b/src/app/AppShell.tsx @@ -67,13 +67,23 @@ export function AppShell({ children }: { children?: React.ReactNode }) { const loadSessionMessages = useCallback(async (sessionId: string) => { const existing = useChatStore.getState().messagesBySession[sessionId]; if (existing && existing.length > 0) { + console.log( + `[perf:load] ${sessionId.slice(0, 8)} skip — already has messages`, + ); return; } + const t0 = performance.now(); + console.log(`[perf:load] ${sessionId.slice(0, 8)} start`); const store = useChatStore.getState(); store.setSessionLoading(sessionId, true); try { + const t1 = performance.now(); const { acpLoadSession } = await import("@/shared/api/acp"); + const t2 = performance.now(); + console.log( + `[perf:load] ${sessionId.slice(0, 8)} import took ${(t2 - t1).toFixed(1)}ms`, + ); const session = useChatSessionStore.getState().getSession(sessionId); const gooseSessionId = session?.acpSessionId ?? sessionId; const project = session?.projectId @@ -88,6 +98,10 @@ export function AppShell({ children }: { children?: React.ReactNode }) { ? resolveEffectiveWorkingDir(null, await getHomeDir()) : undefined); await acpLoadSession(sessionId, gooseSessionId, workingDir); + const t3 = performance.now(); + console.log( + `[perf:load] ${sessionId.slice(0, 8)} acpLoadSession resolved in ${(t3 - t2).toFixed(1)}ms (total ${(t3 - t0).toFixed(1)}ms)`, + ); } catch (err) { console.error("Failed to load session messages:", err); useChatStore.getState().setSessionLoading(sessionId, false); diff --git a/src/features/chat/hooks/useAcpStream.ts b/src/features/chat/hooks/useAcpStream.ts index bd412c6..c70ee68 100644 --- a/src/features/chat/hooks/useAcpStream.ts +++ b/src/features/chat/hooks/useAcpStream.ts @@ -146,6 +146,9 @@ export function useAcpStream(enabled: boolean): void { unlisteners.push( listen("acp:message_created", (event) => { if (!active) return; + console.log( + `[perf:stream] ${event.payload.sessionId.slice(0, 8)} message_created mid=${event.payload.messageId.slice(0, 8)} at ${performance.now().toFixed(1)}ms`, + ); const store = useChatStore.getState(); const { sessionId, messageId, personaId, personaName } = event.payload; const providerId = getAssistantProviderId(sessionId); @@ -213,6 +216,9 @@ export function useAcpStream(enabled: boolean): void { unlisteners.push( listen("acp:text", (event) => { if (!active) return; + console.log( + `[perf:stream] ${event.payload.sessionId.slice(0, 8)} text mid=${event.payload.messageId.slice(0, 8)} len=${event.payload.text.length} at ${performance.now().toFixed(1)}ms`, + ); const store = useChatStore.getState(); const { sessionId, messageId, text } = event.payload; @@ -240,6 +246,9 @@ export function useAcpStream(enabled: boolean): void { unlisteners.push( listen("acp:done", (event) => { if (!active) return; + console.log( + `[perf:stream] ${event.payload.sessionId.slice(0, 8)} done mid=${event.payload.messageId.slice(0, 8)} at ${performance.now().toFixed(1)}ms`, + ); const store = useChatStore.getState(); const { sessionId, messageId } = event.payload; const isLoading = store.loadingSessionIds.has(sessionId); @@ -435,6 +444,9 @@ export function useAcpStream(enabled: boolean): void { "acp:replay_user_message", (event) => { if (!active) return; + console.log( + `[perf:stream] ${event.payload.sessionId.slice(0, 8)} replay_user_message at ${performance.now().toFixed(1)}ms`, + ); const { sessionId, messageId, text } = event.payload; ensureReplayBuffer(sessionId).push({ id: messageId, diff --git a/src/features/chat/ui/ChatView.tsx b/src/features/chat/ui/ChatView.tsx index a1d2638..7551a53 100644 --- a/src/features/chat/ui/ChatView.tsx +++ b/src/features/chat/ui/ChatView.tsx @@ -197,7 +197,9 @@ export function ChatView({ void acpPrepareSession(activeSessionId, selectedProvider, { workingDir: activeWorkingContext.path, personaId: selectedPersonaId ?? undefined, - }).catch(() => undefined); + }).catch((error) => { + console.error("Failed to prepare ACP session:", error); + }); }, [ activeWorkingContext, activeSessionId,