diff --git a/src/vs/platform/agentHost/common/sessionDataService.ts b/src/vs/platform/agentHost/common/sessionDataService.ts index 4b545506fd7798..1aab8000a050ec 100644 --- a/src/vs/platform/agentHost/common/sessionDataService.ts +++ b/src/vs/platform/agentHost/common/sessionDataService.ts @@ -9,7 +9,7 @@ import { URI } from '../../../base/common/uri.js'; import { createDecorator } from '../../instantiation/common/instantiation.js'; import { Event } from '../../../base/common/event.js'; import { getLargeFileConfirmationLimit } from '../../files/common/files.js'; -import type { FileEditKind, Message } from './state/sessionState.js'; +import type { FileEditKind, MarkdownResponsePart, Message, ReasoningResponsePart, ResponsePartKind } from './state/sessionState.js'; export const ISessionDataService = createDecorator('sessionDataService'); @@ -98,6 +98,9 @@ export interface IReviewedFileRecord { // ---- Session database --------------------------------------------------- +/** Ordered response text with stable reasoning-run identities and references to provider-owned tool results. */ +export type StoredAssistantResponsePart = MarkdownResponsePart | ReasoningResponsePart | { readonly kind: ResponsePartKind.ToolCall; readonly toolCallId: string }; + /** A host-persisted turn that is absent from the provider transcript. */ export interface IPersistedTurnRecord { /** Whether this is host-local or a provider turn that failed before persistence. */ @@ -266,6 +269,12 @@ export interface ISessionDatabase extends IDisposable { */ getTurnUsages(): Promise>; + /** Records a response's observed part ordering and reasoning timings with the owning turn's pruning lifecycle. */ + setAssistantResponseParts(turnId: string, responseId: string, parts: readonly StoredAssistantResponsePart[]): Promise; + + /** Reads recorded parts keyed by durable provider response id, after all previously submitted writes. */ + getAssistantResponseParts(): Promise>; + /** * Persists the JSON-serialized delegation metadata for an agent-authored turn. * Idempotent — last writer wins per turn. diff --git a/src/vs/platform/agentHost/common/state/protocol/.ahp-version b/src/vs/platform/agentHost/common/state/protocol/.ahp-version index d51683b6ada87c..79a97aca599a00 100644 --- a/src/vs/platform/agentHost/common/state/protocol/.ahp-version +++ b/src/vs/platform/agentHost/common/state/protocol/.ahp-version @@ -1 +1 @@ -5872a476 +d7a5579b diff --git a/src/vs/platform/agentHost/common/state/protocol/channels-chat/actions.ts b/src/vs/platform/agentHost/common/state/protocol/channels-chat/actions.ts index db20e7d2b67d3f..ac6007997bc90d 100644 --- a/src/vs/platform/agentHost/common/state/protocol/channels-chat/actions.ts +++ b/src/vs/platform/agentHost/common/state/protocol/channels-chat/actions.ts @@ -678,7 +678,8 @@ export interface ChatUsageAction { * Reasoning/thinking text from the model, appended to a specific reasoning response part. * * The server MUST first emit a `chat/responsePart` to create the target - * reasoning part, then use this action to append text to it. + * reasoning part, then use this action to append text or record its timing. + * An empty `content` updates only the supplied timing fields. * * @category Chat Actions * @version 1 @@ -691,6 +692,10 @@ export interface ChatReasoningAction { partId: string; /** Reasoning text chunk */ content: string; + /** Producer-recorded ISO 8601 start of the reasoning interval; omitted to preserve the existing value. */ + startedAt?: string; + /** Final elapsed reasoning time in non-negative integer milliseconds, measured by the producer's clock; omitted to preserve the existing value. Zero is a recorded duration, not unknown. */ + duration?: number; /** * Additional provider-specific metadata for this action. * diff --git a/src/vs/platform/agentHost/common/state/protocol/channels-chat/reducer.ts b/src/vs/platform/agentHost/common/state/protocol/channels-chat/reducer.ts index 5a4fd6d79b5163..806cb16f6e4c50 100644 --- a/src/vs/platform/agentHost/common/state/protocol/channels-chat/reducer.ts +++ b/src/vs/platform/agentHost/common/state/protocol/channels-chat/reducer.ts @@ -763,7 +763,12 @@ export function chatReducer(state: ChatState, action: ChatAction, log?: (msg: st case ActionType.ChatReasoning: return updateResponsePart(state, action.turnId, action.partId, part => { if (part.kind === ResponsePartKind.Reasoning) { - return { ...part, content: part.content + action.content }; + return { + ...part, + content: part.content + action.content, + ...(action.startedAt !== undefined ? { startedAt: action.startedAt } : {}), + ...(action.duration !== undefined ? { duration: action.duration } : {}), + }; } return part; }); diff --git a/src/vs/platform/agentHost/common/state/protocol/channels-chat/state.ts b/src/vs/platform/agentHost/common/state/protocol/channels-chat/state.ts index 1dbe18f14fcb92..a87b8e03be4353 100644 --- a/src/vs/platform/agentHost/common/state/protocol/channels-chat/state.ts +++ b/src/vs/platform/agentHost/common/state/protocol/channels-chat/state.ts @@ -1131,6 +1131,10 @@ export interface ReasoningResponsePart { id: string; /** Accumulated reasoning text */ content: string; + /** Producer-recorded ISO 8601 start of this reasoning interval; absent when unknown. */ + startedAt?: string; + /** Final elapsed reasoning time in non-negative integer milliseconds, measured by the producer's clock; absent while unfinished or unknown. Clients MUST NOT derive it from their own clock. */ + duration?: number; } /** diff --git a/src/vs/platform/agentHost/node/compatibleSessionDatabase.ts b/src/vs/platform/agentHost/node/compatibleSessionDatabase.ts index a0682deec01162..2356dd43df44ad 100644 --- a/src/vs/platform/agentHost/node/compatibleSessionDatabase.ts +++ b/src/vs/platform/agentHost/node/compatibleSessionDatabase.ts @@ -72,6 +72,14 @@ export class CompatibleSessionDatabase implements ISessionDatabase { return result; } + async setAssistantResponseParts(...args: Parameters): ReturnType { + return this.raw.setAssistantResponseParts(...args); + } + + async getAssistantResponseParts(): ReturnType { + return this.raw.getAssistantResponseParts(); + } + async getTurnDelegations(...[]: Parameters): ReturnType { const result = await this.raw.getTurnDelegations(); return new Map([...result].map(([key, value]) => [key, this.identity.metadata('agentHost.turnDelegation', value, 'runtime')!])); diff --git a/src/vs/platform/agentHost/node/copilot/buildSessionEvents.ts b/src/vs/platform/agentHost/node/copilot/buildSessionEvents.ts index 63a5c801f1082e..6e8cd4e6d92425 100644 --- a/src/vs/platform/agentHost/node/copilot/buildSessionEvents.ts +++ b/src/vs/platform/agentHost/node/copilot/buildSessionEvents.ts @@ -6,7 +6,7 @@ import type { JsonValue, SessionEvent } from '@github/copilot-sdk'; import { isObject } from '../../../../base/common/types.js'; import { generateUuid, isUUID } from '../../../../base/common/uuid.js'; -import { getInlineToolInput, ResponsePartKind, ToolCallStatus, ToolResultContentType, TurnState, type ToolCallCompletedState, type ToolResultContent, type ToolResultSubagentContent, type Turn } from '../../common/state/sessionState.js'; +import { getInlineToolInput, ResponsePartKind, ToolCallStatus, ToolResultContentType, TurnState, type MarkdownResponsePart, type ReasoningResponsePart, type ToolCallCompletedState, type ToolResultContent, type ToolResultSubagentContent, type Turn } from '../../common/state/sessionState.js'; /** * Default schema version stamped on the synthesized `session.start` event. @@ -44,6 +44,8 @@ export interface IBuildSessionEventsOptions { readonly schemaVersion?: number; /** Base time for the synthesized (monotonically increasing) event timestamps. Defaults to now. */ readonly startTime?: Date; + /** Associates original response parts with their synthesized user-turn and assistant-event IDs. */ + readonly onAssistantMessage?: (turnId: string, responseId: string, parts: readonly (MarkdownResponsePart | ReasoningResponsePart)[]) => void; } /** @@ -167,8 +169,9 @@ export function buildSessionEventsFromTurns(turns: readonly Turn[], options: IBu // UUID (the runtime rejects non-UUID event ids) so the reconstructed turn // keeps the id the SDK's fork/truncate RPCs address and a caller can seed // a matching protocol turn; otherwise mint a fresh UUID. + const turnId = isUUID(turn.id) ? turn.id : generateUuid(); push({ - id: isUUID(turn.id) ? turn.id : generateUuid(), + id: turnId, parentId, timestamp: nextTimestamp(), type: 'user.message', @@ -180,12 +183,14 @@ export function buildSessionEventsFromTurns(turns: readonly Turn[], options: IBu let markdown = ''; let reasoning = ''; + let parts: (MarkdownResponsePart | ReasoningResponsePart)[] = []; const flushAssistantMessage = (): void => { if (!markdown && !reasoning) { return; } + const responseId = generateUuid(); push({ - id: generateUuid(), + id: responseId, parentId, timestamp: nextTimestamp(), type: 'assistant.message', @@ -196,8 +201,10 @@ export function buildSessionEventsFromTurns(turns: readonly Turn[], options: IBu ...(options.model ? { model: options.model } : {}), }, }); + options.onAssistantMessage?.(turnId, responseId, parts); markdown = ''; reasoning = ''; + parts = []; }; for (const part of turn.responseParts) { @@ -210,11 +217,13 @@ export function buildSessionEventsFromTurns(turns: readonly Turn[], options: IBu flushAssistantMessage(); } markdown += part.content; + parts.push({ ...part }); } else if (part.kind === ResponsePartKind.Reasoning) { if (markdown) { flushAssistantMessage(); } reasoning += part.content; + parts.push({ ...part }); } else if (part.kind === ResponsePartKind.ToolCall && part.toolCall.status === ToolCallStatus.Completed) { // Flush accumulated assistant text before the tool call so the // reconstructed part order matches the original interleaving. diff --git a/src/vs/platform/agentHost/node/copilot/copilotAgent.ts b/src/vs/platform/agentHost/node/copilot/copilotAgent.ts index 93a671d7593cad..c1af91666a6fb8 100644 --- a/src/vs/platform/agentHost/node/copilot/copilotAgent.ts +++ b/src/vs/platform/agentHost/node/copilot/copilotAgent.ts @@ -69,7 +69,7 @@ import { AhpErrorCodes, AHP_SESSION_NOT_FOUND, JsonRpcErrorCodes, ProtocolError import { ICopilotConfigSlashCommandState } from '../../common/copilotConfigSlashCommands.js'; import { ICopilotHomeService } from '../../../environment/common/copilotHome.js'; import { CopilotCustomizationInstallations } from './customizations/copilotCustomizationInstallations.js'; -import { ISessionDataService, SESSION_DB_FILENAME, type ISessionDatabase } from '../../common/sessionDataService.js'; +import { ISessionDataService, SESSION_DB_FILENAME, type ISessionDatabase, type StoredAssistantResponsePart } from '../../common/sessionDataService.js'; import { IAgentHostProxyResolver } from '../agentHostProxyResolver.js'; import { writeUserDataCertificatesFile } from '../../../request/node/certificates.js'; import { MODEL_REFRESH_BASE_DELAY_MS, MODEL_REFRESH_MAX_ATTEMPTS, MODEL_REFRESH_MAX_DELAY_MS, modelRefreshBackoff } from '../shared/modelRefreshRetry.js'; @@ -79,7 +79,7 @@ import { ProtectedResourceMetadata, type AgentCustomization, type AgentSelection import { ActionType, AuthRequiredReason, type AuthRequiredParams, type SessionAction } from '../../common/state/sessionActions.js'; import { areAdditionalWorkingDirectoriesEqual } from '../../common/state/sessionWorkingDirectories.js'; import { getRepositoryRootFromWorktree } from '../../common/worktreePaths.js'; -import { CustomizationLoadStatus, CustomizationType, ChatInputResponseKind, customizationId, buildChatUri, AH_META_WORKSPACELESS_DB_KEY, AH_META_IS_ARCHIVED_DB_KEY, AH_META_IS_DONE_DB_KEY, AH_META_EHCLI_ADOPTED_DB_KEY, AH_META_EHCLI_LAST_TURN_DB_KEY, AH_META_IS_READ_DB_KEY, SessionStatus, withSessionEhcliAdoptable, withSessionStatusFlag, withSessionWorkspaceless, type ChildCustomization, type ClientPluginCustomization, type Customization, type DirectoryCustomization, type ISessionFolderPickerDecision, type MessageAttachment, type PendingMessage, type PluginCustomization, type PolicyState, type ChatInputAnswer, type ToolCallResult, type Turn, type UsageInfo } from '../../common/state/sessionState.js'; +import { CustomizationLoadStatus, CustomizationType, ChatInputResponseKind, customizationId, buildChatUri, AH_META_WORKSPACELESS_DB_KEY, AH_META_IS_ARCHIVED_DB_KEY, AH_META_IS_DONE_DB_KEY, AH_META_EHCLI_ADOPTED_DB_KEY, AH_META_EHCLI_LAST_TURN_DB_KEY, AH_META_IS_READ_DB_KEY, ResponsePartKind, SessionStatus, withSessionEhcliAdoptable, withSessionStatusFlag, withSessionWorkspaceless, type ChildCustomization, type ClientPluginCustomization, type Customization, type DirectoryCustomization, type ISessionFolderPickerDecision, type MessageAttachment, type PendingMessage, type PluginCustomization, type PolicyState, type ChatInputAnswer, type ToolCallResult, type Turn, type UsageInfo } from '../../common/state/sessionState.js'; import { CopilotChatDiscovery, ICopilotChatDiscoveryScan } from './copilotChatDiscovery.js'; import { getByokLmAgentModelId, resolveByokLmEnablement } from '../../common/agentHostByokLm.js'; import { isCustomizationEnabled } from '../../common/customizationEnablement.js'; @@ -6031,13 +6031,29 @@ export class CopilotAgent extends Disposable implements IAgent { // so the git probe and file I/O overlap on the session-creation path. const projectPromise = projectFromCopilotContext({ cwd: workingDirectory.fsPath }, this._gitService); const eventsPath = resourceJoinPath(this._copilotHomeService.home, 'session-state', sessionId, 'events.jsonl').fsPath; + const responses: { turnId: string; responseId: string; parts: readonly StoredAssistantResponsePart[] }[] = []; const jsonl = buildSessionEventLogFromTurns(importConfig.turns, { sessionId, workingDirectory: workingDirectory.fsPath, model: model?.id, + onAssistantMessage: (turnId, responseId, parts) => { + if (parts.some(part => part.kind === ResponsePartKind.Reasoning)) { + responses.push({ turnId, responseId, parts }); + } + }, }); await fs.mkdir(dirname(eventsPath), { recursive: true }); await fs.writeFile(eventsPath, jsonl, 'utf8'); + if (responses.length) { + const reference = this._sessionDataService.openDatabase(this._resolveChatStorageScope(chat)); + try { + for (const response of responses) { + await reference.object.setAssistantResponseParts(response.turnId, response.responseId, response.parts); + } + } finally { + reference.dispose(); + } + } // Persist metadata before resume so `_resumeSession` can resolve the // working directory and model. @@ -7654,6 +7670,7 @@ export class CopilotAgent extends Disposable implements IAgent { try { const backing = this._chatBackings.get(context.chatKey); const result = await mapSessionEvents(context.resource, reference.object, events, context.chat, context.ownerSession, { + logService: this._logService, workingDirectory: metadata.workingDirectory, clientToolNames: new Set(this._activeClients.get(context.ownerSession)?.toolSet.merged().map(tool => tool.name) ?? []), model: backing?.model ?? metadata.model, diff --git a/src/vs/platform/agentHost/node/copilot/copilotAgentSession.ts b/src/vs/platform/agentHost/node/copilot/copilotAgentSession.ts index 5cecd7b49c1630..ab1bca7cc17e57 100644 --- a/src/vs/platform/agentHost/node/copilot/copilotAgentSession.ts +++ b/src/vs/platform/agentHost/node/copilot/copilotAgentSession.ts @@ -57,6 +57,7 @@ import { createUnknownAgentHostClientTelemetryContext, type IAgentHostClientTele import { measureAgentProviderOperation } from '../../common/agentHostProviderTiming.js'; import { type AgentCanvasDefinitionSnapshot, AgentSession, type IAgentChatOwnerRef, type IAgentExtensionInfo, type IAgentManagedPluginRetryEntry, COPILOT_CLI_AGENT_PROVIDER_ID, AgentSignal, AgentWorkingDirectoryChangedError, AuthenticateParams, IMcpNotification, subagentChatTitle, type AgentCanvasExtensionSource, type AgentExtensionStatus, type AgentSubagentTaskModelSource, type AgentTurnProviderCallState, type IAgentCanvasCloseRequest, type IAgentCanvasOpenRequest, type IAgentPendingMessageSender, type IAgentPermissionResponseContext, type IAgentTelemetryContext, type IAgentToolPendingConfirmationSignal, type IAgentTurnDiagnosticSnapshot, type IAgentTurnTokenUsage } from '../../common/agent.js'; import { isReasoningEffortLevel } from '../../common/reasoningEffort.js'; +import { CopilotReasoningTiming } from './copilotReasoningTiming.js'; import { agentModelConfigurationMetaKey, IAgentRuntimeModelConfiguration, readAgentRuntimeModelConfiguration } from '../../common/meta/agentModelConfigurationMeta.js'; import { agentModelConfigurationReportKey, type IAgentModelConfigurationReport } from '../../common/agentModelConfiguration.js'; import { createCopilotModelConfigurationReport } from './copilotManagedModelConfiguration.js'; @@ -389,7 +390,6 @@ type IMappedSessionEvents = { turns: Turn[]; subagentTurnsByToolCallId: Readonly interface ICopilotResponsePartState { readonly markdownPartIds: Map; - readonly reasoningPartIds: Map; } function getEmptyToolResultText(binaryResults: readonly { readonly type: 'image' | 'resource' }[] | undefined): string { @@ -946,8 +946,6 @@ class CopilotTurn extends Disposable { /** Current markdown response part IDs for this root turn and its Fusion phase scopes. */ readonly markdownPartIds = new Map(); - /** Current reasoning response part IDs for this root turn and its Fusion phase scopes. */ - readonly reasoningPartIds = new Map(); readonly toolTitles = new Map(); readonly toolIntentions = new Map(); @@ -1110,6 +1108,17 @@ export class CopilotAgentSession extends Disposable { private readonly _chatChannelUri: URI; /** Fixed persistence scope for this chat; never re-derived from the mutable routing channel. Config reads/writes go through {@link _configTarget} instead — peer chats share that scope but have distinct storage. */ private readonly _storageUri: URI; + private readonly _reasoningTiming = this._register(new CopilotReasoningTiming( + (action, parentToolCallId) => this._emitProgress({ kind: 'action', resource: this._chatChannelUri, action, parentToolCallId }), + (turnId, responseId, parts) => { + if (!turnId) { + this._logService.trace(`[Copilot:${this.sessionId}] Cannot persist reasoning timing without an owning turn`); + return; + } + void this._withDatabase(db => db.setAssistantResponseParts(turnId, responseId, parts)).catch(error => + this._logService.error(`[Copilot:${this.sessionId}] Failed to persist response parts`, error)); + }, + )); get chatChannelUri(): URI { return this._chatChannelUri; @@ -1237,7 +1246,6 @@ export class CopilotAgentSession extends Disposable { private readonly _pendingSubagentToolCompletions = new Map>(); private readonly _subagentResponsePartState: ICopilotResponsePartState = { markdownPartIds: new Map(), - reasoningPartIds: new Map(), }; private readonly _resolveAgentName = (agentId: string) => this._subagents.getDisplayName(agentId); readonly modelCallTurnCorrelation = new ModelCallTurnCorrelation(); @@ -2375,6 +2383,19 @@ export class CopilotAgentSession extends Disposable { if (action.type === ActionType.ChatUsage && !parentToolCallId && this._launchPlan.localModelProvider) { this._lastRootUsage = { turnId: action.turnId, usage: action.usage }; } + if (action.type === ActionType.ChatDelta) { + const timingTurnId = parentToolCallId ? this._subagents.getRootTurnId(parentToolCallId) ?? action.turnId : action.turnId; + this._reasoningTiming.markdown(timingTurnId, action.partId, action.content, parentToolCallId); + } else if (action.type === ActionType.ChatResponsePart && action.part.kind === ResponsePartKind.Markdown) { + const timingTurnId = parentToolCallId ? this._subagents.getRootTurnId(parentToolCallId) ?? action.turnId : action.turnId; + this._reasoningTiming.markdown(timingTurnId, action.part.id, action.part.content, parentToolCallId); + } else if (action.type === ActionType.ChatToolCallStart) { + const timingTurnId = parentToolCallId ? this._subagents.getRootTurnId(parentToolCallId) ?? action.turnId : action.turnId; + this._reasoningTiming.toolCall(timingTurnId, action.toolCallId, parentToolCallId); + } else if (action.type === ActionType.ChatTurnComplete || action.type === ActionType.ChatTurnCancelled || action.type === ActionType.ChatError) { + this._reasoningTiming.finish(parentToolCallId); + this._reasoningTiming.clear(parentToolCallId); + } this._emitProgress({ kind: 'action', resource: isChatAction(action) ? this._chatChannelUri : this._ownerSessionUri, @@ -3359,15 +3380,15 @@ export class CopilotAgentSession extends Disposable { } private _clearSubagentResponseParts(parentToolCallId: string): void { + this._reasoningTiming.finish(parentToolCallId); + this._reasoningTiming.clear(parentToolCallId); this._subagentResponsePartState.markdownPartIds.delete(parentToolCallId); - this._subagentResponsePartState.reasoningPartIds.delete(parentToolCallId); } private _beginToolCallRound(parentToolCallId: string | undefined): void { const scope = parentToolCallId ?? ''; const state = this._getResponsePartState(parentToolCallId); state?.markdownPartIds.delete(scope); - state?.reasoningPartIds.delete(scope); } /** @@ -3391,6 +3412,7 @@ export class CopilotAgentSession extends Disposable { } private _startTurn(turnId: string, senderClientId: string | undefined, clientContext = createUnknownAgentHostClientTelemetryContext(AgentHostClientType.Unknown), providerInitiated = false): void { + this._reasoningTiming.clear(undefined); this._clearActivity(); this._setManagedPluginActivity(undefined); this._detectInterruptedTurnOnRestore = false; @@ -3822,23 +3844,30 @@ export class CopilotAgentSession extends Disposable { if (this._shouldDropLateRootTurnEvent('assistant.reasoning_delta')) { return; } + if (!content) { + return; + } const state = this._getResponsePartState(parentToolCallId); if (!state) { this._logService.error(`[Copilot:${this.sessionId}] Reasoning delta emitted with no active turn; dropping`); return; } const reasoningScope = parentToolCallId ?? ''; - let partId = state.reasoningPartIds.get(reasoningScope); + const timingTurnId = parentToolCallId ? this._subagents.getRootTurnId(parentToolCallId) ?? this._turnId : this._turnId; + let partId = this._reasoningTiming.activePartId(timingTurnId, parentToolCallId); if (!partId) { partId = generateUuid(); - state.reasoningPartIds.set(reasoningScope, partId); + state.markdownPartIds.delete(reasoningScope); + const startedAt = this._reasoningTiming.start(timingTurnId, partId, parentToolCallId); + this._reasoningTiming.append(content, parentToolCallId); this._emitAction({ type: ActionType.ChatResponsePart, turnId: this._turnId, - part: { kind: ResponsePartKind.Reasoning, id: partId, content }, + part: { kind: ResponsePartKind.Reasoning, id: partId, content, startedAt }, }, parentToolCallId); return; } + this._reasoningTiming.append(content, parentToolCallId); this._emitAction({ type: ActionType.ChatReasoning, turnId: this._turnId, @@ -6857,6 +6886,7 @@ export class CopilotAgentSession extends Disposable { this._logService.trace(`[Copilot:${this.sessionId}] Read ${events.length} persisted event(s); reconstructing turns`); return this._withDatabase(async db => { const result = await mapSessionEvents(this._storageUri, db, events, this._chatChannelUri, this._ownerSessionUri, { + logService: this._logService, workingDirectory: this._workingDirectory, clientToolNames: this._clientToolNames, model: this._launchPlan.kind === 'create' @@ -9147,8 +9177,6 @@ export class CopilotAgentSession extends Disposable { this._logService.info(`[Copilot:${sessionId}] System notification received: kind=${e.data.kind.type}`); if (this._turnId) { - // Later parent reasoning belongs after this notice; child reasoning keeps its own stream. - this._currentTurn.value?.reasoningPartIds.delete(''); this._emitAction({ type: ActionType.ChatResponsePart, turnId: this._turnId, @@ -9252,7 +9280,7 @@ export class CopilotAgentSession extends Disposable { const state = this._getResponsePartState(contentParentToolCallId); const isEmptyFinalAnswer = isLastMessageChunk && e.data.phase === 'final_answer' && !e.data.content && !e.data.toolRequests?.length; // Fusion sends distinct complete chunks without preceding text deltas. - if (e.data.content && (isFusionMessage || !state?.markdownPartIds.has(markdownScope))) { + if (e.data.content && (isFusionMessage || (!state?.markdownPartIds.has(markdownScope) && !this._reasoningTiming.hasMarkdown(contentParentToolCallId)))) { const partId = generateUuid(); state?.markdownPartIds.set(markdownScope, partId); this._emitAction({ @@ -9261,8 +9289,6 @@ export class CopilotAgentSession extends Disposable { part: { kind: ResponsePartKind.Markdown, id: partId, content: e.data.content }, }, contentParentToolCallId); } else if (isEmptyFinalAnswer && !state?.markdownPartIds.has(markdownScope)) { - // An empty final answer still ends the open thinking section; later text and reasoning start new parts. - state?.reasoningPartIds.delete(markdownScope); this._emitAction({ type: ActionType.ChatResponsePart, turnId: this._turnId, @@ -9290,6 +9316,12 @@ export class CopilotAgentSession extends Disposable { // Wait for the full message boundary; clearing on an earlier tool delta would duplicate assembled markdown. this._beginToolCallRound(contentParentToolCallId); } + if (isLastMessageChunk) { + const recorded = this._reasoningTiming.completeMessage(e.id, e.data.reasoningText, e.data.content ?? '', contentParentToolCallId); + if (!recorded && e.data.reasoningText) { + this._logService.trace(`[Copilot:${this.sessionId}] No complete observed response layout for assistant message ${e.id}`); + } + } }; const renderCommittedFusionMessage = (e: SessionEventPayload<'assistant.message'>, phaseToolCallId: string): void => { const call = this._pendingFusionMessageChunks.accept(e, phaseToolCallId); @@ -11997,8 +12029,6 @@ export class CopilotAgentSession extends Disposable { return; } this._reportedByokDroppedToolCount = droppedToolCount; - // Later parent reasoning belongs after this notice. - turn.reasoningPartIds.delete(''); this._emitAction({ type: ActionType.ChatResponsePart, turnId: turn.id, diff --git a/src/vs/platform/agentHost/node/copilot/copilotReasoningTiming.ts b/src/vs/platform/agentHost/node/copilot/copilotReasoningTiming.ts new file mode 100644 index 00000000000000..d510e1e63a6c68 --- /dev/null +++ b/src/vs/platform/agentHost/node/copilot/copilotReasoningTiming.ts @@ -0,0 +1,236 @@ +/*--------------------------------------------------------------------------------------------- + * Copyright (c) Microsoft Corporation. All rights reserved. + * Licensed under the MIT License. See License.txt in the project root for license information. + *--------------------------------------------------------------------------------------------*/ + +import { Disposable } from '../../../../base/common/lifecycle.js'; +import { StopWatch } from '../../../../base/common/stopwatch.js'; +import type { ILogService } from '../../../log/common/log.js'; +import type { StoredAssistantResponsePart } from '../../common/sessionDataService.js'; +import { ActionType, type ChatReasoningAction } from '../../common/state/sessionActions.js'; +import { ResponsePartKind, type MarkdownResponsePart, type ReasoningResponsePart, type ResponsePart } from '../../common/state/sessionState.js'; + +interface IRecordedMessage { + readonly turnId: string; + readonly responseId: string; + readonly parts: StoredAssistantResponsePart[]; +} + +interface IReasoningScope { + readonly turnId: string; + parts: StoredAssistantResponsePart[]; + readonly tools: Set; + active?: { + readonly partId: string; + readonly startedAt: string; + readonly clock: StopWatch; + readonly messages: Set; + persistable: boolean; + }; +} + +export interface IRecordedResponseParts { + readonly responseId: string; + readonly original: readonly ResponsePart[]; + readonly recorded: readonly StoredAssistantResponsePart[]; +} + +/** Measures contiguous reasoning output independently of SDK block and message boundaries. */ +export class CopilotReasoningTiming extends Disposable { + private readonly _scopes = new Map(); + + constructor( + private readonly _emit: (action: ChatReasoningAction, parentToolCallId: string | undefined) => void, + private readonly _persist: (turnId: string, responseId: string, parts: readonly StoredAssistantResponsePart[]) => void, + ) { + super(); + } + + activePartId(turnId: string, parentToolCallId: string | undefined): string | undefined { + const scope = this._scopes.get(parentToolCallId); + return scope?.turnId === turnId ? scope.active?.partId : undefined; + } + + start(turnId: string, partId: string, parentToolCallId: string | undefined): string { + const scope = this.getScope(turnId, parentToolCallId); + const startedAt = new Date().toISOString(); + scope.active = { partId, startedAt, clock: StopWatch.create(), messages: new Set(), persistable: true }; + return startedAt; + } + + append(content: string, parentToolCallId: string | undefined): void { + const scope = this._scopes.get(parentToolCallId); + if (!scope?.active) { + throw new Error('Reasoning output has no active interval'); + } + const last = scope.parts.at(-1); + if (last?.kind === ResponsePartKind.Reasoning && last.id === scope.active.partId) { + last.content += content; + } else { + scope.parts.push({ kind: ResponsePartKind.Reasoning, id: scope.active.partId, content, startedAt: scope.active.startedAt }); + } + } + + markdown(turnId: string, partId: string, content: string, parentToolCallId: string | undefined): void { + this.finish(parentToolCallId); + const scope = this.getScope(turnId, parentToolCallId); + const last = scope.parts.at(-1); + if (last?.kind === ResponsePartKind.Markdown && last.id === partId) { + last.content += content; + } else { + scope.parts.push({ kind: ResponsePartKind.Markdown, id: partId, content }); + } + } + + toolCall(turnId: string, toolCallId: string, parentToolCallId: string | undefined): void { + const scope = this.getScope(turnId, parentToolCallId); + if (!scope.tools.has(toolCallId)) { + scope.tools.add(toolCallId); + this.finish(parentToolCallId); + scope.parts.push({ kind: ResponsePartKind.ToolCall, toolCallId }); + } + } + + hasMarkdown(parentToolCallId: string | undefined): boolean { + return this._scopes.get(parentToolCallId)?.parts.some(part => part.kind === ResponsePartKind.Markdown) ?? false; + } + + finish(parentToolCallId: string | undefined): void { + const scope = this._scopes.get(parentToolCallId); + const active = scope?.active; + if (!scope || !active) { + return; + } + const duration = Math.max(0, Math.round(active.clock.elapsed())); + scope.active = undefined; + const finishParts = (parts: StoredAssistantResponsePart[]) => { + for (const part of parts) { + if (part.kind === ResponsePartKind.Reasoning && part.id === active.partId && active.persistable) { + part.duration = duration; + } + } + }; + finishParts(scope.parts); + for (const message of active.messages) { + finishParts(message.parts); + this.persist(message); + } + this._emit({ type: ActionType.ChatReasoning, turnId: scope.turnId, partId: active.partId, content: '', startedAt: active.startedAt, duration }, parentToolCallId); + } + + completeMessage(responseId: string, reasoningText: string | undefined, content: string, parentToolCallId: string | undefined): boolean { + const scope = this._scopes.get(parentToolCallId); + if (!scope || (!reasoningText && !content)) { + return false; + } + const parts = scope.parts; + scope.parts = []; + const matches = parts.filter(part => part.kind === ResponsePartKind.Reasoning).map(part => part.content).join('') === (reasoningText ?? '') + && parts.filter(part => part.kind === ResponsePartKind.Markdown).map(part => part.content).join('') === content; + if (!matches) { + if (scope.active && parts.some(part => part.kind === ResponsePartKind.Reasoning && part.id === scope.active?.partId)) { + scope.active.persistable = false; + } + return false; + } + if (!parts.some(part => part.kind === ResponsePartKind.Reasoning)) { + return false; + } + const message = { turnId: scope.turnId, responseId, parts }; + if (scope.active && parts.some(part => part.kind === ResponsePartKind.Reasoning && part.id === scope.active?.partId)) { + scope.active.messages.add(message); + } + this.persist(message); + return true; + } + + clear(parentToolCallId: string | undefined): void { + this._scopes.delete(parentToolCallId); + } + + private getScope(turnId: string, parentToolCallId: string | undefined): IReasoningScope { + let scope = this._scopes.get(parentToolCallId); + if (scope?.turnId !== turnId) { + scope = { turnId, parts: [], tools: new Set() }; + this._scopes.set(parentToolCallId, scope); + } + return scope; + } + + private persist(message: IRecordedMessage): void { + this._persist(message.turnId, message.responseId, message.parts.map(part => ({ ...part }))); + } + + override dispose(): void { + this._scopes.clear(); + super.dispose(); + } +} + +/** Reconstructs recorded stream order while retaining the provider's canonical tool results. */ +export function restoreRecordedResponseParts(parts: readonly ResponsePart[], responses: readonly IRecordedResponseParts[], logService?: ILogService): ResponsePart[] { + if (!responses.length) { + return [...parts]; + } + const tools = new Map(parts.flatMap((part, index) => part.kind === ResponsePartKind.ToolCall ? [[part.toolCall.toolCallId, { part, index }] as const] : [])); + const replacements = new Map(); + const replaced = new Set(); + const movedTools = new Set(); + for (const response of responses) { + const anchor = response.original[0]; + const anchorIndex = parts.indexOf(anchor); + if (anchorIndex < 0) { + logService?.warn(`[Copilot] Recorded response ${response.responseId} has no history anchor`); + continue; + } + let sawText = false; + const replacement: ResponsePart[] = []; + for (const part of response.recorded) { + if (part.kind === ResponsePartKind.ToolCall) { + const tool = tools.get(part.toolCallId); + if (!tool) { + logService?.warn(`[Copilot] Recorded response ${response.responseId} references an unavailable tool call ${part.toolCallId}`); + } else if (!movedTools.has(part.toolCallId) && (sawText || tool.index > anchorIndex)) { + movedTools.add(part.toolCallId); + replacement.push(tool.part); + } + } else { + sawText = true; + replacement.push({ ...part }); + } + } + replacements.set(anchor, replacement); + for (const original of response.original) { + replaced.add(original); + } + } + + const result: ResponsePart[] = []; + const textParts = new Map(); + const append = (part: ResponsePart) => { + if (part.kind === ResponsePartKind.Markdown || part.kind === ResponsePartKind.Reasoning) { + const key = `${part.kind}:${part.id}`; + const existing = textParts.get(key); + if (existing) { + existing.content += part.content; + if (existing.kind === ResponsePartKind.Reasoning && part.kind === ResponsePartKind.Reasoning) { + existing.startedAt ??= part.startedAt; + existing.duration = part.duration ?? existing.duration; + } + return; + } + part = { ...part }; + textParts.set(key, part); + } + result.push(part); + }; + for (const part of parts) { + const replacement = replacements.get(part); + if (replacement) { + replacement.forEach(append); + } else if (!replaced.has(part) && !(part.kind === ResponsePartKind.ToolCall && movedTools.has(part.toolCall.toolCallId))) { + append(part); + } + } + return result; +} diff --git a/src/vs/platform/agentHost/node/copilot/copilotSubagentTracking.ts b/src/vs/platform/agentHost/node/copilot/copilotSubagentTracking.ts index 918cd32d29d34b..37c1919f56c04b 100644 --- a/src/vs/platform/agentHost/node/copilot/copilotSubagentTracking.ts +++ b/src/vs/platform/agentHost/node/copilot/copilotSubagentTracking.ts @@ -109,6 +109,10 @@ export class CopilotSubagentTracking extends Disposable { return this._children.get(toolCallId)?.rootTurnId !== undefined; } + getRootTurnId(toolCallId: string): string | undefined { + return this._children.get(toolCallId)?.rootTurnId; + } + belongsToRootTurn(toolCallId: string, rootTurnId: string): boolean { return this._children.get(toolCallId)?.rootTurnId === rootTurnId; } diff --git a/src/vs/platform/agentHost/node/copilot/mapSessionEvents.ts b/src/vs/platform/agentHost/node/copilot/mapSessionEvents.ts index 475e2c3466afec..8f7806b17c1f18 100644 --- a/src/vs/platform/agentHost/node/copilot/mapSessionEvents.ts +++ b/src/vs/platform/agentHost/node/copilot/mapSessionEvents.ts @@ -10,6 +10,7 @@ import { basename, isAbsolute, join } from '../../../../base/common/path.js'; import { basename as resourceBasename } from '../../../../base/common/resources.js'; import { hasKey, isString } from '../../../../base/common/types.js'; import { URI } from '../../../../base/common/uri.js'; +import { restoreRecordedResponseParts, type IRecordedResponseParts } from './copilotReasoningTiming.js'; import { generateUuid } from '../../../../base/common/uuid.js'; import { AgentSession, COPILOT_CLI_AGENT_PROVIDER_ID } from '../../common/agent.js'; import { stripRedundantCdPrefix } from '../../common/commandLineHelpers.js'; @@ -342,6 +343,7 @@ interface ITurnBuilder { waitingStartedAt: string | undefined; waitingDuration: number; readonly responseParts: ResponsePart[]; + readonly recordedResponses: IRecordedResponseParts[]; imageGenerationSdkTurnId?: string; usage: UsageInfo | undefined; /** Tool starts seen but not yet completed in this turn, keyed by toolCallId. */ @@ -349,6 +351,7 @@ interface ITurnBuilder { } export interface IMapSessionEventsOptions { + readonly logService?: ILogService; readonly workingDirectory?: URI; /** Known client tool implementations, used to distinguish their inputs from native SDK tools. */ readonly clientToolNames?: ReadonlySet; @@ -365,7 +368,7 @@ function newTurnBuilder(id: string, text: string, options?: { attachments?: Mess ...(options?.model ? { model: options.model } : {}), ...(options?.agent ? { agent: options.agent } : {}), }; - return { id, message, startedAt: options?.startedAt, lastEventAt: options?.startedAt, waitingStartedAt: undefined, waitingDuration: 0, responseParts: [], usage: undefined, pendingTools: new Map() }; + return { id, message, startedAt: options?.startedAt, lastEventAt: options?.startedAt, waitingStartedAt: undefined, waitingDuration: 0, responseParts: [], recordedResponses: [], usage: undefined, pendingTools: new Map() }; } /** Reads the SDK envelope's ISO 8601 `timestamp`, or `undefined` when missing or unparseable. */ @@ -438,7 +441,7 @@ function makeToolStartInfo(toolName: string, rawArguments: unknown, parentToolCa } /** Seals a turn builder into a {@link Turn}, deriving `duration` from its first and last event timestamps. */ -function finalizeTurn(builder: ITurnBuilder, state: TurnState): Turn { +function finalizeTurn(builder: ITurnBuilder, state: TurnState, logService?: ILogService): Turn { const startedAtMs = builder.startedAt === undefined ? undefined : Date.parse(builder.startedAt); const endedAtMs = builder.lastEventAt === undefined ? undefined : Date.parse(builder.lastEventAt); const duration = startedAtMs !== undefined && endedAtMs !== undefined && Number.isFinite(startedAtMs) && Number.isFinite(endedAtMs) @@ -449,7 +452,7 @@ function finalizeTurn(builder: ITurnBuilder, state: TurnState): Turn { ...(builder.startedAt !== undefined ? { startedAt: builder.startedAt } : {}), ...(duration !== undefined ? { duration } : {}), message: builder.message, - responseParts: builder.responseParts, + responseParts: restoreRecordedResponseParts(builder.responseParts, builder.recordedResponses, logService), usage: builder.usage, state, }; @@ -481,6 +484,7 @@ export async function mapSessionEvents( const workingDirectory = options?.workingDirectory; let currentModel = options?.model; let currentAgent = options?.agent; + const recordedResponses = await db?.getAssistantResponseParts(); // First pass: collect tool-arg info and identify edit tool calls so we // can batch-load their stored file edits before the second pass needs // them at `tool.execution_complete` time. We also build the @@ -676,7 +680,7 @@ export async function mapSessionEvents( if (!parentBuilder) { return; } - turns.push(finalizeTurn(parentBuilder, parentTurnState)); + turns.push(finalizeTurn(parentBuilder, parentTurnState, options?.logService)); parentBuilder = undefined; parentTurnState = TurnState.Cancelled; parentTurnTerminated = false; @@ -697,7 +701,7 @@ export async function mapSessionEvents( return; } const list = subagentTurns.get(parentToolCallId) ?? []; - list.push(finalizeTurn(builder, state)); + list.push(finalizeTurn(builder, state, options?.logService)); subagentTurns.set(parentToolCallId, list); }; @@ -931,20 +935,32 @@ export async function mapSessionEvents( pendingSkillBuilder = undefined; touch(builder); } + const original: ResponsePart[] = []; if (reasoningText) { - builder.responseParts.push({ + original.push({ kind: ResponsePartKind.Reasoning, id: generateUuid(), content: reasoningText, }); } if (content) { - builder.responseParts.push({ + original.push({ kind: ResponsePartKind.Markdown, id: generateUuid(), content, }); } + builder.responseParts.push(...original); + const recorded = recordedResponses?.get(e.id); + if (recorded) { + const matches = recorded.filter(part => part.kind === ResponsePartKind.Reasoning).map(part => part.content).join('') === (reasoningText ?? '') + && recorded.filter(part => part.kind === ResponsePartKind.Markdown).map(part => part.content).join('') === content; + if (matches && original.length) { + builder.recordedResponses.push({ responseId: e.id, original, recorded }); + } else { + options?.logService?.warn(`[Copilot] Recorded response parts no longer match assistant message ${e.id}`); + } + } if (!parentToolCallId && builder === parentBuilder && !parentTurnTerminated) { parentTurnState = hasToolRequests ? TurnState.Cancelled : TurnState.Complete; } @@ -1139,7 +1155,7 @@ export async function mapSessionEvents( } flushParent(); if (pendingSkillBuilder) { - turns.push(finalizeTurn(pendingSkillBuilder, TurnState.Cancelled)); + turns.push(finalizeTurn(pendingSkillBuilder, TurnState.Cancelled, options?.logService)); } for (const parentToolCallId of [...subagentBuilders.keys()]) { flushSubagent(parentToolCallId); diff --git a/src/vs/platform/agentHost/node/sessionDatabase.ts b/src/vs/platform/agentHost/node/sessionDatabase.ts index bd8a3c5f938882..69b2f363838e23 100644 --- a/src/vs/platform/agentHost/node/sessionDatabase.ts +++ b/src/vs/platform/agentHost/node/sessionDatabase.ts @@ -6,10 +6,10 @@ import * as fs from 'fs'; import { Sequencer, SequencerByKey } from '../../../base/common/async.js'; import type { Database, RunResult } from '@vscode/sqlite3'; -import { MAX_TERMINAL_OUTPUT_BYTES, MAX_TOOL_RESULT_RESOURCE_BYTES, type IFileEditContent, type IFileEditRecord, type IPersistedTurnRecord, type IReviewedFileRecord, type ISessionCatalogSyncAcknowledgement, type ISessionCatalogSyncPendingSnapshot, type ISessionCatalogSyncSnapshot, type ISessionDatabase, type ISessionRowsWatermark, type IToolResultResource, type SessionCatalogSyncTransitionResult, type SessionCatalogSyncWriteResult, type SessionCatalogSyncWriteValidator, SESSION_FOREIGN_TURN_IDS_METADATA_KEY, SESSION_ROW_OWNER_CHAT_METADATA_KEY, type ITurnCheckpointRecord } from '../common/sessionDataService.js'; +import { MAX_TERMINAL_OUTPUT_BYTES, MAX_TOOL_RESULT_RESOURCE_BYTES, type IFileEditContent, type IFileEditRecord, type IPersistedTurnRecord, type IReviewedFileRecord, type ISessionCatalogSyncAcknowledgement, type ISessionCatalogSyncPendingSnapshot, type ISessionCatalogSyncSnapshot, type ISessionDatabase, type ISessionRowsWatermark, type IToolResultResource, type SessionCatalogSyncTransitionResult, type SessionCatalogSyncWriteResult, type SessionCatalogSyncWriteValidator, SESSION_FOREIGN_TURN_IDS_METADATA_KEY, SESSION_ROW_OWNER_CHAT_METADATA_KEY, type ITurnCheckpointRecord, type StoredAssistantResponsePart } from '../common/sessionDataService.js'; import { dirname } from '../../../base/common/path.js'; import { URI } from '../../../base/common/uri.js'; -import { AH_META_HAS_WORKSPACE_TRANSITIONS_DB_KEY, type Message } from '../common/state/sessionState.js'; +import { AH_META_HAS_WORKSPACE_TRANSITIONS_DB_KEY, ResponsePartKind, type Message } from '../common/state/sessionState.js'; import { configureSqliteJournal } from './agentHostSqliteJournal.js'; /** @@ -261,8 +261,41 @@ export const sessionDatabaseMigrations: readonly ISessionDatabaseMigration[] = [ PRIMARY KEY (tool_call_id, ordinal) )`, }, + { + version: 17, + sql: `CREATE TABLE IF NOT EXISTS reasoning_timing ( + response_id TEXT PRIMARY KEY NOT NULL, + turn_id TEXT NOT NULL REFERENCES turns(id) ON DELETE CASCADE, + started_at TEXT NOT NULL, + duration INTEGER NOT NULL CHECK(duration >= 0) + )`, + }, + { + version: 18, + sql: `CREATE TABLE IF NOT EXISTS assistant_response_parts ( + response_id TEXT PRIMARY KEY NOT NULL, + turn_id TEXT NOT NULL REFERENCES turns(id) ON DELETE CASCADE, + parts TEXT NOT NULL + )`, + }, ]; +function isStoredAssistantResponsePart(part: unknown): part is StoredAssistantResponsePart { + if (!part || typeof part !== 'object' || !('kind' in part)) { + return false; + } + if (part.kind === ResponsePartKind.ToolCall) { + return 'toolCallId' in part && typeof part.toolCallId === 'string'; + } + if ((part.kind !== ResponsePartKind.Markdown && part.kind !== ResponsePartKind.Reasoning) + || !('id' in part) || typeof part.id !== 'string' || !('content' in part) || typeof part.content !== 'string') { + return false; + } + return part.kind === ResponsePartKind.Markdown + || ((!('startedAt' in part) || part.startedAt === undefined || (typeof part.startedAt === 'string' && Number.isFinite(Date.parse(part.startedAt)))) + && (!('duration' in part) || part.duration === undefined || (typeof part.duration === 'number' && Number.isSafeInteger(part.duration) && part.duration >= 0))); +} + // ---- Promise wrappers around callback-based @vscode/sqlite3 API ----------- function dbExec(db: Database, sql: string): Promise { @@ -764,6 +797,37 @@ export class SessionDatabase implements ISessionDatabase { }); } + setAssistantResponseParts(turnId: string, responseId: string, parts: readonly StoredAssistantResponsePart[]): Promise { + const valid = parts.every(isStoredAssistantResponsePart); + const serialized = JSON.stringify(parts); + return this._mutate(async db => { + if (!valid) { + throw new Error('Invalid assistant response parts'); + } + await dbRun(db, 'INSERT OR IGNORE INTO turns (id) VALUES (?)', [turnId]); + await dbRun(db, 'INSERT OR REPLACE INTO assistant_response_parts (response_id, turn_id, parts) VALUES (?, ?, ?)', + [responseId, turnId, serialized]); + }); + } + + async getAssistantResponseParts(): Promise> { + await this.whenIdle(); + const db = await this._ensureDb(); + const rows = await dbAll(db, 'SELECT response_id, parts FROM assistant_response_parts', []); + const result = new Map(); + for (const row of rows) { + if (typeof row.response_id !== 'string' || typeof row.parts !== 'string') { + throw new Error('Invalid persisted assistant response parts'); + } + const parts: unknown = JSON.parse(row.parts); + if (!Array.isArray(parts) || !parts.every(isStoredAssistantResponsePart)) { + throw new Error(`Invalid persisted assistant response parts for ${row.response_id}`); + } + result.set(row.response_id, parts); + } + return result; + } + setTurnDelegation(turnId: string, delegation: string): Promise { return this._mutate(async db => { await dbRun(db, 'INSERT OR IGNORE INTO turns (id) VALUES (?)', [turnId]); @@ -1607,6 +1671,8 @@ export class SessionDatabase implements ISessionDatabase { // or the forked session would restore with no gauge and zero cost. for (const [oldId, newId] of mapping) { await dbRun(db, 'UPDATE turn_usage SET turn_id = ? WHERE turn_id = ?', [newId, oldId]); + await dbRun(db, 'UPDATE reasoning_timing SET turn_id = ? WHERE turn_id = ?', [newId, oldId]); + await dbRun(db, 'UPDATE assistant_response_parts SET turn_id = ? WHERE turn_id = ?', [newId, oldId]); await dbRun(db, 'UPDATE turn_delegation SET turn_id = ? WHERE turn_id = ?', [newId, oldId]); await dbRun(db, 'UPDATE turn_workspace_transition SET turn_id = ? WHERE turn_id = ?', [newId, oldId]); } diff --git a/src/vs/platform/agentHost/test/common/sessionTestHelpers.ts b/src/vs/platform/agentHost/test/common/sessionTestHelpers.ts index 223f2d4c111c28..7f5b367e8c6e99 100644 --- a/src/vs/platform/agentHost/test/common/sessionTestHelpers.ts +++ b/src/vs/platform/agentHost/test/common/sessionTestHelpers.ts @@ -9,7 +9,7 @@ import { URI } from '../../../../base/common/uri.js'; import { Emitter, Event } from '../../../../base/common/event.js'; import { constObservable } from '../../../../base/common/observable.js'; import type { IDetailedDiffResult, IDiffComputeService, IDiffCountResult, IDiffHunksResult } from '../../common/diffComputeService.js'; -import { MAX_TERMINAL_OUTPUT_BYTES, MAX_TOOL_RESULT_RESOURCE_BYTES, type IFileEditContent, type IFileEditRecord, type IPersistedTurnRecord, type IReviewedFileRecord, type ISessionCatalogSyncAcknowledgement, type ISessionCatalogSyncPendingSnapshot, type ISessionCatalogSyncSnapshot, type ISessionDatabase, type ISessionDataService, type ISessionRowsWatermark, type IToolResultResource, type SessionCatalogSyncTransitionResult, type SessionCatalogSyncWriteResult, type SessionCatalogSyncWriteValidator, SESSION_FOREIGN_TURN_IDS_METADATA_KEY, SESSION_ROW_OWNER_CHAT_METADATA_KEY, type ITurnCheckpointRecord } from '../../common/sessionDataService.js'; +import { MAX_TERMINAL_OUTPUT_BYTES, MAX_TOOL_RESULT_RESOURCE_BYTES, type IFileEditContent, type IFileEditRecord, type IPersistedTurnRecord, type IReviewedFileRecord, type ISessionCatalogSyncAcknowledgement, type ISessionCatalogSyncPendingSnapshot, type ISessionCatalogSyncSnapshot, type ISessionDatabase, type ISessionDataService, type ISessionRowsWatermark, type IToolResultResource, type SessionCatalogSyncTransitionResult, type SessionCatalogSyncWriteResult, type SessionCatalogSyncWriteValidator, SESSION_FOREIGN_TURN_IDS_METADATA_KEY, SESSION_ROW_OWNER_CHAT_METADATA_KEY, type ITurnCheckpointRecord, type StoredAssistantResponsePart } from '../../common/sessionDataService.js'; import type { IAgentHostCheckpointService } from '../../common/agentHostCheckpointService.js'; import type { IAgentHostGitStateService } from '../../common/agentHostGitStateService.js'; import { AH_META_HAS_WORKSPACE_TRANSITIONS_DB_KEY, type ISessionGitHubState, type Message } from '../../common/state/sessionState.js'; @@ -49,6 +49,7 @@ export class TestSessionDatabase implements ISessionDatabase { private readonly _turns = new Set(); private readonly _persistedTurns = new Map(); private readonly _turnUsages = new Map(); + private readonly _assistantResponseParts = new Map(); private readonly _turnDelegations = new Map(); private readonly _turnWorkspaceTransitions = new Map(); private readonly _turnEventIds = new Map(); @@ -77,7 +78,7 @@ export class TestSessionDatabase implements ISessionDatabase { this._turnDelegations.delete(turnId); this._turnWorkspaceTransitions.delete(turnId); this._turnEventIds.delete(turnId); - this._deleteToolResultsForTurns(new Set([turnId])); + this._deleteTurnContent(new Set([turnId])); for (let i = this._edits.length - 1; i >= 0; i--) { if (this._edits[i].turnId === turnId) { this._edits.splice(i, 1); @@ -362,6 +363,15 @@ export class TestSessionDatabase implements ISessionDatabase { async getTurnUsages(): Promise> { return new Map(this._turnUsages); } + async setAssistantResponseParts(turnId: string, responseId: string, parts: readonly StoredAssistantResponsePart[]): Promise { + this._turns.add(turnId); + this._assistantResponseParts.set(responseId, { turnId, parts: parts.map(part => ({ ...part })) }); + } + + async getAssistantResponseParts(): Promise> { + return new Map([...this._assistantResponseParts].map(([id, value]) => [id, value.parts])); + } + async setTurnDelegation(turnId: string, delegation: string): Promise { this._turns.add(turnId); this._turnDelegations.set(turnId, delegation); @@ -415,7 +425,7 @@ export class TestSessionDatabase implements ISessionDatabase { const index = turnIds.indexOf(turnId); if (index >= 0) { const prunedTurnIds = new Set(turnIds.slice(index)); - this._deleteToolResultsForTurns(prunedTurnIds); + this._deleteTurnContent(prunedTurnIds); for (const prunedTurnId of prunedTurnIds) { this._turns.delete(prunedTurnId); this._persistedTurns.delete(prunedTurnId); @@ -429,7 +439,7 @@ export class TestSessionDatabase implements ISessionDatabase { const index = turnIds.indexOf(turnId); if (index >= 0) { const prunedTurnIds = new Set(turnIds.slice(index + 1)); - this._deleteToolResultsForTurns(prunedTurnIds); + this._deleteTurnContent(prunedTurnIds); for (const prunedTurnId of prunedTurnIds) { this._turns.delete(prunedTurnId); this._persistedTurns.delete(prunedTurnId); @@ -440,6 +450,7 @@ export class TestSessionDatabase implements ISessionDatabase { async deleteAllTurns(): Promise { this.deleteAllTurnsCalls++; this._turns.clear(); + this._assistantResponseParts.clear(); this._edits.length = 0; this._turnDelegations.clear(); this._turnWorkspaceTransitions.clear(); @@ -568,10 +579,23 @@ export class TestSessionDatabase implements ISessionDatabase { this._toolResultResources.set(toolCallId, { ...resources, turnId: remappedTurnId }); } } + for (const [responseId, response] of this._assistantResponseParts) { + const turnId = mapping.get(response.turnId); + if (turnId) { + this._assistantResponseParts.set(responseId, { ...response, turnId }); + } else { + this._assistantResponseParts.delete(responseId); + } + } this._deleteWorkspaceTransitionMarkerIfEmpty(); } - private _deleteToolResultsForTurns(turnIds: ReadonlySet): void { + private _deleteTurnContent(turnIds: ReadonlySet): void { + for (const [responseId, response] of this._assistantResponseParts) { + if (turnIds.has(response.turnId)) { + this._assistantResponseParts.delete(responseId); + } + } for (const [toolCallId, output] of this._terminalOutputs) { if (turnIds.has(output.turnId)) { this._terminalOutputs.delete(toolCallId); diff --git a/src/vs/platform/agentHost/test/node/README.md b/src/vs/platform/agentHost/test/node/README.md index 72eab13a6bb3ff..79e2eb648f5088 100644 --- a/src/vs/platform/agentHost/test/node/README.md +++ b/src/vs/platform/agentHost/test/node/README.md @@ -12,6 +12,20 @@ Tests that launch a real provider process isolate its home, configuration, logs, The protocol and E2E folders contain their own running and authoring instructions. +## Reasoning timing + +AHP reasoning parts carry optional producer-owned `startedAt` and `duration` fields for one contiguous run of thinking output. A run starts at its first nonempty reasoning text and ends at the next markdown or tool-call part, or at turn termination. SDK reasoning IDs, reasoning-complete events, full-message boundaries, and sideband notifications do not split a run. Timing-only `chat/reasoning` updates finish the run before publishing the following content or terminal action. + +Copilot measures runs with a monotonic clock and stores the observed ordering of reasoning, markdown, and tool references against durable assistant-message event IDs in `assistant_response_parts`. A run may span SDK messages; its fragments share one ID and are updated with the same final duration, then reassembled without summing it during replay. Conversely, two runs separated by markdown or a tool retain separate IDs and durations even when the SDK saves one message containing both. Native tool results are retained and placed at the recorded boundaries. The projection is used only when its text still matches the provider transcript. + +Recorded parts follow turn remapping and pruning. The earlier draft's aggregate `reasoning_timing` rows are not reinterpreted as per-run timings. Unknown history and unfinished runs remain untimed rather than counting time while the host is stopped. This does not add capture to other providers or estimate older history. + +Conversation import stores the original reasoning projections against the synthesized assistant-message IDs before resuming the SDK session, so imported durations also survive restart. The workbench marks every AHP thinking part as provider-owned independently of whether it carries timing values; a live delta after reconnect must never turn a locally observed tail into a persisted total. Local, non-AHP providers retain their existing client-side timing. + +Single-run thinking headers use labels such as "Thought for 5s". Conversation grouping remains available, but its expanded reasoning rows show their individual durations instead of a group-wide sum. `copilotReasoningTiming.test.ts` covers 5s/12s markdown/tool boundaries through a real database restart and a single run spanning SDK messages. The provider, model, database, and renderer tests cover live boundaries, identity, migration, serialization, grouped display, and accessible text. + +Finalized sections refresh both visible and accessible timing when a duration arrives after answer text. Regression coverage includes string/array reasoning, an earlier run inside a completed conversation group, and an import/event-log/database reopen round trip. + ## Mission Control session configuration The Mission Control listener publishes Copilot Host's `approvalMode` vocabulary (`manual`, `assisted`, `allow-all`) in place of VS Code's native `autoApprove` vocabulary (`default`, `assisted`, `autoApprove`). The independent `mode` property advertises `interactive`, `plan`, and `autopilot`. Local clients and persisted configuration keep the native representation; Mission Control requests, snapshots, action echoes, and reconnect replay use the wire representation. diff --git a/src/vs/platform/agentHost/test/node/buildSessionEvents.test.ts b/src/vs/platform/agentHost/test/node/buildSessionEvents.test.ts index e6648f0d100133..c429a801a533b9 100644 --- a/src/vs/platform/agentHost/test/node/buildSessionEvents.test.ts +++ b/src/vs/platform/agentHost/test/node/buildSessionEvents.test.ts @@ -4,6 +4,9 @@ *--------------------------------------------------------------------------------------------*/ import assert from 'assert'; +import { promises as fs } from 'fs'; +import { tmpdir } from 'os'; +import { join } from '../../../../base/common/path.js'; import { ensureNoDisposablesAreLeakedInTestSuite } from '../../../../base/test/common/utils.js'; import { URI } from '../../../../base/common/uri.js'; import { generateUuid, isUUID } from '../../../../base/common/uuid.js'; @@ -12,15 +15,17 @@ import { MessageKind, ResponsePartKind, ToolCallConfirmationReason, ToolCallStat import { buildSessionEventLogFromTurns, buildSessionEventsFromTurns, serializeSessionEventsToJsonl } from '../../node/copilot/buildSessionEvents.js'; import { mapSessionEvents as mapSessionEventsWithRouting } from '../../node/copilot/mapSessionEvents.js'; import type { SessionEvent } from '@github/copilot-sdk'; +import type { ISessionDatabase } from '../../common/sessionDataService.js'; +import { SessionDatabase } from '../../node/sessionDatabase.js'; suite('buildSessionEventsFromTurns — reverse of mapSessionEvents', () => { - ensureNoDisposablesAreLeakedInTestSuite(); + const store = ensureNoDisposablesAreLeakedInTestSuite(); const session = AgentSession.uri('copilot', 'test-session'); const sessionId = 'test-session'; - function mapSessionEvents(session: URI, db: undefined, events: Parameters[2]) { + function mapSessionEvents(session: URI, db: ISessionDatabase | undefined, events: Parameters[2]) { return mapSessionEventsWithRouting(session, db, events, URI.parse(buildChatUri(session, 'default')), session); } @@ -134,6 +139,55 @@ suite('buildSessionEventsFromTurns — reverse of mapSessionEvents', () => { assert.deepStrictEqual(project(reconstructed), project(turns)); }); + for (const sourceId of [generateUuid(), 'local-turn']) { + test(`imported reasoning timing survives event-log and database reopen (${isUUID(sourceId) ? 'UUID' : 'local'} turn id)`, async () => { + const directory = await fs.mkdtemp(join(tmpdir(), 'import-reasoning-timing-')); + const databasePath = join(directory, 'session.db'); + const database = store.add(await SessionDatabase.open(databasePath)); + let reopened: SessionDatabase | undefined; + try { + const timed = { kind: ResponsePartKind.Reasoning as const, id: 'timed-run', content: 'Consider the answer', startedAt: '1970-01-01T00:00:01.000Z', duration: 45_000 }; + const zero = { kind: ResponsePartKind.Reasoning as const, id: 'zero-run', content: 'Check the result', duration: 0 }; + const untimed = { kind: ResponsePartKind.Reasoning as const, id: 'untimed-run', content: 'Older reasoning' }; + const writes: Promise[] = []; + const events = buildSessionEventsFromTurns([userTurn(sourceId, 'Question', [ + timed, toolCallPart('read', 'read_file', '{"path":"file.ts"}', 'Result'), + zero, markdown('Answer'), untimed, markdown('Done'), + ])], { + sessionId, + onAssistantMessage: (turnId, responseId, parts) => { + if (parts.some(part => part.kind === ResponsePartKind.Reasoning)) { + writes.push(database.setAssistantResponseParts(turnId, responseId, parts)); + } + }, + }); + await fs.writeFile(join(directory, 'events.jsonl'), serializeSessionEventsToJsonl(events)); + await Promise.all(writes); + await database.close(); + reopened = store.add(await SessionDatabase.open(databasePath)); + const savedEvents: SessionEvent[] = (await fs.readFile(join(directory, 'events.jsonl'), 'utf8')).trim().split('\n').map(line => JSON.parse(line)); + const { turns } = await mapSessionEvents(session, reopened, savedEvents); + const restoredReasoning = turns[0].responseParts.filter(part => part.kind === ResponsePartKind.Reasoning); + const importedTurnId = savedEvents.find(event => event.type === 'user.message')!.id; + await reopened.deleteTurn(importedTurnId); + + assert.deepStrictEqual({ + restoredReasoning, + turnId: turns[0].id, + remainingParts: [...await reopened.getAssistantResponseParts()], + }, { + restoredReasoning: [timed, zero, untimed], + turnId: importedTurnId, + remainingParts: [], + }); + } finally { + await reopened?.close(); + await database.close(); + await fs.rm(directory, { recursive: true, force: true }); + } + }); + } + test('emits an abort for a cancelled turn so it reconstructs as cancelled with its text', async () => { const id = generateUuid(); const turns: Turn[] = [{ diff --git a/src/vs/platform/agentHost/test/node/copilotAgent.test.ts b/src/vs/platform/agentHost/test/node/copilotAgent.test.ts index b4c3c20e2af57c..b54f1caa5d8962 100644 --- a/src/vs/platform/agentHost/test/node/copilotAgent.test.ts +++ b/src/vs/platform/agentHost/test/node/copilotAgent.test.ts @@ -78,7 +78,7 @@ import { AgentSession, GITHUB_COPILOT_PROTECTED_RESOURCE, type AgentSignal, type import { AgentHostClientType } from '../../common/agentHostClientInfo.js'; import { subagentChatUri } from '../../common/agentHostChatMinting.js'; import { AgentHostClientConnectionKind, AgentHostLaunchKind, AgentHostTransportKind, createUnknownAgentHostClientTelemetryContext } from '../../common/agentHostTelemetry.js'; -import { ISessionDataService } from '../../common/sessionDataService.js'; +import { ISessionDataService, type StoredAssistantResponsePart } from '../../common/sessionDataService.js'; import { buildNonPtyShellTerminalUri } from '../../common/nonPtyShellTerminalUri.js'; import { buildDefaultChatUri, buildChatUri, buildSubagentChatUri, buildSubagentSessionUri, CustomizationLoadStatus, MessageKind, readSessionEhcliAdoptable, readSessionWorkspaceless, ResponsePartKind, ToolResultContentType, TurnState, customizationId, AH_META_EHCLI_ADOPTED_DB_KEY, AH_META_EHCLI_LAST_TURN_DB_KEY, AH_META_IS_ARCHIVED_DB_KEY, AH_META_IS_READ_DB_KEY, AH_META_WORKSPACELESS_DB_KEY, type ClientPluginCustomization, type Customization, type PluginCustomization, type ToolCallResult, type Turn, RuleCustomization } from '../../common/state/sessionState.js'; import { ChatOriginKind, CustomizationEnablementKind, CustomizationType, McpServerStatus, SessionStatus, ToolCallContributorKind, type AgentSelection, type ModelSelection, type ProtectedResourceMetadata, type ToolDefinition } from '../../common/state/protocol/state.js'; @@ -22473,7 +22473,10 @@ suite('CopilotAgent', () => { id: 'imported-turn-1', state: TurnState.Complete, message: { text: 'Remember IMPORT_ALPHA.', origin: { kind: MessageKind.User } }, - responseParts: [{ kind: ResponsePartKind.Markdown, id: 'response', content: 'ready' }], + responseParts: [ + { kind: ResponsePartKind.Reasoning, id: 'imported-reasoning', content: 'Considering the request', startedAt: '1970-01-01T00:00:01.000Z', duration: 45_000 }, + { kind: ResponsePartKind.Markdown, id: 'response', content: 'ready' }, + ], usage: {}, }; @@ -22482,6 +22485,16 @@ suite('CopilotAgent', () => { workingDirectories: [workingDirectory], importConversation: { turns: [turn] }, }); + const events: SessionEvent[] = (await fs.readFile(join(getCopilotHomePath(userHome.fsPath, {}), 'session-state', 'import-exact-chat', 'events.jsonl'), 'utf8')).trim().split('\n').map(line => JSON.parse(line)); + const database = sessionDataService.openDatabase(session); + let importedReasoning: readonly StoredAssistantResponsePart[] | undefined; + try { + const parts = await database.object.getAssistantResponseParts(); + const reasoningEvent = events.find(event => event.type === 'assistant.message' && event.data.reasoningText); + importedReasoning = reasoningEvent && parts.get(reasoningEvent.id); + } finally { + database.dispose(); + } // The imported session's default chat is bound directly by // `createChat` itself (via `_importConversation` → @@ -22492,11 +22505,13 @@ suite('CopilotAgent', () => { resultSession: result.session.toString(), boundSdkId: chatBackings(agent).get(chat.toString())?.sdkSessionId, live: hasLiveChat(agent, chat), + importedReasoning, }, { resumeCalls: ['import-exact-chat'], resultSession: session.toString(), boundSdkId: 'import-exact-chat', live: true, + importedReasoning: [turn.responseParts[0]], }); await agent.chats.sendMessage(chat, 'follow-up', [workingDirectory], undefined, 'turn-2', undefined, exactChatContext(result.session, chat, result.session)); diff --git a/src/vs/platform/agentHost/test/node/copilotAgentSession.test.ts b/src/vs/platform/agentHost/test/node/copilotAgentSession.test.ts index fb179248e9eb0c..1dca6357d9689d 100644 --- a/src/vs/platform/agentHost/test/node/copilotAgentSession.test.ts +++ b/src/vs/platform/agentHost/test/node/copilotAgentSession.test.ts @@ -20,6 +20,7 @@ import { encodeBase64, VSBuffer } from '../../../../base/common/buffer.js'; import { Emitter, Event } from '../../../../base/common/event.js'; import { Disposable, DisposableStore } from '../../../../base/common/lifecycle.js'; import { Schemas } from '../../../../base/common/network.js'; +import { StopWatch } from '../../../../base/common/stopwatch.js'; import { join, sep } from '../../../../base/common/path.js'; import { hasKey } from '../../../../base/common/types.js'; import { URI } from '../../../../base/common/uri.js'; @@ -9782,7 +9783,7 @@ suite('CopilotAgentSession', () => { }); for (const phase of ['commentary', 'final_answer']) { - test(`marks only an empty final answer as a section boundary without claiming the markdown scope (${phase})`, async () => { + test(`retains empty final-answer notices without reusing reasoning across markdown (${phase})`, async () => { const { session, mockSession, signals } = await createAgentSession(disposables); session.resetTurnState('turn-parent'); mockSession.fire('assistant.turn_start', { turnId: 'sdk-parent' }); @@ -9803,11 +9804,12 @@ suite('CopilotAgentSession', () => { } return [{ kind: part.kind, content: part.kind === ResponsePartKind.Markdown || part.kind === ResponsePartKind.Reasoning ? part.content : undefined }]; } - return action.type === ActionType.ChatDelta || action.type === ActionType.ChatReasoning ? [{ kind: action.type, content: action.content }] : []; + return action.type === ActionType.ChatDelta || (action.type === ActionType.ChatReasoning && action.content) ? [{ kind: action.type, content: action.content }] : []; }); assert.deepStrictEqual({ parts, + timingUpdates: getActions(signals).filter(action => action.type === ActionType.ChatReasoning && action.duration !== undefined).length, parentCompleted: getActions(signals).some(action => action.type === ActionType.ChatTurnComplete), childCompleted: signals.some(signal => signal.kind === 'subagent_completed'), }, { @@ -9821,8 +9823,9 @@ suite('CopilotAgentSession', () => { : [ { kind: ResponsePartKind.Reasoning, content: 'Assessing' }, { kind: ResponsePartKind.Markdown, content: 'Later text' }, - { kind: ActionType.ChatReasoning, content: 'Later reasoning' }, + { kind: ResponsePartKind.Reasoning, content: 'Later reasoning' }, ], + timingUpdates: 1, parentCompleted: false, childCompleted: false, }); @@ -16662,7 +16665,7 @@ Use the attached image as context. ]); }); - test('completion notifications split parent reasoning without splitting running subagent reasoning', async () => { + test('completion notifications do not split contiguous parent or child reasoning', async () => { const { session, mockSession, signals } = await createAgentSession(disposables); session.resetTurnState('turn-active'); mockSession.fire('subagent.started', { @@ -16693,21 +16696,23 @@ Use the attached image as context. } return { kind: action.part.kind, scope: signal.parentToolCallId ?? 'parent', content: action.part.content }; } - return action.type === ActionType.ChatReasoning + return action.type === ActionType.ChatReasoning && action.content ? { kind: 'delta', scope: signal.parentToolCallId ?? 'parent', content: action.content } : undefined; }).filter(update => update !== undefined); - assert.deepStrictEqual({ updates, parentReasoningParts: reasoningIds.size }, { + const timingScopes = signals.flatMap(signal => signal.kind === 'action' && signal.action.type === ActionType.ChatReasoning && signal.action.duration !== undefined ? [signal.parentToolCallId ?? 'parent'] : []); + assert.deepStrictEqual({ updates, parentReasoningParts: reasoningIds.size, timingScopes }, { updates: [ { kind: ResponsePartKind.Reasoning, scope: 'parent', content: 'Before notification' }, { kind: ResponsePartKind.Reasoning, scope: 'task-running', content: 'Child reasoning' }, { kind: ResponsePartKind.SystemNotification, scope: 'parent', content: 'Background agent `Completed reviewer` is complete' }, - { kind: ResponsePartKind.Reasoning, scope: 'parent', content: 'After notification' }, + { kind: 'delta', scope: 'parent', content: 'After notification' }, { kind: 'delta', scope: 'parent', content: ' continued' }, { kind: 'delta', scope: 'task-running', content: ' still running' }, ], - parentReasoningParts: 2, + parentReasoningParts: 1, + timingScopes: [], }); }); @@ -23666,12 +23671,87 @@ Use the attached image as context. }); }); + test('publishes and persists reasoning timing before the assistant answer', async () => { + const database = new TestSessionDatabase(); + const { session, mockSession, signals } = await createAgentSession(disposables, { sessionDatabase: database }); + const elapsed = stub(StopWatch.prototype, 'elapsed').returns(45_000); + try { + session.resetTurnState('host-turn'); + mockSession.fire('assistant.reasoning_delta', { reasoningId: 'sdk-reasoning', deltaContent: 'First' }); + mockSession.fire('assistant.reasoning_delta', { reasoningId: 'sdk-reasoning', deltaContent: ' thought' }); + mockSession.fire('assistant.message', { messageId: 'sdk-message', content: 'Done', reasoningText: 'First thought' }, { id: 'durable-response' }); + const actions = signals.flatMap(signal => signal.kind === 'action' ? [signal.action] : []); + const reasoning = actions.flatMap(action => action.type === ActionType.ChatResponsePart && action.part.kind === ResponsePartKind.Reasoning ? [action.part] : [])[0]; + const finalTiming = actions.flatMap(action => action.type === ActionType.ChatReasoning && action.duration !== undefined ? [action] : [])[0]; + const timingIndex = actions.indexOf(finalTiming); + const answerIndex = actions.findIndex(action => action.type === ActionType.ChatResponsePart && action.part.kind === ResponsePartKind.Markdown); + const recorded = await database.getAssistantResponseParts(); + const recordedReasoning = recorded.get('durable-response')?.find(part => part.kind === ResponsePartKind.Reasoning); + + assert.deepStrictEqual({ + duration: finalTiming?.duration, + partIdMatches: finalTiming?.partId === reasoning?.id, + publishedBeforeAnswer: timingIndex >= 0 && timingIndex < answerIndex, + recorded: [...recorded.keys()], + recordedDuration: recordedReasoning?.duration, + startMatches: recordedReasoning?.startedAt === reasoning?.startedAt, + }, { + duration: 45_000, + partIdMatches: true, + publishedBeforeAnswer: true, + recorded: ['durable-response'], + recordedDuration: 45_000, + startMatches: true, + }); + } finally { + elapsed.restore(); + } + }); + + test('SDK reasoning and message completion do not end contiguous thinking output', async () => { + const database = new TestSessionDatabase(); + const { session, mockSession, signals } = await createAgentSession(disposables, { sessionDatabase: database }); + const elapsed = stub(StopWatch.prototype, 'elapsed').returns(45_000); + try { + session.resetTurnState('host-turn'); + mockSession.fire('assistant.reasoning_delta', { reasoningId: 'sdk-first', deltaContent: 'First' }); + mockSession.fire('assistant.reasoning', { reasoningId: 'sdk-first', content: 'First' }); + mockSession.fire('assistant.message', { messageId: 'message-first', content: '', reasoningText: 'First' }, { id: 'durable-first' }); + mockSession.fire('assistant.reasoning_delta', { reasoningId: 'sdk-second', deltaContent: 'Second' }); + mockSession.fire('assistant.reasoning', { reasoningId: 'sdk-second', content: 'Second' }); + mockSession.fire('assistant.message', { messageId: 'message-second', content: '', reasoningText: 'Second' }, { id: 'durable-second' }); + const beforeBoundary = signals.filter(signal => signal.kind === 'action' && signal.action.type === ActionType.ChatReasoning && signal.action.duration !== undefined).length; + mockSession.fire('assistant.message_delta', { messageId: 'answer', deltaContent: 'Done' }); + const parts = signals.flatMap(signal => signal.kind === 'action' && signal.action.type === ActionType.ChatResponsePart && signal.action.part.kind === ResponsePartKind.Reasoning ? [signal.action.part] : []); + const durations = signals.flatMap(signal => signal.kind === 'action' && signal.action.type === ActionType.ChatReasoning && signal.action.duration !== undefined ? [signal.action.duration] : []); + const recorded = await database.getAssistantResponseParts(); + + assert.deepStrictEqual({ + beforeBoundary, + reasoningParts: parts.length, + durations, + recorded: [...recorded].map(([responseId, value]) => ({ responseId, runs: value.flatMap(part => part.kind === ResponsePartKind.Reasoning ? [{ sameRun: part.id === parts[0].id, duration: part.duration }] : []) })), + }, { + beforeBoundary: 0, + reasoningParts: 1, + durations: [45_000], + recorded: [ + { responseId: 'durable-first', runs: [{ sameRun: true, duration: 45_000 }] }, + { responseId: 'durable-second', runs: [{ sameRun: true, duration: 45_000 }] }, + ], + }); + } finally { + elapsed.restore(); + } + }); + test('reasoning delta after tool_start starts a new reasoning response part', async () => { const { session, mockSession, signals } = await createAgentSession(disposables); session.resetTurnState('turn-1'); // First reasoning delta — allocates a fresh reasoning response part. mockSession.fire('assistant.reasoning_delta', { + reasoningId: 'reasoning-before-tool', deltaContent: 'thinking step 1', } as SessionEventPayload<'assistant.reasoning_delta'>['data']); @@ -23692,6 +23772,7 @@ Use the attached image as context. // renderer / state-tree would merge it into the pre-tool-call // block and the visual ordering would be wrong on restore. mockSession.fire('assistant.reasoning_delta', { + reasoningId: 'reasoning-after-tool', deltaContent: 'thinking step 2', } as SessionEventPayload<'assistant.reasoning_delta'>['data']); diff --git a/src/vs/platform/agentHost/test/node/copilotReasoningTiming.test.ts b/src/vs/platform/agentHost/test/node/copilotReasoningTiming.test.ts new file mode 100644 index 00000000000000..f2877b789371f6 --- /dev/null +++ b/src/vs/platform/agentHost/test/node/copilotReasoningTiming.test.ts @@ -0,0 +1,245 @@ +/*--------------------------------------------------------------------------------------------- + * Copyright (c) Microsoft Corporation. All rights reserved. + * Licensed under the MIT License. See License.txt in the project root for license information. + *--------------------------------------------------------------------------------------------*/ + +import assert from 'assert'; +import { promises as fs } from 'fs'; +import { tmpdir } from 'os'; +import sinon from 'sinon'; +import { join } from '../../../../base/common/path.js'; +import { StopWatch } from '../../../../base/common/stopwatch.js'; +import { URI } from '../../../../base/common/uri.js'; +import { ensureNoDisposablesAreLeakedInTestSuite } from '../../../../base/test/common/utils.js'; +import type { StoredAssistantResponsePart } from '../../common/sessionDataService.js'; +import type { ChatReasoningAction } from '../../common/state/sessionActions.js'; +import { ResponsePartKind } from '../../common/state/sessionState.js'; +import { CopilotReasoningTiming } from '../../node/copilot/copilotReasoningTiming.js'; +import { mapSessionEvents } from '../../node/copilot/mapSessionEvents.js'; +import { SessionDatabase } from '../../node/sessionDatabase.js'; +import { toSessionEvents, type ISessionEvent } from './copilotTestEvents.js'; + +suite('CopilotReasoningTiming', () => { + const store = ensureNoDisposablesAreLeakedInTestSuite(); + let clock: ReturnType; + + setup(() => { + clock = sinon.useFakeTimers({ now: 1000, toFake: ['Date'] }); + sinon.stub(StopWatch, 'create').callsFake(() => new StopWatch(false)); + }); + + teardown(() => sinon.restore()); + + function createTiming() { + const actions: { action: ChatReasoningAction; parentToolCallId: string | undefined }[] = []; + const recorded = new Map(); + const timing = store.add(new CopilotReasoningTiming( + (action, parentToolCallId) => actions.push({ action, parentToolCallId }), + (_turnId, responseId, parts) => recorded.set(responseId, parts), + )); + return { timing, actions, recorded }; + } + + test('keeps 5s and 12s runs separate within one SDK message', () => { + const { timing, actions, recorded } = createTiming(); + timing.start('turn', 'first', undefined); + timing.append('First', undefined); + clock.tick(5000); + timing.markdown('turn', 'between', 'Between', undefined); + clock.tick(20_000); + timing.start('turn', 'second', undefined); + timing.append('Second', undefined); + clock.tick(12_000); + timing.markdown('turn', 'answer', 'Done', undefined); + timing.completeMessage('message', 'FirstSecond', 'BetweenDone', undefined); + + assert.deepStrictEqual({ + durations: actions.map(({ action }) => ({ id: action.partId, duration: action.duration })), + parts: recorded.get('message'), + }, { + durations: [{ id: 'first', duration: 5000 }, { id: 'second', duration: 12_000 }], + parts: [ + { kind: ResponsePartKind.Reasoning, id: 'first', content: 'First', startedAt: '1970-01-01T00:00:01.000Z', duration: 5000 }, + { kind: ResponsePartKind.Markdown, id: 'between', content: 'Between' }, + { kind: ResponsePartKind.Reasoning, id: 'second', content: 'Second', startedAt: '1970-01-01T00:00:26.000Z', duration: 12_000 }, + { kind: ResponsePartKind.Markdown, id: 'answer', content: 'Done' }, + ], + }); + }); + + test('SDK messages do not end a run and completed timing updates earlier message fragments', () => { + const { timing, actions, recorded } = createTiming(); + timing.start('turn', 'run', undefined); + timing.append('First', undefined); + clock.tick(5000); + timing.completeMessage('message-1', 'First', '', undefined); + const unfinished = recorded.get('message-1'); + const actionCountAtMessageBoundary = actions.length; + clock.tick(7000); + timing.append('Second', undefined); + clock.tick(12_000); + timing.markdown('turn', 'answer', 'Done', undefined); + timing.completeMessage('message-2', 'Second', 'Done', undefined); + + assert.deepStrictEqual({ + actionCountAtMessageBoundary, + unfinished, + durations: actions.map(({ action }) => action.duration), + parts: [...recorded.values()].flat().filter(part => part.kind === ResponsePartKind.Reasoning), + }, { + actionCountAtMessageBoundary: 0, + unfinished: [{ kind: ResponsePartKind.Reasoning, id: 'run', content: 'First', startedAt: '1970-01-01T00:00:01.000Z' }], + durations: [24_000], + parts: [ + { kind: ResponsePartKind.Reasoning, id: 'run', content: 'First', startedAt: '1970-01-01T00:00:01.000Z', duration: 24_000 }, + { kind: ResponsePartKind.Reasoning, id: 'run', content: 'Second', startedAt: '1970-01-01T00:00:01.000Z', duration: 24_000 }, + ], + }); + }); + + test('parent and subagent runs stop independently', () => { + const { timing, actions } = createTiming(); + timing.start('turn', 'parent', undefined); + timing.append('Parent', undefined); + clock.tick(1000); + timing.start('turn', 'child', 'tool'); + timing.append('Child', 'tool'); + clock.tick(2000); + timing.completeMessage('child-message', 'Child', '', 'tool'); + clock.tick(3000); + timing.markdown('turn', 'parent-answer', 'Done', undefined); + clock.tick(4000); + timing.toolCall('turn', 'child-tool', 'tool'); + + assert.deepStrictEqual(actions.map(({ action, parentToolCallId }) => ({ id: action.partId, duration: action.duration, parentToolCallId })), [ + { id: 'parent', duration: 6000, parentToolCallId: undefined }, + { id: 'child', duration: 9000, parentToolCallId: 'tool' }, + ]); + }); + + test('preserves zero and leaves interrupted or mismatched recordings untimed', () => { + const { timing, recorded } = createTiming(); + timing.start('turn', 'zero', undefined); + timing.append('Immediate', undefined); + timing.markdown('turn', 'answer', 'Done', undefined); + timing.completeMessage('zero-message', 'Immediate', 'Done', undefined); + timing.start('turn', 'interrupted', undefined); + timing.append('Partial', undefined); + timing.completeMessage('partial-message', 'Partial', '', undefined); + timing.clear(undefined); + clock.tick(60_000); + const unobserved = timing.completeMessage('old-message', 'Old history', '', undefined); + timing.start('turn', 'mismatch', undefined); + timing.append('Observed prefix', undefined); + const mismatch = timing.completeMessage('mismatch-message', 'Different content', '', undefined); + timing.append('Tail', undefined); + timing.markdown('turn', 'tail-answer', 'Done', undefined); + timing.completeMessage('tail-message', 'Tail', 'Done', undefined); + + assert.deepStrictEqual({ + unobserved, mismatch, + recorded: [...recorded].map(([id, parts]) => ({ id, durations: parts.flatMap(part => part.kind === ResponsePartKind.Reasoning ? [part.duration] : []) })), + }, { + unobserved: false, mismatch: false, + recorded: [ + { id: 'zero-message', durations: [0] }, + { id: 'partial-message', durations: [undefined] }, + { id: 'tail-message', durations: [undefined] }, + ], + }); + }); + + for (const boundary of ['markdown', 'tool'] as const) { + test(`restores separate 5s and 12s runs and their ${boundary} boundary after a database restart`, async () => { + const directory = await fs.mkdtemp(join(tmpdir(), 'copilot-reasoning-runs-')); + const path = join(directory, 'session.db'); + const database = store.add(await SessionDatabase.open(path)); + let restored: SessionDatabase | undefined; + try { + const writes: Promise[] = []; + const timing = store.add(new CopilotReasoningTiming( + () => { }, + (turnId, responseId, parts) => writes.push(database.setAssistantResponseParts(turnId, responseId, parts)), + )); + timing.start('host-turn', 'first', undefined); + timing.append('First', undefined); + clock.tick(5000); + if (boundary === 'markdown') { + timing.markdown('host-turn', 'between', 'Between', undefined); + } else { + timing.toolCall('host-turn', 'tool', undefined); + } + clock.tick(20_000); + timing.start('host-turn', 'second', undefined); + timing.append('Second', undefined); + clock.tick(12_000); + timing.markdown('host-turn', 'answer', 'Done', undefined); + timing.completeMessage('assistant-event', 'FirstSecond', boundary === 'markdown' ? 'BetweenDone' : 'Done', undefined); + await Promise.all(writes); + await database.close(); + restored = store.add(await SessionDatabase.open(path)); + const session = URI.parse('ahp-session:/opaque-session'); + const events: ISessionEvent[] = [ + { type: 'user.message', id: 'user', data: { content: 'Request' } }, + { type: 'assistant.message', id: 'assistant-event', data: { content: boundary === 'markdown' ? 'BetweenDone' : 'Done', reasoningText: 'FirstSecond' } }, + ]; + if (boundary === 'tool') { + events.push( + { type: 'tool.execution_start', data: { toolCallId: 'tool', toolName: 'read_file', arguments: { path: '/test/file.ts' } } }, + { type: 'tool.execution_complete', data: { toolCallId: 'tool', success: true, result: { content: 'Tool result' } } }, + ); + } + const result = await mapSessionEvents(session, restored, toSessionEvents(events), URI.parse('ahp-chat:/opaque-chat'), session); + + assert.deepStrictEqual(result.turns[0].responseParts.map(part => part.kind === ResponsePartKind.ToolCall + ? { kind: part.kind, id: part.toolCall.toolCallId } + : part.kind === ResponsePartKind.Reasoning + ? { kind: part.kind, id: part.id, content: part.content, duration: part.duration } + : part.kind === ResponsePartKind.Markdown ? { kind: part.kind, id: part.id, content: part.content } : { kind: part.kind }), [ + { kind: ResponsePartKind.Reasoning, id: 'first', content: 'First', duration: 5000 }, + boundary === 'markdown' ? { kind: ResponsePartKind.Markdown, id: 'between', content: 'Between' } : { kind: ResponsePartKind.ToolCall, id: 'tool' }, + { kind: ResponsePartKind.Reasoning, id: 'second', content: 'Second', duration: 12_000 }, + { kind: ResponsePartKind.Markdown, id: 'answer', content: 'Done' }, + ]); + } finally { + await restored?.close(); + await database.close(); + await fs.rm(directory, { recursive: true, force: true }); + } + }); + } + + test('replay combines fragments of one run across SDK messages without summing their duration', async () => { + const database = store.add(await SessionDatabase.open(':memory:')); + try { + const writes: Promise[] = []; + const timing = store.add(new CopilotReasoningTiming( + () => { }, + (turnId, responseId, parts) => writes.push(database.setAssistantResponseParts(turnId, responseId, parts)), + )); + timing.start('host-turn', 'run', undefined); + timing.append('First', undefined); + clock.tick(5000); + timing.completeMessage('first-message', 'First', '', undefined); + clock.tick(7000); + timing.append('Second', undefined); + clock.tick(12_000); + timing.markdown('host-turn', 'answer', 'Done', undefined); + timing.completeMessage('second-message', 'Second', 'Done', undefined); + await Promise.all(writes); + const session = URI.parse('ahp-session:/session'); + const result = await mapSessionEvents(session, database, toSessionEvents([ + { type: 'user.message', id: 'user', data: { content: 'Request' } }, + { type: 'assistant.message', id: 'first-message', data: { reasoningText: 'First', content: '' } }, + { type: 'assistant.message', id: 'second-message', data: { reasoningText: 'Second', content: 'Done' } }, + ]), URI.parse('ahp-chat:/chat'), session); + + assert.deepStrictEqual(result.turns[0].responseParts, [ + { kind: ResponsePartKind.Reasoning, id: 'run', content: 'FirstSecond', startedAt: '1970-01-01T00:00:01.000Z', duration: 24_000 }, + { kind: ResponsePartKind.Markdown, id: 'answer', content: 'Done' }, + ]); + } finally { + await database.close(); + } + }); +}); diff --git a/src/vs/platform/agentHost/test/node/sessionDatabase.test.ts b/src/vs/platform/agentHost/test/node/sessionDatabase.test.ts index 9c9106f6d64512..aad8b93fa14ede 100644 --- a/src/vs/platform/agentHost/test/node/sessionDatabase.test.ts +++ b/src/vs/platform/agentHost/test/node/sessionDatabase.test.ts @@ -10,7 +10,7 @@ import { DeferredPromise } from '../../../../base/common/async.js'; import { ensureNoDisposablesAreLeakedInTestSuite } from '../../../../base/test/common/utils.js'; import { DisposableStore } from '../../../../base/common/lifecycle.js'; import { SessionDatabase, runMigrations, sessionDatabaseMigrations, type ISessionDatabaseMigration } from '../../node/sessionDatabase.js'; -import { AH_META_HAS_WORKSPACE_TRANSITIONS_DB_KEY, AH_META_WORKSPACELESS_DB_KEY, FileEditKind, MessageKind } from '../../common/state/sessionState.js'; +import { AH_META_HAS_WORKSPACE_TRANSITIONS_DB_KEY, AH_META_WORKSPACELESS_DB_KEY, FileEditKind, MessageKind, ResponsePartKind, type ReasoningResponsePart } from '../../common/state/sessionState.js'; import { MAX_TERMINAL_OUTPUT_BYTES, MAX_TOOL_RESULT_RESOURCE_BYTES, type IReviewedFileRecord, type ISessionCatalogSyncPendingSnapshot, type IToolResultResource } from '../../common/sessionDataService.js'; import type { Database } from '@vscode/sqlite3'; import { generateUuid } from '../../../../base/common/uuid.js'; @@ -1018,7 +1018,7 @@ suite('SessionDatabase', () => { tables: await db.getAllTables(), records: await db.getPersistedTurns(), }, { - tables: ['catalog_sync_snapshot', 'chat_drafts', 'file_edits', 'local_turns', 'reviewed_files', 'session_metadata', 'terminal_outputs', 'tool_result_resources', 'turn_delegation', 'turn_usage', 'turn_workspace_transition', 'turns'], + tables: ['assistant_response_parts', 'catalog_sync_snapshot', 'chat_drafts', 'file_edits', 'local_turns', 'reasoning_timing', 'reviewed_files', 'session_metadata', 'terminal_outputs', 'tool_result_resources', 'turn_delegation', 'turn_usage', 'turn_workspace_transition', 'turns'], records: [{ kind: 'local', turnId: 'local-1', chatUri: 'chat', anchorTurnId: undefined, seq: 1, payload: '{"id":"local-1"}' }], }); }); @@ -1122,6 +1122,54 @@ suite('SessionDatabase', () => { }); }); + suite('reasoning response parts', () => { + test('reads submitted writes and preserves a recorded zero', async () => { + db = disposables.add(await SessionDatabase.open(':memory:')); + const part: ReasoningResponsePart = { kind: ResponsePartKind.Reasoning, id: 'run', content: 'Reasoning', startedAt: '1970-01-01T00:00:01.000Z', duration: 45_000 }; + const write = db.setAssistantResponseParts('turn-1', 'response-1', [part]); + const first = [...await db.getAssistantResponseParts()]; + await write; + await db.setAssistantResponseParts('turn-1', 'response-1', [{ ...part, duration: 0 }]); + + assert.deepStrictEqual({ first, updated: [...await db.getAssistantResponseParts()] }, { + first: [['response-1', [part]]], + updated: [['response-1', [{ ...part, duration: 0 }]]], + }); + }); + + test('fork remapping preserves timing and pruning removes it', async () => { + db = disposables.add(await SessionDatabase.open(':memory:')); + const part: ReasoningResponsePart = { kind: ResponsePartKind.Reasoning, id: 'run', content: 'Reasoning', startedAt: '1970-01-01T00:00:01.000Z', duration: 45_000 }; + await db.setAssistantResponseParts('old-1', 'response-1', [part]); + await db.setAssistantResponseParts('old-2', 'response-2', [part]); + await db.remapTurnIds(new Map([['old-1', 'new-1']])); + const forked = [...await db.getAssistantResponseParts()]; + await db.deleteTurn('new-1'); + + assert.deepStrictEqual({ forked, pruned: [...await db.getAssistantResponseParts()] }, { + forked: [['response-1', [part]]], pruned: [], + }); + }); + + test('rejects invalid reasoning timing', async () => { + db = disposables.add(await SessionDatabase.open(':memory:')); + await assert.rejects(db.setAssistantResponseParts('turn', 'response', [{ kind: ResponsePartKind.Reasoning, id: 'run', content: 'Reasoning', startedAt: 'invalid', duration: 1 }]), /Invalid assistant response parts/); + await assert.rejects(db.setAssistantResponseParts('turn', 'response', [{ kind: ResponsePartKind.Reasoning, id: 'run', content: 'Reasoning', duration: -1 }]), /Invalid assistant response parts/); + }); + + test('upgrades the aggregate timing schema without pretending its totals describe individual runs', async () => { + const legacy = await TestableSessionDatabase.open(':memory:', sessionDatabaseMigrations.filter(migration => migration.version <= 17)); + await legacy.createTurn('turn'); + await legacy.setTurnEventId('turn', 'native-turn'); + await legacy.runRaw(`INSERT INTO reasoning_timing VALUES ('response', 'turn', '1970-01-01T00:00:01.000Z', 17000)`); + db = disposables.add(await TestableSessionDatabase.fromDb(await legacy.ejectDb())); + + assert.deepStrictEqual({ parts: [...await db.getAssistantResponseParts()], nativeTurn: await db.getTurnEventId('turn') }, { + parts: [], nativeTurn: 'native-turn', + }); + }); + }); + // ---- Turn usage ------------------------------------------------------ suite('turn usage', () => { @@ -1997,7 +2045,7 @@ suite('SessionDatabase', () => { title: await db.getMetadata('customTitle'), snapshot: await db.getCatalogSyncSnapshot(), }, { - tables: ['catalog_sync_snapshot', 'chat_drafts', 'file_edits', 'local_turns', 'reviewed_files', 'session_metadata', 'terminal_outputs', 'tool_result_resources', 'turn_delegation', 'turn_usage', 'turn_workspace_transition', 'turns'], + tables: ['assistant_response_parts', 'catalog_sync_snapshot', 'chat_drafts', 'file_edits', 'local_turns', 'reasoning_timing', 'reviewed_files', 'session_metadata', 'terminal_outputs', 'tool_result_resources', 'turn_delegation', 'turn_usage', 'turn_workspace_transition', 'turns'], title: 'After upgrade', snapshot: snapshot(1), }); @@ -2024,7 +2072,7 @@ suite('SessionDatabase', () => { tables: await upgraded.getAllTables(), snapshot: await upgraded.getCatalogSyncSnapshot(), }, { - tables: ['catalog_sync_snapshot', 'chat_drafts', 'file_edits', 'local_turns', 'reviewed_files', 'session_metadata', 'terminal_outputs', 'tool_result_resources', 'turn_delegation', 'turn_usage', 'turn_workspace_transition', 'turns'], + tables: ['assistant_response_parts', 'catalog_sync_snapshot', 'chat_drafts', 'file_edits', 'local_turns', 'reasoning_timing', 'reviewed_files', 'session_metadata', 'terminal_outputs', 'tool_result_resources', 'turn_delegation', 'turn_usage', 'turn_workspace_transition', 'turns'], snapshot: snapshot(1), }); }); diff --git a/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/agentHostSessionHandler.ts b/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/agentHostSessionHandler.ts index 69c560b84cad82..9b4ee3ef044786 100644 --- a/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/agentHostSessionHandler.ts +++ b/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/agentHostSessionHandler.ts @@ -164,7 +164,7 @@ import { ICopilotHomeService } from '../../../../../services/environment/common/ import { toolDataToDefinition } from './agentHostToolUtils.js'; import { IAgentHostUntitledProvisionalSessionService } from './agentHostUntitledProvisionalSessionService.js'; import { IAgentHostImportConversation, IAgentHostImportConversationStore } from './agentHostImportConversationStore.js'; -import { activeTurnToProgress, appendToolOutput, BOOLEAN_TRUE_OPTION_ID, canOwnSubagentChat, chatUsageToSessionCost, completedToolCallToEditParts, completedToolCallToSerialized, containsAutomaticReplyAnswer, convertProtocolAnswers, createInputRequestCarousel, createInputRequestPlanReview, finalizeToolInvocation, formatTurnResponseDetails, getAgentHostActivityProgressId, getTerminalContent, getUrlInputRequestPresentation, isSubagentTool, makeAhpTerminalToolSessionId, messageAttachmentsToVariableData, messageToRequestOrigin, messageToRequestSource, messageToVariableData, parseAhpTerminalToolSessionId, rewriteAgentHostLinkTarget, shouldObserveSubagentChat, stringOrMarkdownToString, systemNotificationToChatPart, toolCallAuthenticationServer, toolCallStateToInvocation, toolCallStateToPreparedInvocation, toolCallStateToStreamingInvocation, turnsToHistory, turnToResponseDetails, turnToResultMetadata, updateRunningToolSpecificData, updateStreamingToolInvocation, usageInfoToAutoModeResolution, usageInfoToChatUsage, usageInfoToQuotas, type IAgentHostToolInvocationOptions, type ITurnModelInfo, type TurnModelLookup } from './stateToProgressAdapter.js'; +import { activeTurnToProgress, appendToolOutput, BOOLEAN_TRUE_OPTION_ID, canOwnSubagentChat, chatUsageToSessionCost, completedToolCallToEditParts, completedToolCallToSerialized, containsAutomaticReplyAnswer, convertProtocolAnswers, createInputRequestCarousel, createInputRequestPlanReview, finalizeToolInvocation, formatTurnResponseDetails, getAgentHostActivityProgressId, getTerminalContent, getUrlInputRequestPresentation, isSubagentTool, makeAhpTerminalToolSessionId, messageAttachmentsToVariableData, messageToRequestOrigin, messageToRequestSource, messageToVariableData, parseAhpTerminalToolSessionId, reasoningPartToThinking, rewriteAgentHostLinkTarget, shouldObserveSubagentChat, stringOrMarkdownToString, systemNotificationToChatPart, toolCallAuthenticationServer, toolCallStateToInvocation, toolCallStateToPreparedInvocation, toolCallStateToStreamingInvocation, turnsToHistory, turnToResponseDetails, turnToResultMetadata, updateRunningToolSpecificData, updateStreamingToolInvocation, usageInfoToAutoModeResolution, usageInfoToChatUsage, usageInfoToQuotas, type IAgentHostToolInvocationOptions, type ITurnModelInfo, type TurnModelLookup } from './stateToProgressAdapter.js'; import { COPILOT_HYDRA_FUSION_MODEL_NAMES, isCopilotHydraFusionModelId } from '../../../../../../platform/agentHost/common/copilotCliConfig.js'; import { getFusionTierLabel } from '../../widget/input/modelPicker/modelPickerPresentation.js'; import { autoAuthenticateMcpServer, agentHostMcpServerId, modelRequiresAgentAuthentication } from './agentHostAuth.js'; @@ -4663,14 +4663,20 @@ export class AgentHostSessionHandler extends Disposable implements IChatSessionC ): void { const partId = part$.get().id; let lastEmitted = opts.seedEmittedLengths?.get(partId) ?? 0; + const initial = lastEmitted > 0 ? reasoningPartToThinking(part$.get()) : undefined; + let lastStartedAt = initial?.reasoningStartedAt; + let lastDuration = initial?.reasoningDurationMs; store.add(autorun(reader => { - const content = part$.read(reader).content; - if (content.length <= lastEmitted) { + const part = part$.read(reader); + const progress = reasoningPartToThinking(part, part.content.substring(lastEmitted)); + if (!part.content || (part.content.length <= lastEmitted + && progress.reasoningStartedAt === lastStartedAt && progress.reasoningDurationMs === lastDuration)) { return; } - const delta = content.substring(lastEmitted); - lastEmitted = content.length; - opts.sink([{ kind: 'thinking', value: delta, id: partId }]); + lastEmitted = part.content.length; + lastStartedAt = progress.reasoningStartedAt; + lastDuration = progress.reasoningDurationMs; + opts.sink([progress]); })); } diff --git a/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/importLocalConversationToAgentSession.ts b/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/importLocalConversationToAgentSession.ts index 976f5a50016cbc..ac109ff7640679 100644 --- a/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/importLocalConversationToAgentSession.ts +++ b/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/importLocalConversationToAgentSession.ts @@ -179,7 +179,14 @@ function responsePartsFromRequest(request: IChatRequestModel): ResponsePart[] { } else if (part.kind === 'thinking') { const content = Array.isArray(part.value) ? part.value.join('') : (part.value ?? ''); if (content) { - responseParts.push({ kind: ResponsePartKind.Reasoning, id: generateUuid(), content }); + const startedAt = part.reasoningStartedAt === undefined ? undefined : new Date(part.reasoningStartedAt); + responseParts.push({ + kind: ResponsePartKind.Reasoning, + id: generateUuid(), + content, + ...(startedAt && Number.isFinite(startedAt.getTime()) ? { startedAt: startedAt.toISOString() } : {}), + ...(part.reasoningDurationMs !== undefined && Number.isFinite(part.reasoningDurationMs) && part.reasoningDurationMs >= 0 ? { duration: part.reasoningDurationMs } : {}), + }); } } else if (part.kind === 'inlineReference') { // A file/symbol chip interleaved with the response text; render it diff --git a/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/stateToProgressAdapter.ts b/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/stateToProgressAdapter.ts index 4609ad7572acd2..5548d443abad71 100644 --- a/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/stateToProgressAdapter.ts +++ b/src/vs/workbench/contrib/chat/browser/agentSessions/agentHost/stateToProgressAdapter.ts @@ -43,12 +43,12 @@ import { AGENT_HOST_SESSION_LINK_SCHEME, buildOpenSessionLinkUri, isCreateChatTo import { getAgentHostChatId } from '../../../../../../platform/agentHost/common/agentHostChatIdentity.js'; import { parsePartialToolInputForDisplay } from '../../../../../../platform/agentHost/common/partialToolInput.js'; import { AuthenticateTargetKind } from '../../../../../../platform/agentHost/common/state/sessionProtocol.js'; -import { MessageAttachmentKind, type FileEdit, type MessageAttachment, type ResponsePart, type StringOrMarkdown, type TextRange } from '../../../../../../platform/agentHost/common/state/protocol/state.js'; +import { MessageAttachmentKind, type FileEdit, type MessageAttachment, type ReasoningResponsePart, type ResponsePart, type StringOrMarkdown, type TextRange } from '../../../../../../platform/agentHost/common/state/protocol/state.js'; import { normalizeFileEdit } from '../../../../../../platform/agentHost/common/fileEditDiff.js'; import { AgentSession } from '../../../../../../platform/agentHost/common/agentService.js'; import product from '../../../../../../platform/product/common/product.js'; import { ConfigureAutomationToolReferenceName } from '../../../common/automations/automationService.js'; -import { formatCopilotCreditsLabel, getSubagentIsActive, ElicitationState, type ChatExternalEditKind, type ChatMcpAppData, type IChatAgentFeedbackReviewConfirmationData, type IChatAutomationConfiguredData, type IChatAutoModeResolutionPart, type IChatExternalEdit, type IChatGeneratedImageData, type IChatMcpAuthenticationRequiredServer, type IChatModifiedFilesConfirmationData, type IChatProgress, type IChatQuestion, type IChatQuestionAnswerValue, type IChatQuestionAnswers, type IChatResponseErrorDetails, type IChatSearchToolInvocationData, type IChatSessionTargetData, type IChatSubagentToolInvocationData, type IChatTerminalToolInvocationData, type IChatToolInputInvocationData, type IChatToolInvocationSerialized, type IChatUsage, type IChatUsagePromptTokenDetail, ToolConfirmKind, AgentFeedbackReviewCommandId } from '../../../common/chatService/chatService.js'; +import { formatCopilotCreditsLabel, getSubagentIsActive, ElicitationState, type ChatExternalEditKind, type ChatMcpAppData, type IChatAgentFeedbackReviewConfirmationData, type IChatAutomationConfiguredData, type IChatAutoModeResolutionPart, type IChatExternalEdit, type IChatGeneratedImageData, type IChatMcpAuthenticationRequiredServer, type IChatModifiedFilesConfirmationData, type IChatProgress, type IChatQuestion, type IChatQuestionAnswerValue, type IChatQuestionAnswers, type IChatResponseErrorDetails, type IChatSearchToolInvocationData, type IChatSessionTargetData, type IChatSubagentToolInvocationData, type IChatTerminalToolInvocationData, type IChatThinkingPart, type IChatToolInputInvocationData, type IChatToolInvocationSerialized, type IChatUsage, type IChatUsagePromptTokenDetail, ToolConfirmKind, AgentFeedbackReviewCommandId } from '../../../common/chatService/chatService.js'; import { isTerminalCommandPrompt, type IChatSessionHistoryItem } from '../../../common/chatSessionsService.js'; import { type IQuotaSnapshot, type IRateLimitSnapshot } from '../../../../../services/chat/common/chatEntitlementService.js'; import { ChatToolInvocation } from '../../../common/model/chatProgressTypes/chatToolInvocation.js'; @@ -1303,7 +1303,7 @@ export function turnsToHistory(backendSession: URI, turns: readonly Turn[], part } case ResponsePartKind.Reasoning: if (rp.content) { - parts.push({ kind: 'thinking', value: rp.content, id: rp.id }); + parts.push(reasoningPartToThinking(rp)); } break; case ResponsePartKind.SystemNotification: @@ -1693,6 +1693,18 @@ function textRangeToIRange(range: TextRange): IRange { }; } +export function reasoningPartToThinking(part: ReasoningResponsePart, value = part.content): IChatThinkingPart { + const startedAt = part.startedAt === undefined ? undefined : Date.parse(part.startedAt); + return { + kind: 'thinking', + id: part.id, + value, + reasoningTimingSource: 'provider', + ...(startedAt !== undefined && Number.isFinite(startedAt) ? { reasoningStartedAt: startedAt } : {}), + ...(typeof part.duration === 'number' && Number.isFinite(part.duration) && part.duration >= 0 ? { reasoningDurationMs: part.duration } : {}), + }; +} + /** * Converts an active (in-progress) turn's accumulated state into progress * items suitable for replaying into the chat UI when reconnecting to a @@ -1718,7 +1730,7 @@ export function activeTurnToProgress(sessionResource: URI, activeTurn: ActiveTur break; case ResponsePartKind.Reasoning: if (rp.content) { - parts.push({ kind: 'thinking', value: rp.content, id: rp.id }); + parts.push(reasoningPartToThinking(rp)); } break; case ResponsePartKind.ToolCall: { diff --git a/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/chatThinkingContentPart.ts b/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/chatThinkingContentPart.ts index 2f2f855e96078f..1769f6299fe056 100644 --- a/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/chatThinkingContentPart.ts +++ b/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/chatThinkingContentPart.ts @@ -48,6 +48,7 @@ import { URI } from '../../../../../../base/common/uri.js'; import { IUriIdentityService } from '../../../../../../platform/uriIdentity/common/uriIdentity.js'; import { getToolGroupSummary } from './chatToolGroupSummary.js'; import { ChatActivityLabelTransition } from './chatActivityLabelTransition.js'; +import { formatElapsedTime } from '../../../common/chatProgressFormatting.js'; // Context key id mirrored from `vs/sessions/common/contextkeys` (`IsPhoneLayoutContext`). @@ -357,8 +358,16 @@ export function buildPhrasePool(defaults: string[], configurationService: IConfi return [...defaults]; } -function getFinishedThinkingTitle(): string { - return localize('chat.thinking.finishedThinking', "Finished thinking"); +function getFinishedThinkingTitle(parts: readonly IChatThinkingPart[]): string { + const runs = parts.filter(part => extractTextFromPart(part).trim()); + const duration = runs.length === 1 ? runs[0].reasoningDurationMs : undefined; + return duration !== undefined && Number.isFinite(duration) && duration >= 0 + ? getReasoningDurationLabel(duration) + : localize('chat.thinking.finishedThinking', "Finished thinking"); +} + +function getReasoningDurationLabel(duration: number): string { + return localize('chat.thinking.thoughtFor', "Thought for {0}", formatElapsedTime(duration)); } export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implements IChatContentPart { @@ -400,6 +409,8 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem private textContainer!: HTMLElement; private readonly _markdownResult = this._register(new MutableDisposable()); private readonly renderedThinkingHeaders = new Map(); + private readonly renderedThinkingParts = new Map(); + private readonly reasoningDurationSnapshots = new Map(); private summaryRowItems: HTMLElement[] = []; private summaryRowResults: (IRenderedMarkdown | undefined)[] = []; private summaryRowTexts: string[] = []; @@ -505,7 +516,7 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem const extractedTitle = extractTitleFromThinkingContent(initialText) ?? localize('chat.thinking.header.initial', 'Thinking'); const initialTitle = streamingCompleted && !context.isToolChain - ? getFinishedThinkingTitle() + ? getFinishedThinkingTitle([content]) : context.suppressProgressShimmer && !context.isToolChain ? localize('chat.thinking.header.initial', 'Thinking') : extractedTitle; @@ -1163,6 +1174,7 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem } const cleanedContent = content.trim(); if (!cleanedContent) { + this.renderedThinkingParts.delete(this.textContainer); this._markdownResult.clear(); this.clearSummaryRows(); if (this.textContainer) { @@ -1170,6 +1182,14 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem } return; } + if (this.textContainer) { + const rendered = this.renderedThinkingParts.get(this.textContainer); + if (rendered) { + rendered.part = this.content; + } else { + this.renderedThinkingParts.set(this.textContainer, { part: this.content }); + } + } const headers = getThinkingHeaders(cleanedContent); const summaryRows = splitReasoningSummaryRows(cleanedContent, false, headers); @@ -1413,6 +1433,14 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem return this.containsReasoning; } + public hasReasoningTiming(): boolean { + return this.allThinkingParts.some(part => part.reasoningStartedAt !== undefined || part.reasoningDurationMs !== undefined); + } + + public hasActiveReasoningTiming(): boolean { + return this.content.reasoningStartedAt !== undefined && this.content.reasoningDurationMs === undefined; + } + public hasGroupedItems(): boolean { return this.containsGroupedItems; } @@ -1477,6 +1505,7 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem this.showFinalizedTitle(title); } } + this.updateReasoningDurationLabels(); this.updateToolChainVisibility(); if (this.isVerboseToolChain) { return; @@ -1607,6 +1636,31 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem this.setExpanded(true); } + public updateReasoningTiming(content: IChatThinkingPart): void { + const duration = content.reasoningDurationMs; + const key = content.id ?? content; + if (duration === undefined || Object.is(this.reasoningDurationSnapshots.get(key), duration)) { + return; + } + let matched = false; + for (const part of this.allThinkingParts) { + const source = this.thinkingPartSources?.get(part) ?? part; + if (source !== content && (content.id === undefined || source.id !== content.id)) { + continue; + } + matched = true; + part.reasoningDurationMs = source.reasoningDurationMs = duration; + if (content.reasoningStartedAt !== undefined) { + part.reasoningStartedAt = source.reasoningStartedAt = content.reasoningStartedAt; + } + } + if (matched) { + this.reasoningDurationSnapshots.set(key, duration); + this.updateDropdownClickability(); + this._onDidChangeHeight.fire(); + } + } + public updateThinking(content: IChatThinkingPart): void { // If disposed, ignore late updates coming from renderer diffing if (this._store.isDisposed) { @@ -1629,6 +1683,10 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem this.allThinkingParts[index] = content; } } + const rendered = this.renderedThinkingParts.get(this.textContainer); + if (rendered) { + rendered.part = content; + } this.content = content; // Update any pending lazy thinking item with matching ID so that @@ -1646,6 +1704,7 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem this.thinkingHeadersByPart.delete(content); const needsInitialRender = this.textContainer ? !this.textContainer.hasChildNodes() : this.isPersistentReasoning || this.isConversation; if (next === this.currentThinkingValue && !needsInitialRender) { + this.updateDropdownClickability(); return; } const previousValue = this.currentThinkingValue; @@ -1942,7 +2001,7 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem private getFallbackTitle(): string { if (!this.isToolChain) { - return getFinishedThinkingTitle(); + return getFinishedThinkingTitle([...new Set(this.allThinkingParts.map(part => this.thinkingPartSources?.get(part) ?? part))]); } const visibleItemCount = this.appendedItemCount - this.hiddenToolCallIds.size; @@ -1960,6 +2019,39 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem : localize('chat.thinking.finished', 'Finished Working'); } + private updateReasoningDurationLabels(): void { + if (!this.renderedThinkingParts.size) { + return; + } + const sources = new Set([...this.renderedThinkingParts.values()].map(({ part }) => this.thinkingPartSources?.get(part) ?? part)); + const shown = new Set(); + for (const [container, rendered] of this.renderedThinkingParts) { + const part = rendered.part; + const source = this.thinkingPartSources?.get(part) ?? part; + const duration = source.reasoningDurationMs; + let label = rendered.label; + if (duration === undefined || !Number.isFinite(duration) || duration < 0 || shown.has(source)) { + label?.remove(); + continue; + } + shown.add(source); + const text = getReasoningDurationLabel(duration); + if (sources.size === 1 && this.currentTitle === text) { + label?.remove(); + continue; + } + if (!label) { + label = rendered.label = $('.chat-thinking-run-duration'); + } + if (label.parentElement !== container) { + container.prepend(label); + } + if (label.textContent !== text) { + label.textContent = text; + } + } + } + private setFallbackTitle(): void { const finalLabel = this.getFallbackTitle(); this.currentTitle = finalLabel; @@ -1984,6 +2076,7 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem /** Shows a finished section's title, which a conversation section wipes in after its last activity. */ private showFinalizedTitle(title: string): void { + this.updateReasoningDurationLabels(); if (this.isConversation) { this.showConversationTitle({ title, key: conversationFinishedKey, finished: true }, true); } else { @@ -2832,6 +2925,10 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem } hasSameContent(other: IChatRendererContent, _followingContent: IChatRendererContent[], _element: ChatTreeItem): boolean { + if (other.kind === 'thinking' && other.id === this.content.id && this.hasReasoningTiming() + && (extractTextFromPart(other) !== this.currentThinkingValue || (this.fallbackTitle !== undefined && this.getFallbackTitle() !== this.fallbackTitle))) { + return false; + } // Persistent tool chains and reasoning are separate sections, but a conversation section holds both. if (this.context.suppressProgressShimmer && (other.kind === 'working' || (!this.isConversation && this.isToolChain !== (other.kind !== 'thinking')))) { return false; @@ -2859,6 +2956,8 @@ export class ChatThinkingContentPart extends ChatThinkingStyleContentPart implem } override dispose(): void { + this.reasoningDurationSnapshots.clear(); + this.renderedThinkingParts.clear(); this.isActive = false; this.thinkingPartSources = undefined; if (this.workingSpinnerElement) { diff --git a/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/media/chatThinkingContent.css b/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/media/chatThinkingContent.css index 0942f4d041944d..47e86d7cbe7c04 100644 --- a/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/media/chatThinkingContent.css +++ b/src/vs/workbench/contrib/chat/browser/widget/chatContentParts/media/chatThinkingContent.css @@ -173,6 +173,11 @@ } } +.interactive-session .chat-thinking-box .chat-thinking-run-duration { + color: var(--vscode-descriptionForeground); + margin-bottom: var(--vscode-spacing-size40); +} + /* Lay a conversation's reasoning on its tool rows' line grid: the row keeps their body size, so its icon and rails match theirs, and centers its smaller text on that line. */ .interactive-session .interactive-response.chat-persistent-progress .value .chat-thinking-box.chat-thinking-conversation .chat-used-context-list.chat-thinking-collapsible > .chat-thinking-item.markdown-content { diff --git a/src/vs/workbench/contrib/chat/browser/widget/chatListRenderer.ts b/src/vs/workbench/contrib/chat/browser/widget/chatListRenderer.ts index 633c319df9c741..32340e94ae135b 100644 --- a/src/vs/workbench/contrib/chat/browser/widget/chatListRenderer.ts +++ b/src/vs/workbench/contrib/chat/browser/widget/chatListRenderer.ts @@ -655,6 +655,15 @@ export function shouldCreateGroupedThinkingPart(collapsedToolsMode: CollapsedToo return collapsedToolsMode === CollapsedToolsDisplayMode.Always || separatedFromReasoning; } +function isTimedThinkingPart(part: IChatRendererContent | undefined): part is IChatThinkingPart { + return part?.kind === 'thinking' && (part.reasoningStartedAt !== undefined || part.reasoningDurationMs !== undefined); +} + +function isReasoningTimingBoundary(part: IChatRendererContent | undefined): boolean { + return !!part && !isNestedSubagentContent(part) + && (part.kind === 'markdownContent' || part.kind === 'toolInvocation' || part.kind === 'toolInvocationSerialized'); +} + export function shouldShowFileChangesSummaryForSettings(isComplete: boolean, isLocalSession: boolean, showFileChanges: boolean): boolean { return isComplete && isLocalSession && showFileChanges; } @@ -4452,6 +4461,9 @@ export class ChatListItemRenderer extends Disposable implements ITreeRenderer part.kind === 'thinking' && part.id === progress.id); + const part = this._responseParts[index]; + const crossedBoundary = this._responseParts.slice(index + 1).some(part => !isNestedSubagentResponsePart(part) + && (part.kind === 'markdownContent' || part.kind === 'toolInvocation' || part.kind === 'toolInvocationSerialized')); + if (part?.kind === 'thinking' && (!currText || !crossedBoundary)) { + if (currText) { + const previous = Array.isArray(part.value) ? part.value.join('') : (part.value ?? ''); + this._responseParts[index] = { ...part, ...timing, value: appendMarkdownString(new MarkdownString(previous), new MarkdownString(currText)).value }; + } else { + Object.assign(part, timing); + } + this._contentChanged(quiet); + return; + } + } + if (!currText && progress.id === undefined && !hasTiming && !hasProviderTiming) { + const lastOutput = this._responseParts.findLast(part => !isNestedSubagentResponsePart(part) + && (part.kind === 'thinking' || part.kind === 'markdownContent' || part.kind === 'toolInvocation' || part.kind === 'toolInvocationSerialized')); + if (lastOutput?.kind === 'thinking' && (lastOutput.reasoningTimingSource === 'provider' || lastOutput.reasoningStartedAt !== undefined || lastOutput.reasoningDurationMs !== undefined)) { + return; + } + } // tries to split thinking chunks if it is an array. only while certain models give us array chunks. // Nested subagent parts render inside their parent card and must not split parent reasoning. @@ -1066,11 +1100,14 @@ export class Response extends AbstractResponse implements IDisposable { const lastText = lastResponsePart && lastResponsePart.kind === 'thinking' ? (Array.isArray(lastResponsePart.value) ? lastResponsePart.value.join('') : (lastResponsePart.value || '')) : ''; - const currText = Array.isArray(progress.value) ? progress.value.join('') : (progress.value || ''); + const differentId = lastResponsePart?.kind === 'thinking' && progress.id !== undefined && lastResponsePart.id !== undefined && progress.id !== lastResponsePart.id; + if (differentId) { + this.finalizeReasoningDuration(); + } const isEmpty = (s: string) => s.length === 0; if (isEmpty(currText)) { this.finalizeReasoningDuration(); - } else if (!this._activeReasoning && !restored) { + } else if (!this._activeReasoning && !restored && !hasTiming && !hasProviderTiming && !(lastResponsePart?.kind === 'thinking' && !differentId && lastResponsePart.reasoningTimingSource === 'provider')) { // Replayed history keeps its recorded timing; this clock only measures live reasoning. this._activeReasoning = { part: progress, startedAt: Date.now() }; } @@ -1080,16 +1117,18 @@ export class Response extends AbstractResponse implements IDisposable { || lastResponsePart.kind !== 'thinking' || isEmpty(currText) || isEmpty(lastText) + || differentId || !canMergeMarkdownStrings(new MarkdownString(lastText), new MarkdownString(currText))) { this._responseParts.push(progress); } else { const idx = this._responseParts.indexOf(lastResponsePart); const mergedPart: IChatThinkingPart = { ...lastResponsePart, + ...timing, value: appendMarkdownString(new MarkdownString(lastText), new MarkdownString(currText)).value }; this._responseParts[idx] = mergedPart; - if (this._activeReasoning?.part === lastResponsePart) { + if (this._activeReasoning?.part === lastResponsePart || this._activeReasoning?.part === progress) { this._activeReasoning.part = mergedPart; } } diff --git a/src/vs/workbench/contrib/chat/test/browser/agentSessions/agentHostChatContribution.test.ts b/src/vs/workbench/contrib/chat/test/browser/agentSessions/agentHostChatContribution.test.ts index 8f26c266c6bc3d..6255585f93a687 100644 --- a/src/vs/workbench/contrib/chat/test/browser/agentSessions/agentHostChatContribution.test.ts +++ b/src/vs/workbench/contrib/chat/test/browser/agentSessions/agentHostChatContribution.test.ts @@ -23,7 +23,7 @@ import { getSubagentEditorResource } from '../../../browser/widget/chatContentPa import { URI } from '../../../../../../base/common/uri.js'; import { IAgentHostConnectionsService } from '../../../../../../platform/agentHost/common/agentHostConnectionsService.js'; import { AgentHostConnectionsService } from '../../../../../../platform/agentHost/browser/agentHostConnectionsService.js'; -import { autorun, constObservable, derived, ISettableObservable, observableValue, type IObservable } from '../../../../../../base/common/observable.js'; +import { autorun, constObservable, derived, ISettableObservable, observableValue, waitForState, type IObservable } from '../../../../../../base/common/observable.js'; import { mock, upcastPartial } from '../../../../../../base/test/common/mock.js'; import { ensureNoDisposablesAreLeakedInTestSuite } from '../../../../../../base/test/common/utils.js'; import { runWithFakedTimers } from '../../../../../../base/test/common/timeTravelScheduler.js'; @@ -169,7 +169,7 @@ import { ChatQuestionCarouselData } from '../../../common/model/chatProgressType import { ChatPlanReviewData } from '../../../common/model/chatProgressTypes/chatPlanReviewData.js'; import { ChatElicitationRequestPart } from '../../../common/model/chatProgressTypes/chatElicitationRequestPart.js'; import { ChatToolInvocation } from '../../../common/model/chatProgressTypes/chatToolInvocation.js'; -import { ChatModel, ChatResponseModel, IntendedModelSlot, reviveSerializableInputState, type ChatRequestModel, type IChatModel, type IChatModelInputState, type IChatPendingRequest, type IChatRequestModel, type IChatResponseModel, type IInputModel } from '../../../common/model/chatModel.js'; +import { ChatModel, ChatResponseModel, IntendedModelSlot, Response, reviveSerializableInputState, type ChatRequestModel, type IChatModel, type IChatModelInputState, type IChatPendingRequest, type IChatRequestModel, type IChatResponseModel, type IInputModel } from '../../../common/model/chatModel.js'; import { ModelSelectionReason } from '../../../common/modelSelection.js'; import { convertBufferToScreenshotVariable } from '../../../browser/attachments/chatScreenshotContext.js'; import { AgentHostCompletionReferenceKind, ChatPasteAttachmentMetadata, createChatReferenceVariableEntry, isChatReferenceVariableEntry, toAgentHostCompletionVariableEntry, type IChatRequestVariableEntry } from '../../../common/attachments/chatVariableEntries.js'; @@ -18444,6 +18444,86 @@ suite('AgentHostChatContribution', () => { assert.deepStrictEqual(session.progressObs?.get(), []); }); + test('receives timing-only reasoning updates after reconnect on an opaque advertised chat', async () => { + const { sessionHandler, agentHostService } = createContribution(disposables, { backendSessionScheme: 'unused-allocation-scheme' }); + const sessionUri = URI.parse('ahp-session:/opaque-reasoning-session'); + const chatUri = 'ahp-chat:/host-chosen-reasoning-chat'; + const state = makeSessionStateWithActiveTurn(sessionUri.toString()); + agentHostService.seedSessionMetadata(sessionUri, 'copilot'); + agentHostService.sessionStates.set(sessionUri.toString(), { + ...state, + defaultChat: chatUri, + chats: [{ resource: chatUri, title: state.title, status: SessionStatus.InProgress, modifiedAt: '2025-01-01T00:00:00.000Z', origin: { kind: ChatOriginKind.User } }], + activeTurn: { + ...state.activeTurn!, + responseParts: [{ kind: ResponsePartKind.Reasoning, id: 'reasoning', content: 'Already received', startedAt: '1970-01-01T00:00:01.000Z' }], + }, + }); + const session = await sessionHandler.provideChatSessionContent(URI.parse('agent-host-copilot:/opaque-reasoning-session'), CancellationToken.None); + disposables.add(toDisposable(() => session.dispose())); + assert.ok(session.isCompleteObs); + const completed = waitForState(session.isCompleteObs, complete => complete); + const action = { type: ActionType.ChatReasoning as const, turnId: 'turn-active', partId: 'reasoning', content: '', duration: 45_000 }; + agentHostService.fireAction({ channel: chatUri, action, serverSeq: 100, origin: undefined }); + agentHostService.fireAction({ channel: chatUri, action, serverSeq: 101, origin: undefined }); + agentHostService.fireAction({ channel: chatUri, action: { type: ActionType.ChatTurnComplete, turnId: 'turn-active', duration: 50_000 }, serverSeq: 102, origin: undefined }); + await completed; + + assert.deepStrictEqual({ + parts: session.progressObs?.get().filter(part => part.kind === 'thinking'), + complete: session.isCompleteObs?.get(), + }, { + parts: [ + { kind: 'thinking', id: 'reasoning', value: 'Already received', reasoningTimingSource: 'provider', reasoningStartedAt: 1000 }, + { kind: 'thinking', id: 'reasoning', value: '', reasoningTimingSource: 'provider', reasoningStartedAt: 1000, reasoningDurationMs: 45_000 }, + ], + complete: true, + }); + }); + + test('untimed reasoning remains producer-owned through reconnect and continued live output', async () => { + const { sessionHandler, agentHostService } = createContribution(disposables, { backendSessionScheme: 'unused-allocation-scheme' }); + const backend = URI.parse('ahp-session:/untimed-reconnect'); + const chat = 'ahp-chat:/opaque-untimed-chat'; + const state = makeSessionStateWithActiveTurn(backend.toString()); + agentHostService.seedSessionMetadata(backend, 'copilot'); + agentHostService.sessionStates.set(backend.toString(), { + ...state, + defaultChat: chat, + chats: [{ resource: chat, title: state.title, status: SessionStatus.InProgress, modifiedAt: '2025-01-01T00:00:00.000Z', origin: { kind: ChatOriginKind.User } }], + activeTurn: { ...state.activeTurn!, responseParts: [{ kind: ResponsePartKind.Reasoning, id: 'reasoning', content: 'Restored prefix' }] }, + }); + const session = await sessionHandler.provideChatSessionContent(URI.parse('agent-host-copilot:/untimed-reconnect'), CancellationToken.None); + disposables.add(session); + const response = disposables.add(new Response([])); + let consumed = 0; + const consume = (restored: boolean) => { + const parts = session.progressObs?.get() ?? []; + for (const part of parts.slice(consumed)) { + if (part.kind === 'thinking' || part.kind === 'markdownContent') { + response.updateContent(part, false, restored); + } + } + consumed = parts.length; + }; + consume(true); + const clock = sinon.useFakeTimers({ now: 900_000, toFake: ['Date'] }); + try { + agentHostService.fireAction({ channel: chat, action: { type: ActionType.ChatReasoning, turnId: 'turn-active', partId: 'reasoning', content: ' continued' }, serverSeq: 100, origin: undefined }); + consume(false); + clock.tick(5000); + agentHostService.fireAction({ channel: chat, action: { type: ActionType.ChatResponsePart, turnId: 'turn-active', part: { kind: ResponsePartKind.Markdown, id: 'answer', content: 'Answer' } }, serverSeq: 101, origin: undefined }); + consume(false); + response.finalizeReasoningDuration(); + + assert.deepStrictEqual(JSON.parse(JSON.stringify(response.value.filter(part => part.kind === 'thinking'))), [ + { kind: 'thinking', id: 'reasoning', value: 'Restored prefix continued', reasoningTimingSource: 'provider' }, + ]); + } finally { + clock.restore(); + } + }); + test('includes reasoning in initial progress', async () => { const { sessionHandler, agentHostService } = createContribution(disposables); diff --git a/src/vs/workbench/contrib/chat/test/browser/agentSessions/importLocalConversationToAgentSession.test.ts b/src/vs/workbench/contrib/chat/test/browser/agentSessions/importLocalConversationToAgentSession.test.ts index 6d1b4dbd60d557..5ba327a2aecbfe 100644 --- a/src/vs/workbench/contrib/chat/test/browser/agentSessions/importLocalConversationToAgentSession.test.ts +++ b/src/vs/workbench/contrib/chat/test/browser/agentSessions/importLocalConversationToAgentSession.test.ts @@ -86,6 +86,21 @@ suite('importedTurnsFromChatModel', () => { })); } + test('preserves local reasoning timing when importing into an agent session', () => { + const turns = importedTurnsFromChatModel(model([request('q', response([ + { kind: 'thinking', value: 'Measured', reasoningStartedAt: 1000, reasoningDurationMs: 45_000 }, + { kind: 'thinking', value: 'Immediate', reasoningDurationMs: 0 }, + { kind: 'thinking', value: 'Older history' }, + ]))])); + + assert.deepStrictEqual(turns[0].responseParts.flatMap(part => part.kind === ResponsePartKind.Reasoning + ? [{ content: part.content, startedAt: part.startedAt, duration: part.duration }] : []), [ + { content: 'Measured', startedAt: '1970-01-01T00:00:01.000Z', duration: 45_000 }, + { content: 'Immediate', startedAt: undefined, duration: 0 }, + { content: 'Older history', startedAt: undefined, duration: undefined }, + ]); + }); + test('maps markdown, reasoning and inline references in stream order', () => { const result = project(model([request('q', response([ markdown('Found in '), diff --git a/src/vs/workbench/contrib/chat/test/browser/agentSessions/stateToProgressAdapter.test.ts b/src/vs/workbench/contrib/chat/test/browser/agentSessions/stateToProgressAdapter.test.ts index 59506e35128d94..7cb0212e9bb23f 100644 --- a/src/vs/workbench/contrib/chat/test/browser/agentSessions/stateToProgressAdapter.test.ts +++ b/src/vs/workbench/contrib/chat/test/browser/agentSessions/stateToProgressAdapter.test.ts @@ -1063,6 +1063,24 @@ suite('stateToProgressAdapter', () => { assert.strictEqual(thinking.id, 'r-1'); }); + test('restores producer reasoning timing without inventing timing for older hosts', () => { + const history = turnsToHistory(URI.parse('external:/opaque/session'), [createTurn({ + responseParts: [ + { kind: ResponsePartKind.Reasoning, id: 'timed', content: 'Measured', startedAt: '1970-01-01T00:00:01.000Z', duration: 45_000 }, + { kind: ResponsePartKind.Reasoning, id: 'zero', content: 'Immediate', duration: 0 }, + { kind: ResponsePartKind.Reasoning, id: 'unknown', content: 'Older host' }, + { kind: ResponsePartKind.Reasoning, id: 'invalid', content: 'Invalid metadata', startedAt: 'invalid', duration: -1 }, + ], + })], 'participant'); + + assert.deepStrictEqual(history[1].type === 'response' ? history[1].parts : undefined, [ + { kind: 'thinking', id: 'timed', value: 'Measured', reasoningTimingSource: 'provider', reasoningStartedAt: 1000, reasoningDurationMs: 45_000 }, + { kind: 'thinking', id: 'zero', value: 'Immediate', reasoningTimingSource: 'provider', reasoningDurationMs: 0 }, + { kind: 'thinking', id: 'unknown', value: 'Older host', reasoningTimingSource: 'provider' }, + { kind: 'thinking', id: 'invalid', value: 'Invalid metadata', reasoningTimingSource: 'provider' }, + ]); + }); + test('generic completed tool call in history includes input/output details', () => { const turn = createTurn({ responseParts: [{ @@ -4294,7 +4312,7 @@ suite('stateToProgressAdapter', () => { ]), undefined); assert.deepStrictEqual(result, [ - { kind: 'thinking', id: 'reasoning', value: 'Assessing final output steps' }, + { kind: 'thinking', id: 'reasoning', value: 'Assessing final output steps', reasoningTimingSource: 'provider' }, { kind: 'thinking', value: '' }, ]); }); @@ -4545,6 +4563,18 @@ suite('stateToProgressAdapter', () => { assert.strictEqual((result[0] as IChatThinkingPart).id, 'r-1'); }); + test('preserves completed and unfinished reasoning timing on reconnect', () => { + const result = activeTurnToProgress(URI.parse('external:/opaque/session'), createActiveTurnState([ + { kind: ResponsePartKind.Reasoning, id: 'completed', content: 'Already thought', startedAt: '1970-01-01T00:00:01.000Z', duration: 45_000 }, + { kind: ResponsePartKind.Reasoning, id: 'active', content: 'Still thinking', startedAt: '1970-01-01T00:01:00.000Z' }, + ]), 'remote-host'); + + assert.deepStrictEqual(result, [ + { kind: 'thinking', id: 'completed', value: 'Already thought', reasoningTimingSource: 'provider', reasoningStartedAt: 1000, reasoningDurationMs: 45_000 }, + { kind: 'thinking', id: 'active', value: 'Still thinking', reasoningTimingSource: 'provider', reasoningStartedAt: 60_000 }, + ]); + }); + test('reasoning comes before streamed text when ordered that way', () => { const result = activeTurnToProgress(URI.file('/'), createActiveTurnState([ { kind: ResponsePartKind.Reasoning, id: 'r-1', content: 'Hmm...' }, diff --git a/src/vs/workbench/contrib/chat/test/browser/widget/chatContentParts/chatThinkingContentPart.test.ts b/src/vs/workbench/contrib/chat/test/browser/widget/chatContentParts/chatThinkingContentPart.test.ts index 95e24b5fd54a88..1c166ce2052441 100644 --- a/src/vs/workbench/contrib/chat/test/browser/widget/chatContentParts/chatThinkingContentPart.test.ts +++ b/src/vs/workbench/contrib/chat/test/browser/widget/chatContentParts/chatThinkingContentPart.test.ts @@ -2086,7 +2086,7 @@ suite('ChatThinkingContentPart', () => { }); }); - test('does not use reasoning duration in the generic title', async () => { + test('shows individual run durations instead of a grouped total', async () => { const first = createThinkingPart('Consider how to update the progress renderer.', 'first'); first.reasoningStartedAt = 1000; first.reasoningDurationMs = 1200; @@ -2098,10 +2098,16 @@ suite('ChatThinkingContentPart', () => { part.finalizeTitleIfDefault(); await timeout(0); + part.expandContent(); - assert.deepStrictEqual({ title: snapshot(part).title, ariaLabel: snapshot(part).ariaLabel }, { + assert.deepStrictEqual({ + title: snapshot(part).title, + ariaLabel: snapshot(part).ariaLabel, + runs: Array.from(part.domNode.querySelectorAll('.chat-thinking-run-duration'), label => label.textContent), + }, { title: 'Finished thinking', ariaLabel: 'Finished thinking', + runs: ['Thought for 1s', 'Thought for 2s'], }); }); }); @@ -2374,7 +2380,7 @@ suite('ChatThinkingContentPart', () => { }); }); - test('finished sections use the same fallback with or without recorded timing', () => { + test('finished sections report only recorded reasoning time and not tool time', () => { type Case = { readonly reasoning: readonly { readonly startedAt?: number; readonly durationMs?: number; readonly text?: string }[]; readonly tools: readonly (readonly [startedAt?: number, completedAt?: number])[] }; const cases: Record = { shortReasoning: { reasoning: [{ startedAt: 1000, durationMs: 400 }], tools: [] }, @@ -2404,22 +2410,22 @@ suite('ChatThinkingContentPart', () => { })); assert.deepStrictEqual(titles, { - shortReasoning: 'Finished thinking', - reasoningWithoutStart: 'Finished thinking', + shortReasoning: 'Thought for 0s', + reasoningWithoutStart: 'Thought for 2s', textlessReasoning: 'Finished thinking', textlessReasoningAndTools: 'Finished thinking', toolsOnly: 'Finished thinking', - reasoningAndTools: 'Finished thinking', - reasoningWithoutStartAndTools: 'Finished thinking', - unfinishedTool: 'Finished thinking', + reasoningAndTools: 'Thought for 1s', + reasoningWithoutStartAndTools: 'Thought for 2s', + unfinishedTool: 'Thought for 0s', restoredReasoning: 'Finished thinking', restoredTools: 'Finished thinking', restoredReasoningThenLiveTool: 'Finished thinking', - liveReasoningThenRestoredTool: 'Finished thinking', + liveReasoningThenRestoredTool: 'Thought for 1s', }); }); - test('split array reasoning uses the same fallback regardless of timing', () => { + test('split array reasoning does not combine distinct source durations', () => { const cases: Record = { equalDurations: { parts: [ @@ -2458,7 +2464,7 @@ suite('ChatThinkingContentPart', () => { assert.deepStrictEqual(titles, Object.fromEntries(Object.entries(cases).map(([name, { title }]) => [name, title]))); }); - test('replacing a split reasoning fragment preserves the finished fallback', () => { + test('replacing a split reasoning fragment updates the recorded duration', () => { const source = { ...createThinkingPart(undefined, 'shared'), value: ['First', 'Second'], reasoningDurationMs: 1200 }; const first = { ...source, value: 'First' }; const part = createConversationSection(first); @@ -2468,8 +2474,8 @@ suite('ChatThinkingContentPart', () => { part.finalizeTitleIfDefault(); assert.deepStrictEqual({ title: snapshot(part).title, ariaLabel: snapshot(part).ariaLabel }, { - title: 'Finished thinking', - ariaLabel: 'Finished thinking', + title: 'Thought for 2s', + ariaLabel: 'Thought for 2s', }); }); @@ -2681,7 +2687,7 @@ suite('ChatThinkingContentPart', () => { assert.strictEqual(part.hasGroupedItems(), true); }); - test('shows Finished thinking in untitled finalized headers and accessible labels', () => { + test('shows recorded reasoning duration in finalized headers and accessible labels', () => { const content = createThinkingPart('Reviewed the implementation'); content.reasoningDurationMs = 1200; const part = store.add(instantiationService.createInstance( @@ -2705,14 +2711,14 @@ suite('ChatThinkingContentPart', () => { ariaLabel: button?.ariaLabel, }, { generatedTitle: undefined, - label: 'Finished thinking', - ariaLabel: 'Finished thinking', + label: 'Thought for 1s', + ariaLabel: 'Thought for 1s', }); }); - test('does not display persisted duration when reasoning content is rehydrated', () => { + test('displays Thought for 45s when reasoning content is rehydrated', () => { const content = createThinkingPart('Reviewed the implementation'); - content.reasoningDurationMs = 2300; + content.reasoningDurationMs = 45_000; const part = store.add(instantiationService.createInstance( ChatThinkingContentPart, content, @@ -2725,11 +2731,11 @@ suite('ChatThinkingContentPart', () => { disposables.add(toDisposable(() => part.domNode.remove())); part.finalizeTitleIfDefault(); - assert.strictEqual(part.domNode.querySelector('.monaco-button')?.textContent, 'Finished thinking'); + assert.strictEqual(part.domNode.querySelector('.monaco-button')?.textContent, 'Thought for 45s'); }); - test('uses Finished thinking for zero or unavailable reasoning duration', () => { - const titles = [undefined, 0].map(reasoningDurationMs => { + test('distinguishes zero reasoning duration from unavailable or invalid timing', () => { + const titles = [undefined, 0, 999, 1000, 83_000, -1, NaN, Infinity].map(reasoningDurationMs => { const content = createThinkingPart('Reviewed the implementation'); content.reasoningDurationMs = reasoningDurationMs; const part = store.add(instantiationService.createInstance( @@ -2743,7 +2749,7 @@ suite('ChatThinkingContentPart', () => { return part.domNode.querySelector('.monaco-button')?.textContent; }); - assert.deepStrictEqual(titles, ['Finished thinking', 'Finished thinking']); + assert.deepStrictEqual(titles, ['Finished thinking', 'Thought for 0s', 'Thought for 0s', 'Thought for 1s', 'Thought for 1m 23s', 'Finished thinking', 'Finished thinking', 'Finished thinking']); }); }); diff --git a/src/vs/workbench/contrib/chat/test/browser/widget/chatListRenderer.test.ts b/src/vs/workbench/contrib/chat/test/browser/widget/chatListRenderer.test.ts index 4ffd9f57e6c5fd..8cee23b13e968a 100644 --- a/src/vs/workbench/contrib/chat/test/browser/widget/chatListRenderer.test.ts +++ b/src/vs/workbench/contrib/chat/test/browser/widget/chatListRenderer.test.ts @@ -10312,6 +10312,124 @@ suite('ChatListRenderer', () => { renderer.renderElement(node, 0, template); }); + for (const value of ['Reasoning without a heading', ['First reasoning piece', 'Second reasoning piece']]) { + test(`late reasoning timing refreshes a finalized header and ARIA label (${typeof value})`, async () => { + const { model, request, renderer, template, node } = createPersistentProgressRenderer({ progressVerbosity: ChatProgressVerbosity.Compact }); + model.acceptResponseProgress(request, { kind: 'thinking', id: 'late-timing', value }, false, true); + model.acceptResponseProgress(request, { kind: 'markdownContent', content: new MarkdownString('The answer') }); + renderer.renderElement(node, 0, template); + await Promise.all(template.renderedParts?.flatMap(part => part instanceof ChatThinkingContentPart ? [part.getPendingCollapseAnimation()] : []) ?? []); + const section = template.value.querySelector('.chat-thinking-box'); + const button = section?.querySelector('.chat-used-context-label .monaco-button'); + const before = { title: button?.textContent, ariaLabel: button?.ariaLabel }; + + model.acceptResponseProgress(request, { kind: 'thinking', id: 'late-timing', value: '', reasoningDurationMs: 45_000 }); + renderer.renderElement(node, 0, template); + const after = { title: button?.textContent, ariaLabel: button?.ariaLabel }; + request.response?.complete(); + + assert.deepStrictEqual({ + before, + after, + preservesSection: template.value.querySelector('.chat-thinking-box') === section, + }, { + before: { title: 'Finished thinking', ariaLabel: 'Finished thinking' }, + after: { title: 'Thought for 45s', ariaLabel: 'Thought for 45s' }, + preservesSection: true, + }); + }); + } + + test('late reasoning timing refreshes an earlier run inside a finalized conversation group', async () => { + const { model, request, renderer, template, node } = createPersistentProgressRenderer({ progressVerbosity: ChatProgressVerbosity.Conversation }); + model.acceptResponseProgress(request, { kind: 'thinking', id: 'first', value: 'First run', reasoningTimingSource: 'provider' }, false, true); + const tool = new ChatToolInvocation( + { invocationMessage: 'Reading', pastTenseMessage: 'Read' }, + { id: 'read_file', displayName: 'Read file', modelDescription: 'Read file', source: ToolDataSource.Internal }, + 'between', undefined, {}, + ); + model.acceptResponseProgress(request, tool); + await tool.didExecuteTool(undefined); + model.acceptResponseProgress(request, { kind: 'thinking', id: 'second', value: 'Second run', reasoningTimingSource: 'provider', reasoningDurationMs: 12_000 }); + model.acceptResponseProgress(request, { kind: 'markdownContent', content: new MarkdownString('The answer') }); + renderer.renderElement(node, 0, template); + const section = template.renderedParts?.find(part => part instanceof ChatThinkingContentPart); + assert.ok(section instanceof ChatThinkingContentPart); + section.expandContent(); + const labels = () => Array.from(section.domNode.querySelectorAll('.chat-thinking-run-duration'), element => element.textContent); + const before = labels(); + + model.acceptResponseProgress(request, { kind: 'thinking', id: 'first', value: '', reasoningTimingSource: 'provider', reasoningDurationMs: 5000 }); + renderer.renderElement(node, 0, template); + const after = labels(); + request.response?.complete(); + + assert.deepStrictEqual({ before, after }, { before: ['Thought for 12s'], after: ['Thought for 5s', 'Thought for 12s'] }); + }); + + for (const progressVerbosity of [ChatProgressVerbosity.Compact, ChatProgressVerbosity.Verbose, ChatProgressVerbosity.Conversation]) { + for (const boundary of ['markdown', 'tool'] as const) { + test(`reasoning run durations survive reload independently (${progressVerbosity}, ${boundary})`, async () => { + const setup = createPersistentProgressRenderer({ chatMode: ChatModeKind.Agent, progressVerbosity }); + setup.configurationService.setUserConfiguration(ChatConfiguration.CollapseCompletedResponses, false); + const diagnostics: string[] = []; + const snapshot = async (current: ReturnType) => { + current.renderer.renderElement(current.node, 0, current.template); + if (current.response.renderData) { + await Event.toPromise(Event.filter(current.renderer.onDidChangeItemHeight, () => !current.response.renderData)); + } + const thinkingParts = [...new Set(current.template.renderedParts)].filter(part => part instanceof ChatThinkingContentPart); + await Promise.all(thinkingParts.map(part => part.getPendingCollapseAnimation())); + for (const part of thinkingParts) { + part.expandContent(); + } + diagnostics.push(JSON.stringify({ + pending: current.renderer.hasPendingProgressContent(current.response), + sections: thinkingParts.map(part => ({ active: part.getIsActive(), activeTiming: part.hasActiveReasoningTiming(), connected: part.domNode.isConnected, text: part.domNode.textContent })), + })); + return { + labels: Array.from(current.template.value.querySelectorAll('.chat-used-context-label .monaco-button, .chat-thinking-run-duration'), label => label.textContent?.trim()) + .filter(label => label?.startsWith('Thought for ')), + runs: current.request.response?.entireResponse.value.flatMap(part => part.kind === 'thinking' && part.value + ? [{ value: part.value, duration: part.reasoningDurationMs }] : []), + }; + }; + setup.model.acceptResponseProgress(setup.request, { kind: 'thinking', id: 'first', value: 'First run', reasoningStartedAt: 1000 }); + setup.renderer.renderElement(setup.node, 0, setup.template); + setup.model.acceptResponseProgress(setup.request, { kind: 'thinking', id: 'first', value: '', reasoningDurationMs: 5000 }); + if (boundary === 'markdown') { + setup.model.acceptResponseProgress(setup.request, { kind: 'markdownContent', content: new MarkdownString('Between') }); + } else { + const tool = new ChatToolInvocation( + { invocationMessage: 'Reading a file', pastTenseMessage: 'Read a file' }, + { id: 'read_file', displayName: 'Read file', modelDescription: 'Read file', source: ToolDataSource.Internal }, + 'tool', undefined, {}, + ); + setup.model.acceptResponseProgress(setup.request, tool); + await tool.didExecuteTool(undefined); + } + setup.model.acceptResponseProgress(setup.request, { kind: 'thinking', id: 'second', value: 'Second run', reasoningStartedAt: 26_000 }); + setup.renderer.renderElement(setup.node, 0, setup.template); + setup.model.acceptResponseProgress(setup.request, { kind: 'thinking', id: 'second', value: '', reasoningDurationMs: 12_000 }); + setup.model.acceptResponseProgress(setup.request, { kind: 'markdownContent', content: new MarkdownString('Done') }); + setup.request.response?.complete(); + const before = await snapshot(setup); + const value: unknown = revive(JSON.parse(JSON.stringify(setup.model.toJSON()))); + assert.ok(isSerializableSessionData(value)); + setup.disposables.dispose(); + + const restored = createPersistentProgressRenderer({ chatMode: ChatModeKind.Agent, progressVerbosity, initialData: { value, serializer: new ChatSessionOperationLog() } }); + restored.configurationService.setUserConfiguration(ChatConfiguration.CollapseCompletedResponses, false); + const expected = { + labels: ['Thought for 5s', 'Thought for 12s'], + runs: [{ value: 'First run', duration: 5000 }, { value: 'Second run', duration: 12_000 }], + }; + assert.deepStrictEqual({ before, after: await snapshot(restored) }, { before: expected, after: expected }, diagnostics.join('\n')); + restored.disposables.dispose(); + }); + } + } + test('conversation progress collapses reasoning and tool calls into one section with its extracted heading', async () => { const clock = sinon.useFakeTimers({ now: 1_000_000, toFake: ['Date'] }); try { @@ -14106,7 +14224,7 @@ suite('ChatListRenderer', () => { }); for (const values of [['First', 'Second'], ['', 'First', 'Second']]) { - test(`restored array reasoning preserves all text with the Finished thinking fallback (${JSON.stringify(values)})`, async () => { + test(`restored array reasoning preserves all text and its single-run duration (${JSON.stringify(values)})`, async () => { const seed = createPersistentProgressRenderer(); seed.model.acceptResponseProgress(seed.request, { kind: 'markdownContent', content: new MarkdownString('Done') }); seed.request.response!.complete(); @@ -14137,11 +14255,11 @@ suite('ChatListRenderer', () => { title: button?.textContent, first: text?.includes('First'), second: text?.includes('Second'), - }, { title: 'Finished thinking', first: true, second: true }); + }, { title: 'Thought for 1s', first: true, second: true }); }); } - test('array reasoning keeps the Finished thinking fallback when timing arrives later', () => runWithFakedTimers({ useFakeTimers: true, startTime: 1000 }, async () => { + test('array reasoning shows its single-run duration when timing arrives later', () => runWithFakedTimers({ useFakeTimers: true, startTime: 1000 }, async () => { const { disposables, model, request, renderer, template, node } = createPersistentProgressRenderer({ persistentProgress: ChatProgressAnimation.Off, thinkingStyle: ThinkingDisplayMode.Collapsed, @@ -14154,7 +14272,7 @@ suite('ChatListRenderer', () => { model.acceptResponseProgress(request, { kind: 'markdownContent', content: new MarkdownString('Done') }); request.response!.complete(); renderer.renderElement(node, 0, template); - assert.strictEqual(template.value.querySelector('.chat-thinking-box > .chat-used-context-label .monaco-button')?.textContent, 'Finished thinking'); + assert.strictEqual(template.value.querySelector('.chat-thinking-box > .chat-used-context-label .monaco-button')?.textContent, 'Thought for 2s'); } finally { disposables.dispose(); } diff --git a/src/vs/workbench/contrib/chat/test/common/model/chatModel.test.ts b/src/vs/workbench/contrib/chat/test/common/model/chatModel.test.ts index bc0296e35b2ca1..c0e4606cb49037 100644 --- a/src/vs/workbench/contrib/chat/test/common/model/chatModel.test.ts +++ b/src/vs/workbench/contrib/chat/test/common/model/chatModel.test.ts @@ -995,6 +995,105 @@ suite('ChatModel', () => { } }); + test('provider-owned reasoning stays untimed after reconnect while local providers retain measurement', () => { + const clock = sinon.useFakeTimers({ now: 900_000 }); + try { + const model = testDisposables.add(instantiationService.createInstance(ChatModel, undefined, { initialLocation: ChatAgentLocation.Chat, canUseTools: true })); + const request = model.addRequest({ text: 'Question', parts: [] }, { variables: [] }, 0); + model.acceptResponseProgress(request, { kind: 'thinking', id: 'remote', value: 'Restored', reasoningTimingSource: 'provider' }, false, true); + model.acceptResponseProgress(request, { kind: 'thinking', id: 'remote', value: ' continuation', reasoningTimingSource: 'provider' }); + clock.tick(5000); + model.acceptResponseProgress(request, { kind: 'markdownContent', content: new MarkdownString('Remote answer') }); + model.acceptResponseProgress(request, { kind: 'thinking', id: 'local', value: 'Local reasoning' }); + clock.tick(2000); + request.response?.complete(); + const restored = testDisposables.add(instantiationService.createInstance(ChatModel, { value: model.toJSON(), serializer: undefined! }, { initialLocation: ChatAgentLocation.Chat, canUseTools: true })); + + assert.deepStrictEqual(restored.getRequests()[0].response?.entireResponse.value.filter(part => part.kind === 'thinking'), [ + { kind: 'thinking', id: 'remote', value: 'Restored continuation', reasoningTimingSource: 'provider' }, + { kind: 'thinking', id: 'local', value: 'Local reasoning', reasoningStartedAt: 905_000, reasoningDurationMs: 2000 }, + ]); + } finally { + clock.restore(); + } + }); + + test('provider-owned timing accepts a late recorded zero without a client-clock fallback', () => { + const response = testDisposables.add(new Response([])); + response.updateContent({ kind: 'thinking', id: 'remote', value: 'Reasoning', reasoningTimingSource: 'provider' }); + response.updateContent({ kind: 'markdownContent', content: new MarkdownString('Answer') }); + response.updateContent({ kind: 'thinking', id: 'remote', value: '', reasoningTimingSource: 'provider', reasoningDurationMs: 0 }); + response.finalizeReasoningDuration(); + + assert.deepStrictEqual(response.value[0], { kind: 'thinking', id: 'remote', value: 'Reasoning', reasoningTimingSource: 'provider', reasoningDurationMs: 0 }); + }); + + test('applies timing-only reasoning updates without replaying text or measuring a remote clock', () => { + const clock = sinon.useFakeTimers({ now: 900_000 }); + try { + const response = testDisposables.add(new Response([])); + response.updateContent({ kind: 'thinking', id: 'reasoning', value: 'First', reasoningStartedAt: 1000 }); + response.updateContent({ kind: 'thinking', id: 'reasoning', value: ' thought', reasoningStartedAt: 1000 }); + const renderedPart = response.value[0]; + clock.tick(5000); + response.updateContent({ kind: 'markdownContent', content: new MarkdownString('Done') }); + response.updateContent({ kind: 'thinking', id: 'reasoning', value: '', reasoningDurationMs: 45_000 }); + response.finalizeReasoningDuration(); + + assert.deepStrictEqual({ parts: response.value, keepsRenderedPart: response.value[0] === renderedPart }, { + parts: [ + { kind: 'thinking', id: 'reasoning', value: 'First thought', reasoningStartedAt: 1000, reasoningDurationMs: 45_000 }, + { kind: 'markdownContent', content: new MarkdownString('Done') }, + ], + keepsRenderedPart: true, + }); + } finally { + clock.restore(); + } + }); + + test('managed reasoning remains one run across notifications and SDK completion markers', () => { + const response = testDisposables.add(new Response([])); + response.updateContent({ kind: 'thinking', id: 'run', value: 'First', reasoningStartedAt: 1000 }); + response.updateContent({ kind: 'systemNotification', content: new MarkdownString('Background work completed') }); + response.updateContent({ kind: 'thinking', value: '' }); + response.updateContent({ kind: 'thinking', id: 'run', value: 'Second', reasoningStartedAt: 1000 }); + response.updateContent({ kind: 'thinking', id: 'run', value: [''], reasoningDurationMs: 5000 }); + response.updateContent({ kind: 'markdownContent', content: new MarkdownString('Between') }); + response.updateContent({ kind: 'thinking', id: 'next', value: 'Next', reasoningStartedAt: 8000, reasoningDurationMs: 12_000 }); + + assert.deepStrictEqual(response.value, [ + { kind: 'thinking', id: 'run', value: 'FirstSecond', reasoningStartedAt: 1000, reasoningDurationMs: 5000 }, + { kind: 'systemNotification', content: new MarkdownString('Background work completed') }, + { kind: 'markdownContent', content: new MarkdownString('Between') }, + { kind: 'thinking', id: 'next', value: 'Next', reasoningStartedAt: 8000, reasoningDurationMs: 12_000 }, + ]); + }); + + test('keeps consecutive reasoning ids and zero durations distinct', () => { + const response = testDisposables.add(new Response([])); + response.updateContent({ kind: 'thinking', id: 'first', value: 'First', reasoningDurationMs: 45_000 }); + response.updateContent({ kind: 'thinking', id: 'second', value: 'Second', reasoningDurationMs: 0 }); + response.finalizeReasoningDuration(); + + assert.deepStrictEqual(response.value, [ + { kind: 'thinking', id: 'first', value: 'First', reasoningDurationMs: 45_000 }, + { kind: 'thinking', id: 'second', value: 'Second', reasoningDurationMs: 0 }, + ]); + }); + + test('recorded reasoning timing survives chat model serialization and restoration', () => { + const model = testDisposables.add(instantiationService.createInstance(ChatModel, undefined, { initialLocation: ChatAgentLocation.Chat, canUseTools: true })); + const request = model.addRequest({ text: 'hello', parts: [] }, { variables: [] }, 0); + model.acceptResponseProgress(request, { kind: 'thinking', id: 'reasoning', value: 'Working through it', reasoningStartedAt: 1000, reasoningDurationMs: 45_000 }); + request.response?.complete(); + const restored = testDisposables.add(instantiationService.createInstance(ChatModel, { value: model.toJSON(), serializer: undefined! }, { initialLocation: ChatAgentLocation.Chat, canUseTools: true })); + + assert.deepStrictEqual(restored.getRequests()[0].response?.entireResponse.value, [ + { kind: 'thinking', id: 'reasoning', value: 'Working through it', reasoningStartedAt: 1000, reasoningDurationMs: 45_000 }, + ]); + }); + test('leaves tool calls replayed from history untimed', async () => { const clock = sinon.useFakeTimers({ now: 9000 }); try {