Skip to content

Add trace logs around chat session opening#313853

Merged
rebornix merged 5 commits intomainfrom
rebornix/chat-session-trace-logs
May 2, 2026
Merged

Add trace logs around chat session opening#313853
rebornix merged 5 commits intomainfrom
rebornix/chat-session-trace-logs

Conversation

@rebornix
Copy link
Copy Markdown
Member

@rebornix rebornix commented May 2, 2026

Adds tracing logs to help diagnose chat session opening performance.

Instrumented call path:

  • SessionsManagementService.openChat / openSession
  • ChatWidgetService.openSession
  • ChatViewPane.loadSession
  • MainThreadChatSessions._provideChatSessionContent

Each entry logs a start and done total=Xms at trace level so timings can be correlated end-to-end when investigating slow open scenarios.

Adds tracing logs around openChat/openSession in SessionsManagementService,
ChatWidgetService.openSession, ChatViewPane.loadSession, and
MainThreadChatSessions._provideChatSessionContent to help diagnose
chat session opening performance.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Copilot AI review requested due to automatic review settings May 2, 2026 05:57
@github-actions
Copy link
Copy Markdown
Contributor

github-actions Bot commented May 2, 2026

Screenshot Changes

Base: d1bbbc1c Current: a3d00608

Changed (1)

agentSessionsViewer/WithMarkdownBadge/Dark
Before After
before after

blocks-ci screenshots changed

Replace the contents of test/componentFixtures/blocks-ci-screenshots.md with:

Updated blocks-ci-screenshots.md
<!-- auto-generated by CI — do not edit manually -->

#### editor/codeEditor/CodeEditor/Dark
![screenshot](https://hediet-screenshots.azurewebsites.net/images/cb32a3e854b5734fe5aaca2318f2e0a42ee821b05ea97883ea42c5ba95edb3c3)

#### editor/codeEditor/CodeEditor/Light
![screenshot](https://hediet-screenshots.azurewebsites.net/images/42624fbba5e0db7f32c224b5eb9c5dd3b08245697ae2e7d2a88be0d7c287129b)

#### editor/inlineChatZoneWidget/InlineChatZoneWidget/Dark
![screenshot](https://hediet-screenshots.azurewebsites.net/images/28af1b719f3877d2f048fef10bb4534d5f638c1987bb0536331f4ab50ea0ea7a)

#### editor/inlineChatZoneWidget/InlineChatZoneWidget/Light
![screenshot](https://hediet-screenshots.azurewebsites.net/images/c6c77ca2785665ae66c817cda21a8e5f5ea7d51e798c5b4e5aedcda9fd7323bd)

#### editor/inlineChatZoneWidget/InlineChatZoneWidgetTerminated/Dark
![screenshot](https://hediet-screenshots.azurewebsites.net/images/2fbc12507b59ff950d9612d2df92e6b39d8bf0bf500478e42eca2ead4d1ae206)

#### editor/inlineChatZoneWidget/InlineChatZoneWidgetTerminated/Light
![screenshot](https://hediet-screenshots.azurewebsites.net/images/4632ab04d1fdd7db9ab0e00cce10aefb7a6344eb8869dfce740309a8801cab73)

Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Adds trace-level timing logs to the chat session open pipeline to help diagnose slow session opening across the sessions UI, chat widget/view, and main thread session content provider.

Changes:

  • Instrumented session open entry points in SessionsManagementService (openChat, openSession) with start/done total=...ms trace logs.
  • Added tracing to ChatWidgetService.openSession to distinguish reveal/view/editor paths and report end-to-end timing.
  • Added tracing around ChatViewPane.loadSession and MainThreadChatSessions._provideChatSessionContent to correlate timings across layers.
Show a summary per file
File Description
src/vs/workbench/contrib/chat/browser/widgetHosts/viewPane/chatViewPane.ts Adds trace timing logs to loadSession including cancellation/error phases.
src/vs/workbench/contrib/chat/browser/widget/chatWidgetService.ts Adds trace timing logs to openSession and injects ILogService.
src/vs/workbench/api/browser/mainThreadChatSessions.ts Adds trace timing logs to _provideChatSessionContent.
src/vs/sessions/services/sessions/browser/sessionsManagementService.ts Switches to trace-level timing logs for openChat/openSession and tweaks warn message format.

Copilot's findings

Comments suppressed due to low confidence (4)

src/vs/workbench/api/browser/mainThreadChatSessions.ts:943

  • _provideChatSessionContent logs start and logs done only on the success path. If session.initialize(...) throws (including cancellation), you end up with a start log without a done, which makes timing correlation incomplete. Consider moving the final done total=...ms into a finally block and adding an error=true/cancelled=true marker when appropriate.

This issue also appears on line 898 of the same file.

	private async _provideChatSessionContent(providerHandle: number, sessionResource: URI, token: CancellationToken): Promise<IChatSession> {
		const t0 = Date.now();
		this._logService.trace(`[MainThreadChatSessions] _provideChatSessionContent start handle=${providerHandle} uri=${sessionResource.toString()}`);
		warnOnUntitledSessionResource(sessionResource, this._logService);

		let session = this._activeSessions.get(sessionResource);

		if (!session) {
			session = new ObservableChatSession(
				sessionResource,
				providerHandle,
				this._proxy,
				this._logService,
				this._dialogService
			);
			this._activeSessions.set(sessionResource, session);
			const disposable = session.onWillDispose(() => {
				this._activeSessions.delete(sessionResource);
				this._sessionDisposables.get(sessionResource)?.dispose();
				this._sessionDisposables.delete(sessionResource);
			});
			this._sessionDisposables.set(sessionResource, disposable);
		}

		try {
			const initialSessionOptions = this._chatSessionsService.getSessionOptions(sessionResource);
			await session.initialize(token, {
				initialSessionOptions: initialSessionOptions ? [...initialSessionOptions].map(([optionId, value]) => ({ optionId, value: typeof value === 'string' ? value : value?.id })) : undefined,
			});
			if (session.options) {
				for (const [_, handle] of this._sessionTypeToHandle) {
					if (handle === providerHandle) {
						for (const [optionId, value] of session.options) {
							this._chatSessionsService.setSessionOption(sessionResource, optionId, value);
						}
						break;
					}
				}
			}
			this._logService.trace(`[MainThreadChatSessions] _provideChatSessionContent done total=${Date.now() - t0}ms handle=${providerHandle}`);
			return session;
		} catch (error) {
			session.dispose();
			this._logService.error(`Error providing chat session content for handle ${providerHandle} and resource ${sessionResource.toString()}:`, error);
			throw error;
		}

src/vs/workbench/api/browser/mainThreadChatSessions.ts:901

  • These trace logs eagerly call sessionResource.toString() and build template strings even when Trace logging is disabled. Since this method can be called frequently, please guard the trace log construction with canLog(this._logService.getLevel(), LogLevel.Trace) (or similar) so URI stringification and string building only occurs at Trace level.
	private async _provideChatSessionContent(providerHandle: number, sessionResource: URI, token: CancellationToken): Promise<IChatSession> {
		const t0 = Date.now();
		this._logService.trace(`[MainThreadChatSessions] _provideChatSessionContent start handle=${providerHandle} uri=${sessionResource.toString()}`);
		warnOnUntitledSessionResource(sessionResource, this._logService);

src/vs/workbench/contrib/chat/browser/widget/chatWidgetService.ts:112

  • These trace logs build template strings and call sessionResource.toString()/Date.now() unconditionally, even when the log level is above Trace. Since this is on the session-opening hot path, please guard the log construction with canLog(logService.getLevel(), LogLevel.Trace) (or a getLevel() === LogLevel.Trace check) so the additional overhead is avoided unless Trace logging is enabled.
		const t0 = Date.now();
		const targetKind = target === ChatViewPaneTarget ? 'view' : (typeof target === 'undefined' ? 'undefined' : 'editor');
		this.logService.trace(`[ChatWidgetService] openSession start uri=${sessionResource.toString()} target=${targetKind}`);

src/vs/sessions/services/sessions/browser/sessionsManagementService.ts:250

  • The new openSession tracing only logs done after chatWidgetService.openSession(...) resolves. If that call throws, the start log will have no matching done. For consistent timing correlation, consider emitting the done total=...ms from a finally block with an error=true/cancelled=true attribute as appropriate.
	async openSession(sessionResource: URI, options?: { preserveFocus?: boolean }): Promise<void> {
		const t0 = Date.now();
		const sessionData = this.getSession(sessionResource);
		if (!sessionData) {
			this.logService.warn(`[SessionsManagement] openSession: session not found uri=${sessionResource.toString()}`);
			throw new Error(`Session with resource ${sessionResource.toString()} not found`);
		}
		this.logService.trace(`[SessionsManagement] openSession start uri=${sessionResource.toString()} provider=${sessionData.providerId}`);
		this.isNewChatSessionContext.set(false);
		this._isNewChatInSessionContext.set(false);
		this.setActiveSession(sessionData);

		// Open the active chat (which may have been restored to the last active chat)
		const activeChat = this._activeSession.get()?.activeChat.get();
		const openUri = activeChat?.resource ?? sessionData.resource;
		await this.chatWidgetService.openSession(openUri, ChatViewPaneTarget, { preserveFocus: options?.preserveFocus });
		this.logService.trace(`[SessionsManagement] openSession done total=${Date.now() - t0}ms`);
	}
  • Files reviewed: 4/4 changed files
  • Comments generated: 4

Comment thread src/vs/workbench/contrib/chat/browser/widget/chatWidgetService.ts
rebornix and others added 4 commits May 2, 2026 00:22
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Keep simple success-path logging only.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@rebornix rebornix marked this pull request as ready for review May 2, 2026 20:03
@rebornix rebornix enabled auto-merge (squash) May 2, 2026 20:03
@rebornix rebornix merged commit 4e312e3 into main May 2, 2026
25 of 26 checks passed
@rebornix rebornix deleted the rebornix/chat-session-trace-logs branch May 2, 2026 20:39
@vs-code-engineering vs-code-engineering Bot added this to the 1.119.0 milestone May 2, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants