Skip to content

Commit 9ee53b4

Browse files
chrmartichrmarti
authored
Log recovery after timeout (#306751)
1 parent 6b7cce1 commit 9ee53b4

1 file changed

Lines changed: 97 additions & 66 deletions

File tree

‎src/vs/workbench/contrib/chat/browser/chatSetup/chatSetupProviders.ts‎

Lines changed: 97 additions & 66 deletions
Original file line numberDiff line numberDiff line change
@@ -368,15 +368,16 @@ export class SetupAgent extends Disposable implements IChatAgentImplementation {
368368
const disposables = new DisposableStore();
369369
disposables.add(toDisposable(() => clearTimeout(timeoutHandle)));
370370
try {
371+
const allReady = Promise.allSettled([
372+
whenAgentActivated,
373+
whenAgentReady,
374+
whenLanguageModelReady,
375+
whenToolsModelReady
376+
]);
371377
const ready = await Promise.race([
372378
timeout(this.environmentService.remoteAuthority ? 60000 /* increase for remote scenarios */ : 20000).then(() => 'timedout'),
373379
this.whenPanelAgentHasGuidance(disposables).then(() => 'panelGuidance'),
374-
Promise.allSettled([
375-
whenAgentActivated,
376-
whenAgentReady,
377-
whenLanguageModelReady,
378-
whenToolsModelReady
379-
])
380+
allReady
380381
]);
381382

382383
if (ready === 'panelGuidance') {
@@ -401,41 +402,9 @@ export class SetupAgent extends Disposable implements IChatAgentImplementation {
401402
warningMessage = localize('chatTookLongWarning', "Chat took too long to get ready. Please ensure you are signed in to {0} and that the extension `{1}` is installed and enabled. Click restart to try again if this issue persists.", defaultChat.provider.default.name, defaultChat.chatExtensionId);
402403
}
403404

404-
// Compute language model diagnostic info
405-
const languageModelIds = languageModelsService.getLanguageModelIds();
406-
let languageModelDefaultCount = 0;
407-
for (const id of languageModelIds) {
408-
const model = languageModelsService.lookupLanguageModel(id);
409-
if (model?.isDefaultForLocation[ChatAgentLocation.Chat]) {
410-
languageModelDefaultCount++;
411-
}
412-
}
405+
const diagnosticInfo = this.computeDiagnosticInfo(agentActivated, agentReady, languageModelReady, toolsModelReady, requestModel, languageModelsService, chatAgentService, modeInfo);
413406

414-
// Compute agent diagnostic info
415-
const defaultAgent = chatAgentService.getDefaultAgent(this.location, modeInfo?.kind);
416-
const agentHasDefault = !!defaultAgent;
417-
const agentDefaultIsCore = defaultAgent?.isCore ?? false;
418-
const contributedDefaultAgent = chatAgentService.getContributedDefaultAgent(this.location);
419-
const agentHasContributedDefault = !!contributedDefaultAgent;
420-
const agentContributedDefaultIsCore = contributedDefaultAgent?.isCore ?? false;
421-
const agentActivatedCount = chatAgentService.getActivatedAgents().length;
422-
423-
this.logService.warn(warningMessage, {
424-
agentActivated,
425-
agentReady,
426-
agentHasDefault,
427-
agentDefaultIsCore,
428-
agentHasContributedDefault,
429-
agentContributedDefaultIsCore,
430-
agentActivatedCount,
431-
agentLocation: this.location,
432-
agentModeKind: modeInfo?.kind,
433-
languageModelReady,
434-
languageModelCount: languageModelIds.length,
435-
languageModelDefaultCount,
436-
languageModelHasRequestedModel: !!requestModel.modelId,
437-
toolsModelReady
438-
});
407+
this.logService.warn(`[chat setup] ${warningMessage}`, diagnosticInfo);
439408

440409
type ChatSetupTimeoutClassification = {
441410
owner: 'chrmarti';
@@ -477,28 +446,8 @@ export class SetupAgent extends Disposable implements IChatAgentImplementation {
477446
isAnonymous: boolean;
478447
matchingWelcomeViewWhen: string;
479448
};
480-
const chatViewPane = this.viewsService.getActiveViewWithId(ChatViewId) as ChatViewPane | undefined;
481-
const matchingWelcomeView = chatViewPane?.getMatchingWelcomeView();
482-
483-
this.telemetryService.publicLog2<ChatSetupTimeoutEvent, ChatSetupTimeoutClassification>('chatSetup.timeout', {
484-
agentActivated,
485-
agentReady,
486-
agentHasDefault,
487-
agentDefaultIsCore,
488-
agentHasContributedDefault,
489-
agentContributedDefaultIsCore,
490-
agentActivatedCount,
491-
agentLocation: this.location,
492-
agentModeKind: modeInfo?.kind ?? '',
493-
languageModelReady,
494-
languageModelCount: languageModelIds.length,
495-
languageModelDefaultCount,
496-
languageModelHasRequestedModel: !!requestModel.modelId,
497-
toolsModelReady,
498-
isRemote: !!this.environmentService.remoteAuthority,
499-
isAnonymous: this.chatEntitlementService.anonymous,
500-
matchingWelcomeViewWhen: matchingWelcomeView?.when.serialize() ?? (chatViewPane ? 'noWelcomeView' : 'noChatViewPane'),
501-
});
449+
450+
this.telemetryService.publicLog2<ChatSetupTimeoutEvent, ChatSetupTimeoutClassification>('chatSetup.timeout', diagnosticInfo);
502451

503452
progress({
504453
kind: 'warning',
@@ -527,10 +476,56 @@ export class SetupAgent extends Disposable implements IChatAgentImplementation {
527476
});
528477
}
529478

530-
// This means Chat is unhealthy and we cannot retry the
531-
// request. Signal this to the outside via an event.
532-
this._onUnresolvableError.fire();
533-
return;
479+
// Wait for all readiness signals and log/send
480+
// telemetry about recovery after the timeout.
481+
await allReady;
482+
483+
const recoveryDiagnosticInfo = this.computeDiagnosticInfo(agentActivated, agentReady, languageModelReady, toolsModelReady, requestModel, languageModelsService, chatAgentService, modeInfo);
484+
485+
this.logService.info('[chat setup] Chat setup timeout recovered', recoveryDiagnosticInfo);
486+
487+
type ChatSetupTimeoutRecoveryClassification = {
488+
owner: 'chrmarti';
489+
comment: 'Provides insight into chat setup timeout recovery.';
490+
agentActivated: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether the agent was activated.' };
491+
agentReady: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether the agent was ready.' };
492+
agentHasDefault: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether a default agent exists for the location and mode.' };
493+
agentDefaultIsCore: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether the default agent is a core agent.' };
494+
agentHasContributedDefault: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether a contributed default agent exists for the location.' };
495+
agentContributedDefaultIsCore: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether the contributed default agent is a core agent.' };
496+
agentActivatedCount: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; isMeasurement: true; comment: 'Number of activated agents at recovery time.' };
497+
agentLocation: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'The chat agent location.' };
498+
agentModeKind: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'The chat mode kind.' };
499+
languageModelReady: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether the language model was ready.' };
500+
languageModelCount: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; isMeasurement: true; comment: 'Number of registered language models at recovery time.' };
501+
languageModelDefaultCount: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; isMeasurement: true; comment: 'Number of language models with isDefaultForLocation[Chat] set at recovery time.' };
502+
languageModelHasRequestedModel: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether a specific model ID was requested.' };
503+
toolsModelReady: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether the tools model was ready.' };
504+
isRemote: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether this is a remote scenario.' };
505+
isAnonymous: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'Whether anonymous access is enabled.' };
506+
matchingWelcomeViewWhen: { classification: 'SystemMetaData'; purpose: 'FeatureInsight'; comment: 'The when clause of the matching extension welcome view, if any.' };
507+
};
508+
type ChatSetupTimeoutRecoveryEvent = {
509+
agentActivated: boolean;
510+
agentReady: boolean;
511+
agentHasDefault: boolean;
512+
agentDefaultIsCore: boolean;
513+
agentHasContributedDefault: boolean;
514+
agentContributedDefaultIsCore: boolean;
515+
agentActivatedCount: number;
516+
agentLocation: string;
517+
agentModeKind: string;
518+
languageModelReady: boolean;
519+
languageModelCount: number;
520+
languageModelDefaultCount: number;
521+
languageModelHasRequestedModel: boolean;
522+
toolsModelReady: boolean;
523+
isRemote: boolean;
524+
isAnonymous: boolean;
525+
matchingWelcomeViewWhen: string;
526+
};
527+
528+
this.telemetryService.publicLog2<ChatSetupTimeoutRecoveryEvent, ChatSetupTimeoutRecoveryClassification>('chatSetup.timeoutRecovery', recoveryDiagnosticInfo);
534529
}
535530
} finally {
536531
disposables.dispose();
@@ -647,6 +642,42 @@ export class SetupAgent extends Disposable implements IChatAgentImplementation {
647642
}
648643
}
649644

645+
private computeDiagnosticInfo(agentActivated: boolean, agentReady: boolean, languageModelReady: boolean, toolsModelReady: boolean, requestModel: IChatRequestModel, languageModelsService: ILanguageModelsService, chatAgentService: IChatAgentService, modeInfo: { kind?: ChatModeKind } | undefined) {
646+
const languageModelIds = languageModelsService.getLanguageModelIds();
647+
let languageModelDefaultCount = 0;
648+
for (const id of languageModelIds) {
649+
const model = languageModelsService.lookupLanguageModel(id);
650+
if (model?.isDefaultForLocation[ChatAgentLocation.Chat]) {
651+
languageModelDefaultCount++;
652+
}
653+
}
654+
655+
const defaultAgent = chatAgentService.getDefaultAgent(this.location, modeInfo?.kind);
656+
const contributedDefaultAgent = chatAgentService.getContributedDefaultAgent(this.location);
657+
const chatViewPane = this.viewsService.getActiveViewWithId(ChatViewId) as ChatViewPane | undefined;
658+
const matchingWelcomeView = chatViewPane?.getMatchingWelcomeView();
659+
660+
return {
661+
agentActivated,
662+
agentReady,
663+
agentHasDefault: !!defaultAgent,
664+
agentDefaultIsCore: defaultAgent?.isCore ?? false,
665+
agentHasContributedDefault: !!contributedDefaultAgent,
666+
agentContributedDefaultIsCore: contributedDefaultAgent?.isCore ?? false,
667+
agentActivatedCount: chatAgentService.getActivatedAgents().length,
668+
agentLocation: this.location,
669+
agentModeKind: modeInfo?.kind ?? '',
670+
languageModelReady,
671+
languageModelCount: languageModelIds.length,
672+
languageModelDefaultCount,
673+
languageModelHasRequestedModel: !!requestModel.modelId,
674+
toolsModelReady,
675+
isRemote: !!this.environmentService.remoteAuthority,
676+
isAnonymous: this.chatEntitlementService.anonymous,
677+
matchingWelcomeViewWhen: matchingWelcomeView?.when.serialize() ?? (chatViewPane ? 'noWelcomeView' : 'noChatViewPane'),
678+
};
679+
}
680+
650681
private async doInvokeWithSetup(request: IChatAgentRequest, progress: (part: IChatProgress) => void, chatService: IChatService, languageModelsService: ILanguageModelsService, chatWidgetService: IChatWidgetService, chatAgentService: IChatAgentService, languageModelToolsService: ILanguageModelToolsService, defaultAccountService: IDefaultAccountService): Promise<IChatAgentResult> {
651682
this.telemetryService.publicLog2<WorkbenchActionExecutedEvent, WorkbenchActionExecutedClassification>('workbenchActionExecuted', { id: CHAT_SETUP_ACTION_ID, from: 'chat' });
652683

0 commit comments

Comments
 (0)