Skip to content

ghost: add logs to be able to track down behavior issues in ghost-text #3271

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
ulugbekna merged 1 commit into from
Jan 29, 2026
Merged

ghost: add logs to be able to track down behavior issues in ghost-text #3271

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions src/extension/completions-core/vscode-node/extension/src/ghostText/ghostTextProvider.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ import { handleGhostTextPostInsert, handleGhostTextShown, handlePartialGhostText
import { GhostText } from '../../../lib/src/inlineCompletion';
import { telemetry } from '../../../lib/src/telemetry';
import { wrapDoc } from '../textDocumentManager';
import { ILogger } from '../../../../../../platform/log/common/logService';

export interface GhostTextCompletionList extends InlineCompletionList {
items: GhostTextCompletionItem[];
Expand Down Expand Up @@ -57,13 +58,16 @@ export class GhostTextProvider {
context: InlineCompletionContext,
telemetryBuilder: NextEditProviderTelemetryBuilder,
logContext: GhostTextLogContext,
parentLogger: ILogger,
token: CancellationToken
): Promise<GhostTextCompletionList | undefined> {
const textDocument = wrapDoc(vscodeDoc);
if (!textDocument) {
return;
}

const logger = parentLogger.createSubLogger(['GhostTextProvider', 'provideInlineCompletionItems']);

// Opportunity ID is a unique ID generated by the client relating to a single "opportunity"
// to provide some kind of suggestion to the user. Multiple requests might be made for a single
// opportunity, for example requesting a completion as well as an edit suggestion. The single ID
Expand All @@ -84,6 +88,7 @@ export class GhostTextProvider {
},
logContext,
telemetryBuilder.nesBuilder,
logger,
);

if (!rawCompletions) {
Expand Down
33 changes: 24 additions & 9 deletions ...xtension/completions-core/vscode-node/extension/src/vscodeInlineCompletionItemProvider.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,8 +17,10 @@ import {
TextDocument,
workspace
} from 'vscode';
import { ILogger, ILogService, LogTarget } from '../../../../../platform/log/common/logService';
import { softAssert } from '../../../../../util/vs/base/common/assert';
import { Disposable } from '../../../../../util/vs/base/common/lifecycle';
import { StopWatch } from '../../../../../util/vs/base/common/stopwatch';
import { LineEdit } from '../../../../../util/vs/editor/common/core/edits/lineEdit';
import { TextEdit, TextReplacement } from '../../../../../util/vs/editor/common/core/edits/textEdit';
import { Range } from '../../../../../util/vs/editor/common/core/range';
Expand All @@ -37,13 +39,13 @@ import { CopilotCompletionFeedbackTracker, sendCompletionFeedbackCommand } from
import { ICompletionsExtensionStatus } from './extensionStatus';
import { GhostTextCompletionItem, GhostTextCompletionList, GhostTextProvider } from './ghostText/ghostTextProvider';

const logger = new Logger('inlineCompletionItemProvider');

function quickSuggestionsDisabled() {
const qs = workspace.getConfiguration('editor.quickSuggestions');
return qs.get('other') !== 'on' && qs.get('comments') !== 'on' && qs.get('strings') !== 'on';
}

const myLogger = new Logger('CopilotInlineCompletionItemProvider');

export function exception(accessor: ServicesAccessor, error: unknown, origin: string, logger?: Logger) {
if (error instanceof Error && error.name === 'Canceled') {
// these are VS Code cancellations
Expand Down Expand Up @@ -71,16 +73,20 @@ export class CopilotInlineCompletionItemProvider extends Disposable implements I

public onDidChange = undefined;

private readonly logger: ILogger;

constructor(
@IInstantiationService private readonly instantiationService: IInstantiationService,
@ICompletionsTelemetryService private readonly telemetryService: ICompletionsTelemetryService,
@ICompletionsExtensionStatus private readonly extensionStatusService: ICompletionsExtensionStatus,
@ILogService logService: ILogService,
) {
super();
this.copilotCompletionFeedbackTracker = this._register(this.instantiationService.createInstance(CopilotCompletionFeedbackTracker));
this.ghostTextProvider = this.instantiationService.createInstance(GhostTextProvider);
this.inlineEditLogger = this.instantiationService.createInstance(InlineEditLogger);
this.telemetrySender = this.instantiationService.createInstance(TelemetrySender);
this.logger = logService.createSubLogger(['Ghost', 'CopilotInlineCompletionItemProvider']);
}

async provideInlineCompletionItems(
Expand All @@ -100,13 +106,21 @@ export class CopilotInlineCompletionItemProvider extends Disposable implements I
}
}

const sw = new StopWatch();

const logContext = new GhostTextLogContext(doc.uri.toString(), doc.version, context);

const logger = this.logger.createSubLogger('provideInlineCompletionItems').withExtraTarget(LogTarget.fromCallback((_level, msg) => {
logContext.trace(`[${Math.floor(sw.elapsed()).toString().padStart(4, ' ')}ms] ${msg}`);
}));

logger.trace('Started providing inline completion items');

const telemetryBuilder = this.createTelemetryBuilder();
telemetryBuilder.setOpportunityId(context.requestUuid);

try {
return await this._provideInlineCompletionItems(doc, position, context, telemetryBuilder, logContext, token);
return await this._provideInlineCompletionItems(doc, position, context, telemetryBuilder, logContext, logger, token);
} catch (e) {
logContext.setError(e);
this.telemetryService.sendGHTelemetryException(e, 'codeUnification.completions.exception');
Expand All @@ -125,7 +139,8 @@ export class CopilotInlineCompletionItemProvider extends Disposable implements I
context: InlineCompletionContext,
telemetryBuilder: NextEditProviderTelemetryBuilder,
logContext: GhostTextLogContext,
token: CancellationToken
parentLogger: ILogger,
token: CancellationToken,
): Promise<GhostTextCompletionList> {

const copilotConfig = workspace.getConfiguration(CopilotConfigPrefix);
Expand All @@ -142,7 +157,7 @@ export class CopilotInlineCompletionItemProvider extends Disposable implements I
const emptyList = { items: [], telemetryBuilder }; // we need to return an empty list, such that vscode invokes endOfLife on it and we send telemetry

try {
const list = await this.ghostTextProvider.provideInlineCompletionItems(doc, position, context, telemetryBuilder, logContext, token);
const list = await this.ghostTextProvider.provideInlineCompletionItems(doc, position, context, telemetryBuilder, logContext, parentLogger, token);

telemetryBuilder.nesBuilder.setHasNextEdit(list !== undefined && list.items.length > 0);

Expand All @@ -164,7 +179,7 @@ export class CopilotInlineCompletionItemProvider extends Disposable implements I
commands: [sendCompletionFeedbackCommand],
};
} catch (e) {
this.instantiationService.invokeFunction(exception, e, '._provideInlineCompletionItems', logger);
this.instantiationService.invokeFunction(exception, e, '._provideInlineCompletionItems', myLogger);
logContext.setError(e);
}

Expand All @@ -177,7 +192,7 @@ export class CopilotInlineCompletionItemProvider extends Disposable implements I
this.copilotCompletionFeedbackTracker.trackItem(item);
return this.ghostTextProvider.handleDidShowCompletionItem(item);
} catch (e) {
this.instantiationService.invokeFunction(exception, e, '.handleDidShowCompletionItem', logger);
this.instantiationService.invokeFunction(exception, e, '.handleDidShowCompletionItem', myLogger);
}
}

Expand All @@ -188,15 +203,15 @@ export class CopilotInlineCompletionItemProvider extends Disposable implements I
try {
return this.ghostTextProvider.handleDidPartiallyAcceptCompletionItem(item, acceptedLengthOrInfo);
} catch (e) {
this.instantiationService.invokeFunction(exception, e, '.handleDidPartiallyAcceptCompletionItem', logger);
this.instantiationService.invokeFunction(exception, e, '.handleDidPartiallyAcceptCompletionItem', myLogger);
}
}

handleEndOfLifetime(completionItem: GhostTextCompletionItem, reason: InlineCompletionEndOfLifeReason) {
try {
return this.ghostTextProvider.handleEndOfLifetime(completionItem, reason);
} catch (e) {
this.instantiationService.invokeFunction(exception, e, '.handleEndOfLifetime', logger);
this.instantiationService.invokeFunction(exception, e, '.handleEndOfLifetime', myLogger);
}
}

Expand Down
Loading
Loading