Skip to content

Commit a679d58

Browse files
ulugbeknaCopilot
andauthored
Live debug log entries for NES inline edit requests (#4649)
* Enhance inline edit logging with live updates and dynamic content resolution * Fix "In progress" not clearing by using explicit completion flag The "In progress" indicator was inferred from result/error fields being unset, but many terminal code paths (markAsNoSuggestions, setIsSkipped, early returns in the provider) never set those fields. Replace with an explicit _isCompleted flag set via markCompleted() in the finally block, which always runs. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> * Address PR review comments for live debug log entries - Dispose per-entry subscriptions when entries are evicted from RequestLogger - Throttle tree refreshes (200ms debounce) while keeping document updates immediate - Fire 'latest' document change event when the updated entry is the most recent - Use resolveMarkdownContent() in TestLoggedRequestInfo.toJSON() - Add fireDidChange() to all state-mutating methods in InlineEditRequestLogContext - Prune _liveRequestIds when evicting entries in InlineEditLogger - Add isVisible predicate to IMarkdownContentRequest for dynamic tree filtering --------- Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
1 parent f69fb7d commit a679d58

7 files changed

Lines changed: 144 additions & 14 deletions

File tree

src/extension/inlineEdits/vscode-node/inlineCompletionProvider.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -273,6 +273,7 @@ export class InlineCompletionProviderImpl extends Disposable implements InlineCo
273273
const documentVersion = (isNotebookCell(document.uri) ? findNotebook(document.uri, workspace.notebookDocuments)?.version : undefined) || document.version;
274274
const logContext = new InlineEditRequestLogContext(doc.id.uri, documentVersion, context);
275275
logContext.recordingBookmark = this.model.debugRecorder.createBookmark();
276+
this.logger.addLive(logContext);
276277

277278
const telemetryBuilder = new NextEditProviderTelemetryBuilder(this._gitExtensionService, this._notebookService, this._workspaceService, this.model.nextEditProvider.ID, doc, this.model.debugRecorder, logContext.recordingBookmark);
278279
telemetryBuilder.setOpportunityId(context.requestUuid);
@@ -477,6 +478,7 @@ export class InlineCompletionProviderImpl extends Disposable implements InlineCo
477478

478479
throw e;
479480
} finally {
481+
logContext.markCompleted();
480482
requestCancellationTokenSource.dispose();
481483
this.logger.add(logContext);
482484
}

src/extension/inlineEdits/vscode-node/parts/inlineEditLogger.ts

Lines changed: 32 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,14 +9,38 @@ import { Disposable } from '../../../../util/vs/base/common/lifecycle';
99

1010
export class InlineEditLogger extends Disposable {
1111
private readonly _requests: InlineEditRequestLogContext[] = [];
12+
private readonly _liveRequestIds = new Set<number>();
1213

1314
constructor(
1415
@IRequestLogger private readonly _requestLogger: IRequestLogger,
1516
) {
1617
super();
1718
}
1819

20+
/**
21+
* Add a live log entry that appears immediately in the tree with dynamic content.
22+
* Content and icon are resolved on-demand from the logContext, and the entry
23+
* refreshes automatically as the logContext state changes.
24+
*/
25+
addLive(request: InlineEditRequestLogContext): void {
26+
this._liveRequestIds.add(request.requestId);
27+
this._requestLogger.addEntry({
28+
type: LoggedRequestKind.MarkdownContentRequest,
29+
debugName: request.getDebugName(),
30+
icon: () => request.getIcon(),
31+
startTimeMs: request.time,
32+
markdownContent: () => request.toLogDocument(),
33+
onDidChange: request.onDidChange,
34+
isVisible: () => request.includeInLogTree,
35+
});
36+
this._pushRequest(request);
37+
}
38+
1939
add(request: InlineEditRequestLogContext): void {
40+
if (this._liveRequestIds.has(request.requestId)) {
41+
return; // already added as a live entry
42+
}
43+
2044
if (!request.includeInLogTree) {
2145
return;
2246
}
@@ -28,10 +52,16 @@ export class InlineEditLogger extends Disposable {
2852
startTimeMs: request.time,
2953
markdownContent: request.toLogDocument(),
3054
});
31-
this._requests.push(request);
55+
this._pushRequest(request);
56+
}
3257

58+
private _pushRequest(request: InlineEditRequestLogContext): void {
59+
this._requests.push(request);
3360
if (this._requests.length > 100) {
34-
this._requests.shift();
61+
const evicted = this._requests.shift();
62+
if (evicted) {
63+
this._liveRequestIds.delete(evicted.requestId);
64+
}
3565
}
3666
}
3767

src/extension/log/vscode-node/requestLogTree.ts

Lines changed: 10 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -13,7 +13,7 @@ import * as vscode from 'vscode';
1313
import { IVSCodeExtensionContext } from '../../../platform/extContext/common/extensionContext';
1414
import { outputChannel } from '../../../platform/log/vscode/outputChannelLogTarget';
1515
import { CapturingToken } from '../../../platform/requestLogger/common/capturingToken';
16-
import { ChatRequestScheme, ILoggedElementInfo, ILoggedRequestInfo, ILoggedToolCall, IRequestLogger, LoggedInfo, LoggedInfoKind, LoggedRequestKind } from '../../../platform/requestLogger/node/requestLogger';
16+
import { ChatRequestScheme, ILoggedElementInfo, ILoggedRequestInfo, ILoggedToolCall, IRequestLogger, LoggedInfo, LoggedInfoKind, LoggedRequestKind, resolveMarkdownIcon } from '../../../platform/requestLogger/node/requestLogger';
1717
import { filterMap } from '../../../util/common/arrays';
1818
import { assert, assertNever } from '../../../util/vs/base/common/assert';
1919
import { Disposable, toDisposable } from '../../../util/vs/base/common/lifecycle';
@@ -600,6 +600,13 @@ class ChatRequestProvider extends Disposable implements vscode.TreeDataProvider<
600600
const tokenToPrompt = new Map<CapturingToken, ChatPromptItem>();
601601

602602
for (const currReq of this.requestLogger.getRequests()) {
603+
// Skip entries that are dynamically hidden (e.g. skipped/cancelled live NES requests)
604+
if (currReq.kind === LoggedInfoKind.Request &&
605+
currReq.entry.type === LoggedRequestKind.MarkdownContentRequest &&
606+
currReq.entry.isVisible && !currReq.entry.isVisible()) {
607+
continue;
608+
}
609+
603610
const currReqTreeItem = this.logToTreeItem(currReq);
604611

605612
if (!currReq.token) {
@@ -784,7 +791,8 @@ class ChatRequestItem extends vscode.TreeItem {
784791
this.id = info.id;
785792

786793
if (info.entry.type === LoggedRequestKind.MarkdownContentRequest) {
787-
this.iconPath = info.entry.icon === undefined ? undefined : new vscode.ThemeIcon(info.entry.icon.id);
794+
const resolvedIcon = resolveMarkdownIcon(info.entry);
795+
this.iconPath = resolvedIcon === undefined ? undefined : new vscode.ThemeIcon(resolvedIcon.id);
788796
const startTimeStr = new Date(info.entry.startTimeMs).toLocaleTimeString([], { hour: '2-digit', minute: '2-digit' });
789797
this.description = startTimeStr;
790798
} else {

src/extension/prompt/vscode-node/requestLoggerImpl.ts

Lines changed: 38 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -16,13 +16,14 @@ import { ContextManagementResponse } from '../../../platform/networking/common/a
1616
import { IResponseDelta, isOpenAiFunctionTool } from '../../../platform/networking/common/fetch';
1717
import { IEndpointBody } from '../../../platform/networking/common/networking';
1818
import { CapturingToken } from '../../../platform/requestLogger/common/capturingToken';
19-
import { AbstractRequestLogger, ChatRequestScheme, ILoggedElementInfo, ILoggedRequestInfo, ILoggedToolCall, LoggedInfo, LoggedInfoKind, LoggedRequest, LoggedRequestKind } from '../../../platform/requestLogger/node/requestLogger';
19+
import { AbstractRequestLogger, ChatRequestScheme, ILoggedElementInfo, ILoggedRequestInfo, ILoggedToolCall, LoggedInfo, LoggedInfoKind, LoggedRequest, LoggedRequestKind, resolveMarkdownContent } from '../../../platform/requestLogger/node/requestLogger';
2020
import { ThinkingData } from '../../../platform/thinking/common/thinking';
2121
import { createFencedCodeBlock } from '../../../util/common/markdown';
2222
import { assertNever } from '../../../util/vs/base/common/assert';
2323
import { Codicon } from '../../../util/vs/base/common/codicons';
24-
import { Emitter, Event } from '../../../util/vs/base/common/event';
24+
import { Emitter } from '../../../util/vs/base/common/event';
2525
import { Iterable } from '../../../util/vs/base/common/iterator';
26+
import { IDisposable } from '../../../util/vs/base/common/lifecycle';
2627
import { generateUuid } from '../../../util/vs/base/common/uuid';
2728
import { IInstantiationService } from '../../../util/vs/platform/instantiation/common/instantiation';
2829
import { renderDataPartToString, renderToolResultToStringNoBudget } from './requestLoggerToolResult';
@@ -138,7 +139,7 @@ class LoggedRequestInfo implements ILoggedRequestInfo {
138139
return {
139140
...baseInfo,
140141
startTime: new Date(this.entry.startTimeMs).toISOString(),
141-
content: this.entry.markdownContent
142+
content: resolveMarkdownContent(this.entry)
142143
};
143144
}
144145

@@ -274,7 +275,9 @@ export class RequestLogger extends AbstractRequestLogger {
274275

275276
private _didRegisterLinkProvider = false;
276277
private readonly _entries: LoggedInfo[] = [];
278+
private readonly _entryDisposables = new Map<string, IDisposable>();
277279
private _workspaceEditRecorder: WorkspaceEditRecorder | undefined;
280+
private readonly _onDidChangeDocument = this._register(new Emitter<Uri>());
278281

279282
constructor(
280283
@ILogService private readonly _logService: ILogService,
@@ -285,7 +288,7 @@ export class RequestLogger extends AbstractRequestLogger {
285288

286289

287290
this._register(workspace.registerTextDocumentContentProvider(ChatRequestScheme.chatRequestScheme, {
288-
onDidChange: Event.map(this.onDidChangeRequests, () => Uri.parse(ChatRequestScheme.buildUri({ kind: 'latest' }))),
291+
onDidChange: this._onDidChangeDocument.event,
289292
provideTextDocumentContent: (uri) => {
290293
const parseResult = ChatRequestScheme.parseUri(uri.toString());
291294
if (!parseResult) { return `Invalid URI: ${uri}`; }
@@ -409,6 +412,30 @@ export class RequestLogger extends AbstractRequestLogger {
409412
if (ok) {
410413
this._ensureLinkProvider();
411414

415+
// Subscribe to live entry changes for dynamic content/icon refresh
416+
if (entry.type === LoggedRequestKind.MarkdownContentRequest && entry.onDidChange) {
417+
let treeRefreshTimeout: ReturnType<typeof setTimeout> | undefined;
418+
const subscription = entry.onDidChange(() => {
419+
// Always update the virtual document immediately for streaming content
420+
this._onDidChangeDocument.fire(Uri.parse(ChatRequestScheme.buildUri({ kind: 'request', id })));
421+
422+
// Also refresh the "latest" document if this is the most recent entry
423+
if (this._entries.at(-1)?.id === id) {
424+
this._onDidChangeDocument.fire(Uri.parse(ChatRequestScheme.buildUri({ kind: 'latest' })));
425+
}
426+
427+
// Throttle tree refreshes to avoid frequent expensive updates on streaming changes
428+
if (treeRefreshTimeout !== undefined) {
429+
clearTimeout(treeRefreshTimeout);
430+
}
431+
treeRefreshTimeout = setTimeout(() => {
432+
this._onDidChangeRequests.fire();
433+
treeRefreshTimeout = undefined;
434+
}, 200);
435+
});
436+
this._entryDisposables.set(id, subscription);
437+
}
438+
412439
let extraData: string;
413440
if (entry.type === LoggedRequestKind.MarkdownContentRequest) {
414441
extraData = 'markdown';
@@ -457,9 +484,14 @@ export class RequestLogger extends AbstractRequestLogger {
457484
this._entries.push(entry);
458485
const maxEntries = this._configService.getConfig(ConfigKey.Advanced.RequestLoggerMaxEntries);
459486
if (this._entries.length > maxEntries) {
460-
this._entries.shift();
487+
const evicted = this._entries.shift();
488+
if (evicted) {
489+
this._entryDisposables.get(evicted.id)?.dispose();
490+
this._entryDisposables.delete(evicted.id);
491+
}
461492
}
462493
this._onDidChangeRequests.fire();
494+
this._onDidChangeDocument.fire(Uri.parse(ChatRequestScheme.buildUri({ kind: 'latest' })));
463495
return true;
464496
}
465497

@@ -570,7 +602,7 @@ export class RequestLogger extends AbstractRequestLogger {
570602

571603
private _renderRequestToMarkdown(id: string, entry: LoggedRequest): string {
572604
if (entry.type === LoggedRequestKind.MarkdownContentRequest) {
573-
return entry.markdownContent;
605+
return resolveMarkdownContent(entry);
574606
}
575607

576608
const result: string[] = [];

src/platform/inlineEdits/common/inlineEditLogContext.ts

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import type { InlineCompletionContext } from 'vscode';
88
import * as yaml from 'yaml';
99
import { ErrorUtils } from '../../../util/common/errors';
1010
import { isCancellationError } from '../../../util/vs/base/common/errors';
11+
import { Emitter, Event } from '../../../util/vs/base/common/event';
1112
import { ThemeIcon } from '../../../util/vs/base/common/themables';
1213
import { SerializedLineEdit } from '../../../util/vs/editor/common/core/edits/lineEdit';
1314
import { SerializedEdit } from './dataTypes/editUtils';
@@ -39,6 +40,22 @@ export class InlineEditRequestLogContext {
3940
return this._isVisible;
4041
}
4142

43+
private _isCompleted: boolean = false;
44+
45+
/** Mark this request as completed (no longer in progress). */
46+
markCompleted(): void {
47+
this._isCompleted = true;
48+
this.fireDidChange();
49+
}
50+
51+
private readonly _onDidChange = new Emitter<void>();
52+
/** Fires when state changes, allowing live log entries to refresh their content. */
53+
public readonly onDidChange: Event<void> = this._onDidChange.event;
54+
55+
protected fireDidChange(): void {
56+
this._onDidChange.fire();
57+
}
58+
4259
constructor(
4360
public readonly filePath: string,
4461
public readonly version: number,
@@ -51,6 +68,10 @@ export class InlineEditRequestLogContext {
5168
const lines: string[] = [];
5269
lines.push('# ' + this.getMarkdownTitle() + ` (Request #${this.requestId})`);
5370

71+
if (!this._isCompleted) {
72+
lines.push('\n⏳ **In progress…**\n');
73+
}
74+
5475
lines.push('💡 Tip: double-click anywhere to open this file as text to copy-paste content into an issue.\n');
5576

5677
lines.push('<details><summary>Explanation for icons</summary>\n');
@@ -219,20 +240,23 @@ export class InlineEditRequestLogContext {
219240
setRequestInput(nextEditRequest: StatelessNextEditRequest): void {
220241
this._isVisible = true;
221242
this._nextEditRequest = nextEditRequest;
243+
this.fireDidChange();
222244
}
223245

224246
private _resultEdit: RootedLineEdit | string | undefined = undefined;
225247

226248
setResult(resultEditOrPatchString: RootedLineEdit | string) {
227249
this._isVisible = true;
228250
this._resultEdit = resultEditOrPatchString;
251+
this.fireDidChange();
229252
}
230253

231254
protected _diagnosticsResultEdit: RootedLineEdit | undefined = undefined;
232255

233256
setDiagnosticsResult(resultEdit: RootedLineEdit) {
234257
this._isVisible = true;
235258
this._diagnosticsResultEdit = resultEdit;
259+
this.fireDidChange();
236260
}
237261

238262
private _nesTypePicked: 'llm' | 'diagnostics' | undefined;
@@ -286,12 +310,14 @@ export class InlineEditRequestLogContext {
286310

287311
this._isVisible = true;
288312
this._icon = Icon.database;
313+
this.fireDidChange();
289314
}
290315

291316
private _endpointInfo: { url: string; modelName: string } | undefined;
292317

293318
public setEndpointInfo(url: string, modelName: string): void {
294319
this._endpointInfo = { url, modelName };
320+
this.fireDidChange();
295321
}
296322

297323
public get endpointInfo(): { url: string; modelName: string } | undefined {
@@ -301,6 +327,7 @@ export class InlineEditRequestLogContext {
301327
private _headerRequestId: string | undefined = undefined;
302328
public setHeaderRequestId(headerRequestId: string): void {
303329
this._headerRequestId = headerRequestId;
330+
this.fireDidChange();
304331
}
305332
get headerRequestId(): string | undefined {
306333
return this._headerRequestId;
@@ -319,6 +346,7 @@ export class InlineEditRequestLogContext {
319346
} else {
320347
this._prompt = stringifyChatMessages(prompt);
321348
}
349+
this.fireDidChange();
322350
}
323351

324352
private _icon: Icon.t | undefined;
@@ -330,16 +358,19 @@ export class InlineEditRequestLogContext {
330358
public setIsSkipped() {
331359
this._isVisible = false;
332360
this._icon = Icon.skipped;
361+
this.fireDidChange();
333362
}
334363

335364
public markAsFromCache() {
336365
this._isVisible = true;
337366
this._icon = Icon.database;
367+
this.fireDidChange();
338368
}
339369

340370
public markAsNoSuggestions() {
341371
this._isVisible = true;
342372
this._icon = Icon.circleSlash;
373+
this.fireDidChange();
343374
}
344375

345376
private error: unknown | undefined = undefined;
@@ -354,6 +385,7 @@ export class InlineEditRequestLogContext {
354385
} else {
355386
this._icon = Icon.error;
356387
}
388+
this.fireDidChange();
357389
}
358390

359391
/**
@@ -363,6 +395,7 @@ export class InlineEditRequestLogContext {
363395
setResponse(v: string): void {
364396
this._isVisible = true;
365397
this.response = v;
398+
this.fireDidChange();
366399
}
367400

368401
private fullResponsePromise: Promise<string | undefined> | undefined = undefined;
@@ -379,21 +412,25 @@ export class InlineEditRequestLogContext {
379412
private providerStartTime: number | undefined = undefined;
380413
setProviderStartTime(): void {
381414
this.providerStartTime = Date.now();
415+
this.fireDidChange();
382416
}
383417

384418
private providerEndTime: number | undefined = undefined;
385419
setProviderEndTime(): void {
386420
this.providerEndTime = Date.now();
421+
this.fireDidChange();
387422
}
388423

389424
private fetchStartTime: number | undefined = undefined;
390425
setFetchStartTime(): void {
391426
this.fetchStartTime = Date.now();
427+
this.fireDidChange();
392428
}
393429

394430
private fetchEndTime: number | undefined = undefined;
395431
setFetchEndTime(): void {
396432
this.fetchEndTime = Date.now();
433+
this.fireDidChange();
397434
}
398435

399436
/**
@@ -409,6 +446,7 @@ export class InlineEditRequestLogContext {
409446
this._isVisible = true;
410447
this._responseResults = v;
411448
this._icon ??= Icon.lightbulbFull;
449+
this.fireDidChange();
412450
}
413451

414452
getDebugName(): string {
@@ -429,6 +467,7 @@ export class InlineEditRequestLogContext {
429467
private _trace: string[] = [];
430468
trace(msg: string): void {
431469
this._trace.push(msg);
470+
this.fireDidChange();
432471
}
433472

434473
private _renderTraceDiagram(): string[] {
@@ -572,6 +611,7 @@ export class InlineEditRequestLogContext {
572611
private _logs: string[] = [];
573612
addLog(content: string): void {
574613
this._logs.push(content.replace('\n', '\\n').replace('\t', '\\t').replace('`', '\`') + '\n');
614+
this.fireDidChange();
575615
}
576616

577617
private _rebaseFailure: MarkdownLoggable | undefined;

0 commit comments

Comments
 (0)