diff --git a/.eslintrc.js b/.eslintrc.js index 6453dd70202..3275c70d17b 100644 --- a/.eslintrc.js +++ b/.eslintrc.js @@ -61,7 +61,7 @@ module.exports = { '@typescript-eslint/no-floating-promises': [ 'error', { - ignoreVoid: false + ignoreVoid: true } ], diff --git a/package.json b/package.json index 7cd66e9709a..b3503e2f7bb 100644 --- a/package.json +++ b/package.json @@ -1497,7 +1497,9 @@ "type": "array", "default": [], "items": { - "enum": [] + "enum": [ + "KernelCompletions" + ] }, "markdownDescription": "%jupyter.configuration.jupyter.experiments.optInto.markdownDescription%", "scope": "application" @@ -1506,7 +1508,9 @@ "type": "array", "default": [], "items": { - "enum": [] + "enum": [ + "KernelCompletions" + ] }, "markdownDescription": "%jupyter.configuration.jupyter.experiments.optOutFrom.markdownDescription%", "scope": "application" @@ -1971,8 +1975,7 @@ }, "jupyter.enableKernelCompletions": { "type": "boolean", - "default": false, - "description": "Enable Non-Python Kernel Completions", + "default": true, "markdownDescription": "%jupyter.configuration.jupyter.enableKernelCompletions.markdownDescription%", "scope": "application" }, @@ -2036,7 +2039,74 @@ ] }, "markdownDescription": "%jupyter.configuration.jupyter.completionTriggerCharacters.markdownDescription%", - "scope": "machine-overridable" + "scope": "machine-overridable", + "examples": [ + { + "bash": [ + "$", + "{" + ] + }, + { + "java": [ + ".", + "@", + "#" + ] + }, + { + "javascript": [ + ".", + "\"", + "'", + "/", + "@" + ] + }, + { + "julia": [ + "." + ] + }, + { + "python": [ + ".", + "%", + "'", + "\"" + ] + }, + { + "typescript": [ + ".", + "\"", + "'", + "/", + "@", + "<" + ] + }, + { + "rust": [ + ".", + ":" + ] + }, + { + "scala": [ + "." + ] + }, + { + "xonsh": [ + " ", + ".", + "%", + "'", + "\"" + ] + } + ] } } }, diff --git a/package.nls.json b/package.nls.json index a4ad836db9b..66201f584de 100644 --- a/package.nls.json +++ b/package.nls.json @@ -237,7 +237,7 @@ "comment": ["{Locked='PYTHONNOUSERSITE'}", "{Locked='PYTHONPATH'}"] }, "jupyter.configuration.jupyter.enableExtendedKernelCompletions.markdownDescription": "Enables Jedi support for extended IntelliSense completions in running Python Jupyter kernels for Python (see this [setting](https://ipython.readthedocs.io/en/stable/config/options/terminal.html?highlight=use_jedi#configtrait-Completer.use_jedi)). This can greatly impact notebook cell execution performance. Use with caution.", - "jupyter.configuration.jupyter.enableKernelCompletions.markdownDescription": "Enables support for auto completion in non-Python Notebooks and Interactive Windows using the associated Jupyter Kernel. \n\nWarning: This can greatly impact cell execution performance. Use with caution.", + "jupyter.configuration.jupyter.enableKernelCompletions.markdownDescription": "Enable code completions in Notebooks and Interactive Windows using results from the associated Jupyter Kernel.", "DataScience.exportDialogTitle": { "message": "Export to Jupyter Notebook", "comment": ["{Locked='Notebook'}"] diff --git a/src/gdpr.ts b/src/gdpr.ts index b6a0b34deb6..c1e5f9f27ed 100644 --- a/src/gdpr.ts +++ b/src/gdpr.ts @@ -263,6 +263,33 @@ "${include}": [ "${F1}" + ] + } + */ +//Telemetry.ExecuteCode +/* __GDPR__ + "DATASCIENCE.EXECUTE_CODE" : { + "actionSource": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Whether this was started by Jupyter extension or a 3rd party. Common to most of the events.","owner":"donjayamanne"}, + "disableUI": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Whether the notebook startup UI (progress indicator & the like) was displayed to the user or not. If its not displayed, then its considered an auto start (start in the background, like pre-warming kernel) Common to most of the events.","owner":"donjayamanne"}, + "userExecutedCell": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Whether the user executed a cell. Common to most of the events.","owner":"donjayamanne"}, + "resourceHash": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Hash of the resource (notebook.uri or pythonfile.uri associated with this). If we run the same notebook tomorrow, the hash will be the same. Used to check whether a particular notebook fails across time or not. This is also used to map different telemetry events related to this same resource. E.g. we could have an event sent for starting a notebook with this hash, and then later we get yet another event indicating starting a notebook failed. And another event indicating the Python environment used for this notebook is a conda environment or we have some other event indicating some other piece of data for this resource. With the information across multiple resources we can now join the different data points and have a better understanding of what is going on, e.g. why something failed. Common to most of the events.","owner":"donjayamanne"}, + "pythonEnvironmentVersion": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Found plenty of issues when starting Conda Python 3.7, Python 3.7 Python 3.9 (in early days when ipykernel was not up to date) Common to most of the events.","owner":"donjayamanne"}, + "pythonEnvironmentType": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Found plenty of issues when starting kernels with conda, hence useful to capture this info. Common to most of the events.","owner":"donjayamanne"}, + "pythonEnvironmentPath": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"A key, so that rest of the information is tied to this. (hash) Common to most of the events.","owner":"donjayamanne"}, + "pythonEnvironmentPackages": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Comma delimited list of hashed packages & their versions. Common to most of the events.","owner":"donjayamanne"}, + "kernelSessionId": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Unique identifier for an instance of a notebook session. If we restart or run this notebook tomorrow, this id will be different. Id could be something as simple as a hash of the current Epoch time. Common to most of the events.","owner":"donjayamanne"}, + "kernelLanguage": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Language of the kernel connection. Common to most of the events.","owner":"donjayamanne"}, + "kernelSpecHash": {"classification":"EndUserPseudonymizedInformation","purpose":"FeatureInsight","comment":"Hash of the kernelspec file (so we do not end up with duplicate telemetry for the same user in same session)","owner":"donjayamanne"}, + "kernelId": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Hash of the Kernel Connection id. Common to most of the events.","owner":"donjayamanne"}, + "kernelConnectionType": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Whether kernel was started using kernel spec, interpreter, etc. Common to most of the events.","owner":"donjayamanne"}, + "isUsingActiveInterpreter": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Whether this resource is using the active Python interpreter or not. Common to most of the events.","owner":"donjayamanne"}, + "capturedEnvVars": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Whether we managed to capture the environment variables or not. In the case of conda environments, `false` would be an error condition, as we must have env variables for conda to work. Common to most of the events.","owner":"donjayamanne"}, + "newKernelPicker": {"classification":"PublicNonPersonalData","purpose":"PerformanceAndHealth","comment":"Whether using the new kernel picker or not. This will be obsolete once we ship the new kernel picker.","owner":"donjayamanne"}, + "resourceType": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Used to determine whether this event is related to a Notebooks or Interactive window. Common to most of the events.","owner":"donjayamanne"}, + "extensionId": {"classification":"SystemMetaData","purpose":"FeatureInsight","comment":"Extension Id that's attempting to use the API.","owner":"donjayamanne"}, + "${include}": [ + "${F1}" + ] } */ @@ -403,8 +430,12 @@ "kernelLanguage": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Language of the kernel spec.","owner":"donjayamanne"}, "kernelId": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Hash of the Kernel Connection id.","owner":"donjayamanne"}, "cancelled": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether the completion request was cancelled or not.","owner":"donjayamanne"}, - "resolved": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether we resolved the documentation or not.","owner":"donjayamanne"}, - "resolveDuration": {"classification":"SystemMetaData","purpose":"PerformanceAndHealth","comment":"Time taken to resolve the documentation.","owner":"donjayamanne","isMeasurement":true}, + "completed": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether we completed the request.","owner":"donjayamanne"}, + "kernelStatusAfterRequest": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Status of the kernel at the time we make a request for the resolve completion information","owner":"donjayamanne"}, + "kernelStatusBeforeRequest": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Status of the kernel at the time we make a request for the resolve completion information","owner":"donjayamanne"}, + "requestSent": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether we send the request to resolve the completion item.","owner":"donjayamanne"}, + "requestDuration": {"classification":"SystemMetaData","purpose":"PerformanceAndHealth","comment":"Total time taken to complete the request.","owner":"donjayamanne","isMeasurement":true}, + "completionItems": {"classification":"SystemMetaData","purpose":"PerformanceAndHealth","comment":"Number of items returned.","owner":"donjayamanne","isMeasurement":true}, "${include}": [ "${F1}" @@ -420,6 +451,26 @@ "${include}": [ "${F1}" + ] + } + */ +//Telemetry.KernelCodeCompletionResolve +/* __GDPR__ + "DATASCIENCE.JUPYTER_KERNEL_CODE_COMPLETION_RESOLVE" : { + "kernelConnectionType": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"What kind of kernel spec did we fail to create.","owner":"donjayamanne"}, + "kernelLanguage": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Language of the kernel spec.","owner":"donjayamanne"}, + "kernelId": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Hash of the Kernel Connection id.","owner":"donjayamanne"}, + "cancelled": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether the completion request was cancelled or not.","owner":"donjayamanne"}, + "kernelStatusBeforeRequest": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Status of the kernel at the time we make a request for the resolve completion information","owner":"donjayamanne"}, + "kernelStatusAfterRequest": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Status of the kernel at the time we make a request for the resolve completion information","owner":"donjayamanne"}, + "requestTimedout": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether we timedout waiting for the request to complete.","owner":"donjayamanne"}, + "completedWithData": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether the kernel completion resolve request returned any data.","owner":"donjayamanne"}, + "requestSent": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether we send the request to resolve the completion item.","owner":"donjayamanne"}, + "completed": {"classification":"PublicNonPersonalData","purpose":"FeatureInsight","comment":"Whether we resolved the documentation or not.","owner":"donjayamanne"}, + "requestDuration": {"classification":"SystemMetaData","purpose":"PerformanceAndHealth","comment":"Total time taken to resolve the documentation.","owner":"donjayamanne","isMeasurement":true}, + "${include}": [ + "${F1}" + ] } */ diff --git a/src/kernels/kernelExecution.ts b/src/kernels/kernelExecution.ts index e7420e8b874..0a0670ad36d 100644 --- a/src/kernels/kernelExecution.ts +++ b/src/kernels/kernelExecution.ts @@ -124,6 +124,7 @@ export class NotebookKernelExecution implements INotebookKernelExecution { } public async executeCell(cell: NotebookCell, codeOverride?: string | undefined): Promise { traceCellMessage(cell, `NotebookKernelExecution.executeCell (1), ${getDisplayPath(cell.notebook.uri)}`); + const stopWatch = new StopWatch(); if (cell.kind == NotebookCellKind.Markup) { return NotebookCellRunState.Success; } @@ -133,7 +134,6 @@ export class NotebookKernelExecution implements INotebookKernelExecution { this.kernel.resourceUri, this.kernel.kernelConnectionMetadata ); - sendKernelTelemetryEvent(this.kernel.resourceUri, Telemetry.ExecuteCell); const sessionPromise = this.kernel.start(new DisplayOptions(false)); // If we're restarting, wait for it to finish @@ -149,6 +149,7 @@ export class NotebookKernelExecution implements INotebookKernelExecution { `NotebookKernelExecution.executeCell completed (3), ${getDisplayPath(cell.notebook.uri)}` ); traceVerbose(`Cell ${cell.index} executed with state ${result[0]}`); + sendKernelTelemetryEvent(this.kernel.resourceUri, Telemetry.ExecuteCell, { duration: stopWatch.elapsedTime }); return result[0]; } @@ -158,7 +159,6 @@ export class NotebookKernelExecution implements INotebookKernelExecution { this.kernel.resourceUri, this.kernel.kernelConnectionMetadata ); - sendKernelTelemetryEvent(this.kernel.resourceUri, Telemetry.ExecuteCell); const sessionPromise = this.kernel.start(new DisplayOptions(false)); // If we're restarting, wait for it to finish @@ -168,11 +168,16 @@ export class NotebookKernelExecution implements INotebookKernelExecution { const result = executionQueue.queueCode(code, extensionId, token); traceVerbose(`Queue code ${result.executionId} from ${extensionId} after ${stopWatch.elapsedTime}ms:\n${code}`); result.result - .finally( - () => - !token.isCancellationRequested && - traceInfo(`Execution of code ${result.executionId} completed in ${stopWatch.elapsedTime}ms`) - ) + .finally(() => { + !token.isCancellationRequested && + traceInfo(`Execution of code ${result.executionId} completed in ${stopWatch.elapsedTime}ms`); + sendKernelTelemetryEvent( + this.kernel.resourceUri, + Telemetry.ExecuteCode, + { duration: stopWatch.elapsedTime }, + { extensionId } + ); + }) .catch(noop); return result; } diff --git a/src/platform/common/constants.ts b/src/platform/common/constants.ts index 35ae82ec595..123e23d6823 100644 --- a/src/platform/common/constants.ts +++ b/src/platform/common/constants.ts @@ -386,6 +386,7 @@ export enum Telemetry { CellOutputMimeType = 'DS_INTERNAL.CELL_OUTPUT_MIME_TYPE', JupyterApiUsage = 'DATASCIENCE.JUPYTER_API_USAGE', KernelCodeCompletion = 'DATASCIENCE.JUPYTER_KERNEL_CODE_COMPLETION', + KernelCodeCompletionResolve = 'DATASCIENCE.JUPYTER_KERNEL_CODE_COMPLETION_RESOLVE', KernelCodeCompletionCannotResolve = 'DATASCIENCE.JUPYTER_KERNEL_CODE_COMPLETION_CANNOT_RESOLVE', JupyterKernelApiUsage = 'DATASCIENCE.JUPYTER_KERNEL_API_USAGE', NewJupyterKernelApiUsage = 'DATASCIENCE.JUPYTER_NEW_KERNEL_API_USAGE', @@ -446,6 +447,7 @@ export enum Telemetry { SwitchKernel = 'DS_INTERNAL.SWITCH_KERNEL', KernelCount = 'DS_INTERNAL.KERNEL_COUNT', ExecuteCell = 'DATASCIENCE.EXECUTE_CELL', + ExecuteCode = 'DATASCIENCE.EXECUTE_CODE', ResumeCellExecution = 'DATASCIENCE.RESUME_EXECUTE_CELL', /** * Sent when a command we register is executed. diff --git a/src/platform/common/types.ts b/src/platform/common/types.ts index 561652246ae..e6629da7e27 100644 --- a/src/platform/common/types.ts +++ b/src/platform/common/types.ts @@ -296,7 +296,8 @@ export interface IAsyncDisposableRegistry extends IAsyncDisposable { } export enum Experiments { - DataViewerContribution = 'DataViewerContribution' + DataViewerContribution = 'DataViewerContribution', + KernelCompletions = 'KernelCompletions' } /** diff --git a/src/platform/telemetry/index.ts b/src/platform/telemetry/index.ts index bafe74e5e74..2dcd0df9c43 100644 --- a/src/platform/telemetry/index.ts +++ b/src/platform/telemetry/index.ts @@ -131,6 +131,20 @@ export function sendTelemetryEvent

= P[E] extends TelemetryEventInfo + ? ExcludeType extends never | undefined + ? undefined + : ExcludeType + : undefined | undefined; + +export type TelemetryMeasures< + E extends keyof P, + P extends IEventNamePropertyMapping = IEventNamePropertyMapping +> = P[E] extends TelemetryEventInfo ? PickType, number> : undefined; + function sendTelemetryEventInternal

( eventName: E, measures?: Record, diff --git a/src/standalone/intellisense/helpers.ts b/src/standalone/intellisense/helpers.ts new file mode 100644 index 00000000000..42af57905b8 --- /dev/null +++ b/src/standalone/intellisense/helpers.ts @@ -0,0 +1,17 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +export function generateSortString(index: number) { + // If its 0, then use AA, if 25, then use ZZ + // This will give us the ability to sort first 700 items (thats more than enough). + // To keep things fast we'll only sort the first 300. + if (index >= 300) { + return 'ZZZZZZZ'; + } + if (index <= 25) { + return `A${String.fromCharCode(65 + index)}`; + } + const firstChar = String.fromCharCode(65 + Math.ceil(index / 25)); + const secondChar = String.fromCharCode(65 + (index % 25)); + return `${firstChar}${secondChar}`; +} diff --git a/src/standalone/intellisense/nonPythonKernelCompletionProvider.ts b/src/standalone/intellisense/nonPythonKernelCompletionProvider.ts index c8136fc44ed..4fa99611860 100644 --- a/src/standalone/intellisense/nonPythonKernelCompletionProvider.ts +++ b/src/standalone/intellisense/nonPythonKernelCompletionProvider.ts @@ -17,7 +17,13 @@ import { } from 'vscode'; import { raceCancellation } from '../../platform/common/cancellation'; import { traceInfo, traceVerbose, traceWarning } from '../../platform/logging'; -import { IDisposable, IDisposableRegistry, Resource } from '../../platform/common/types'; +import { + Experiments, + IDisposable, + IDisposableRegistry, + IExperimentService, + Resource +} from '../../platform/common/types'; import { StopWatch } from '../../platform/common/utils/stopWatch'; import { IKernelProvider, IKernel } from '../../kernels/types'; import { INotebookEditorProvider } from '../../notebooks/types'; @@ -27,35 +33,25 @@ import { INotebookCompletion } from './types'; import { translateKernelLanguageToMonaco } from '../../platform/common/utils'; import { IExtensionSyncActivationService } from '../../platform/activation/types'; import { ServiceContainer } from '../../platform/ioc/container'; -import { DisposableBase } from '../../platform/common/utils/lifecycle'; -import { generateSortString } from './pythonKernelCompletionProvider'; -import { raceTimeout, sleep } from '../../platform/common/utils/async'; -import { sendTelemetryEvent } from '../../telemetry'; +import { DisposableBase, DisposableStore } from '../../platform/common/utils/lifecycle'; +import { sleep } from '../../platform/common/utils/async'; +import { TelemetryMeasures, TelemetryProperties, sendTelemetryEvent } from '../../telemetry'; import { getTelemetrySafeHashedString } from '../../platform/telemetry/helpers'; import { getDisplayNameOrNameOfKernelConnection } from '../../kernels/helpers'; -import type { KernelMessage } from '@jupyterlab/services'; -import { stripAnsi } from '../../platform/common/utils/regexp'; - -// Not all kernels support requestInspect method. -// E.g. deno does not support this, hence waiting for this to complete is poinless. -// As that results in a `loading...` method to appear against the completion item. -// If we have n consecutive attempts where the response never comes back in 1s, -// then we'll always ignore `requestInspect` method for this kernel. -const MAX_ATTEMPTS_BEFORE_IGNORING_RESOLVE_COMPLETION = 5; -const MAX_TIMEOUT_WAITING_FOR_RESOLVE_COMPLETION = 1_000; - -const kernelIdsThatToNotSupportCompletionResolve = new Set(); +import { generateSortString } from './helpers'; +import { resolveCompletionItem } from './resolveCompletionItem'; -class NotebookCellSpecificKernelCompletionProvider implements CompletionItemProvider { - private totalNumberOfTimeoutsWaitingForResolveCompletion = 0; - constructor(private readonly kernel: IKernel) {} - public get canResolveCompletionItem() { - return this.totalNumberOfTimeoutsWaitingForResolveCompletion < MAX_ATTEMPTS_BEFORE_IGNORING_RESOLVE_COMPLETION; - } +export class NotebookCellSpecificKernelCompletionProvider implements CompletionItemProvider { + constructor( + private readonly kernelId: string, + private readonly kernel: IKernel, + private readonly monacoLanguage: string, + private readonly toDispose: DisposableStore + ) {} private previousCompletionItems = new WeakMap< CompletionItem, - { code: string; cursor: { start: number; end: number } } + { documentRef: WeakRef; position: Position } >(); async provideCompletionItems( document: TextDocument, @@ -71,23 +67,31 @@ class NotebookCellSpecificKernelCompletionProvider implements CompletionItemProv return []; } const stopWatch = new StopWatch(); + const measures: TelemetryMeasures = { + duration: 0, + requestDuration: 0, + completionItems: 0 + }; + const properties: TelemetryProperties = { + kernelId: this.kernelId, + kernelConnectionType: this.kernel.kernelConnectionMetadata.kind, + kernelLanguage: this.monacoLanguage, + cancelled: false, + kernelStatusBeforeRequest: this.kernel.status, + completed: false, + requestSent: false + }; // No point sending completions if we're not connected. // Even if we're busy restarting, then no point, by the time it starts, the user would have typed something else // Hence no point sending requests that would unnecessarily slow things down. - if ( - this.kernel.status === 'autorestarting' || - this.kernel.status === 'dead' || - this.kernel.status === 'restarting' || - this.kernel.status === 'terminating' || - this.kernel.status === 'unknown' - ) { - return []; - } - if (!this.kernel.session?.kernel) { + if (this.kernel.status !== 'idle' || !this.kernel.session?.kernel) { + sendTelemetryEvent(Telemetry.KernelCodeCompletion, measures, properties); return []; } const code = document.getText(); const cursor_pos = document.offsetAt(position); + + properties.requestSent = true; const kernelCompletions = await raceCancellation( token, this.kernel.session.kernel.requestComplete({ @@ -96,15 +100,16 @@ class NotebookCellSpecificKernelCompletionProvider implements CompletionItemProv }) ); traceVerbose(`Jupyter completion time: ${stopWatch.elapsedTime}`); + properties.cancelled = token.isCancellationRequested; + properties.kernelStatusAfterRequest = this.kernel.status; + measures.requestDuration = token.isCancellationRequested ? 0 : stopWatch.elapsedTime; + if ( token.isCancellationRequested || - !kernelCompletions || - !kernelCompletions.content || - kernelCompletions.content.status !== 'ok' + kernelCompletions?.content?.status !== 'ok' || + (kernelCompletions?.content?.matches?.length ?? 0) === 0 ) { - return []; - } - if (kernelCompletions.content.matches.length === 0) { + sendTelemetryEvent(Telemetry.KernelCodeCompletion, measures, properties); return []; } const result: INotebookCompletion = { @@ -117,28 +122,37 @@ class NotebookCellSpecificKernelCompletionProvider implements CompletionItemProv }; const experimentMatches = result.metadata ? result.metadata._jupyter_types_experimental : []; + measures.completionItems = result.matches.length; + sendTelemetryEvent(Telemetry.KernelCodeCompletion, measures, properties); + // Check if we have more information about the completion items & whether its valid. // This will ensure that we don't regress (as long as all items are valid & we have the same number of completions items // then we should be able to use the experiment matches value) - const dataToStore = { code, cursor: result.cursor }; + const dataToStore = { + code, + cursor: result.cursor, + documentRef: new WeakRef(document), + position: document.positionAt(result.cursor.start) + }; + const range = new Range(document.positionAt(result.cursor.start), document.positionAt(result.cursor.end)); + if ( Array.isArray(experimentMatches) && experimentMatches.length >= result.matches.length && - experimentMatches.every( - (item) => - item && - typeof item.start === 'number' && - typeof item.end === 'number' && - typeof item.text === 'string' - ) + experimentMatches.every((item) => item && typeof item.text === 'string') ) { + // This works for Julia and Python kernels, haven't tested others. return kernelCompletions.content.matches.map((label, index) => { const item = experimentMatches[index]; const type = item.type ? mapJupyterKind.get(item.type) : CompletionItemKind.Field; const completionItem = new CompletionItem(label, type); - completionItem.range = new Range(document.positionAt(item.start), document.positionAt(item.end)); + if (typeof item.start === 'number' && typeof item.end === 'number') { + completionItem.range = new Range(document.positionAt(item.start), document.positionAt(item.end)); + } else { + completionItem.range = range; + } completionItem.insertText = item.text; completionItem.sortText = generateSortString(index); this.previousCompletionItems.set(completionItem, dataToStore); @@ -148,10 +162,7 @@ class NotebookCellSpecificKernelCompletionProvider implements CompletionItemProv return result.matches.map((label, index) => { const completionItem = new CompletionItem(label); - completionItem.range = new Range( - document.positionAt(result.cursor.start), - document.positionAt(result.cursor.end) - ); + completionItem.range = range; completionItem.sortText = generateSortString(index); this.previousCompletionItems.set(completionItem, dataToStore); return completionItem; @@ -171,69 +182,52 @@ class NotebookCellSpecificKernelCompletionProvider implements CompletionItemProv if (!info) { return item; } - const { code, cursor } = info; - const newCode = code.substring(0, cursor.start) + (item.insertText || item.label); - const cursor_pos = - cursor.start + - ( - (typeof item.insertText === 'string' ? item.insertText : item.insertText?.value) || - (typeof item.label === 'string' ? item.label : item.label.label) || - '' - ).length; - const contents: KernelMessage.IInspectRequestMsg['content'] = { - code: newCode, - cursor_pos, - detail_level: 0 - }; - const stopWatch = new StopWatch(); - const msg = await raceTimeout( - MAX_TIMEOUT_WAITING_FOR_RESOLVE_COMPLETION, - raceCancellation(token, this.kernel.session.kernel.requestInspect(contents)) - ); - if (token.isCancellationRequested) { - return item; - } - if (!msg || msg.content.status !== 'ok' || !msg.content.found) { - if (stopWatch.elapsedTime > MAX_TIMEOUT_WAITING_FOR_RESOLVE_COMPLETION) { - this.totalNumberOfTimeoutsWaitingForResolveCompletion += 1; - } + const { documentRef, position } = info; + const document = documentRef.deref(); + if (!document) { return item; } - item.documentation = stripAnsi(msg.content.data['text/plain'] as string); - return item; + return resolveCompletionItem( + item, + token, + this.kernel, + this.kernelId, + this.monacoLanguage, + document, + position, + this.toDispose + ); } } class KernelSpecificCompletionProvider extends DisposableBase implements CompletionItemProvider { private cellCompletionProviders = new WeakMap(); - private completionItemsSent = new WeakMap< - CompletionItem, - { duration: number; provider: NotebookCellSpecificKernelCompletionProvider } - >(); - private readonly monacoLanguage: string; - private readonly kernelLanguage: string; + private completionItemsSent = new WeakMap(); private completionProvider?: IDisposable; + private readonly monacoLanguage = getKernelLanguageAsMonacoLanguage(this.kernel); + private readonly toDispose = this._register(new DisposableStore()); constructor( - private readonly kernelId: string, private readonly kernel: IKernel, private readonly notebookEditorProvider: INotebookEditorProvider ) { super(); - this.kernelLanguage = getKernelLanguage(kernel); - this.monacoLanguage = getKernelLanguageAsMonacoLanguage(kernel); this.registerCompletionProvider(); this._register( workspace.onDidChangeConfiguration((e) => { if (e.affectsConfiguration('jupyter.enableKernelCompletions')) { if (!isKernelCompletionEnabled(this.kernel.notebook.uri)) { this.completionProvider?.dispose(); + this.completionProvider = undefined; return; + } else if (!this.completionProvider) { + this.registerCompletionProvider(); } } if (!e.affectsConfiguration('jupyter.completionTriggerCharacters')) { return; } this.completionProvider?.dispose(); + this.completionProvider = undefined; this.registerCompletionProvider(); }) ); @@ -243,28 +237,12 @@ class KernelSpecificCompletionProvider extends DisposableBase implements Complet return; } - const triggerCharacters = this.getCompletionTriggerCharacter(); + const triggerCharacters = getCompletionTriggerCharacter(this.kernel); if (triggerCharacters.length === 0) { - if (this.kernelLanguage.toLowerCase() === this.monacoLanguage.toLowerCase()) { - traceWarning( - l10n.t( - `Kernel completions not enabled for '{0}'. \nTo enable Kernel completion for this language please add the following setting \njupyter.completionTriggerCharacters = {1}: []}. \nFor more information please see https://aka.ms/vscodeJupyterCompletion`, - getDisplayNameOrNameOfKernelConnection(this.kernel.kernelConnectionMetadata), - `{${this.kernelLanguage}` - ) - ); - } else { - traceWarning( - l10n.t( - `Kernel completions not enabled for '{0}'. \nTo enable Kernel completion for this language please add the following setting \njupyter.completionTriggerCharacters = {1}: []}. \n or the following: \njupyter.completionTriggerCharacters = {2}: []}. \nFor more information please see https://aka.ms/vscodeJupyterCompletion`, - getDisplayNameOrNameOfKernelConnection(this.kernel.kernelConnectionMetadata), - `{${this.kernelLanguage}`, - `{${this.monacoLanguage}` - ) - ); - } + logHowToEnableKernelCompletion(this.kernel); return; } + traceInfo( `Registering Kernel Completion Provider from kernel ${getDisplayNameOrNameOfKernelConnection( this.kernel.kernelConnectionMetadata @@ -275,30 +253,7 @@ class KernelSpecificCompletionProvider extends DisposableBase implements Complet this, ...triggerCharacters ); - } - private getCompletionTriggerCharacter() { - const triggerCharacters = workspace - .getConfiguration('jupyter', this.kernel.notebook.uri) - .get>('completionTriggerCharacters'); - - // Check if object, as this used to be a different setting a few years ago (when it was specific to Python). - if (!triggerCharacters || typeof triggerCharacters !== 'object') { - return []; - } - // Always use the kernel language first, then the monaco language. - // Thats because kernel language could be something like `bash` - // However there's no such language in vscode (monoca), and those get treated as `shellscript` - // Such the kernel language `bash` ends up getting translated to the monaco language `shellscript`. - // But we need to give preference to the language the users see in their kernelspecs and thats `bash` - if (this.kernelLanguage in triggerCharacters) { - // Possible a user still has some old setting. - return Array.isArray(triggerCharacters[this.kernelLanguage]) ? triggerCharacters[this.kernelLanguage] : []; - } - if (this.monacoLanguage in triggerCharacters) { - // Possible a user still has some old setting. - return Array.isArray(triggerCharacters[this.monacoLanguage]) ? triggerCharacters[this.monacoLanguage] : []; - } - return []; + return; } override dispose() { super.dispose(); @@ -315,57 +270,23 @@ class KernelSpecificCompletionProvider extends DisposableBase implements Complet } let provider = this.cellCompletionProviders.get(document); if (!provider) { - provider = new NotebookCellSpecificKernelCompletionProvider(this.kernel); + const kernelId = await getTelemetrySafeHashedString(this.kernel.kernelConnectionMetadata.id); + provider = new NotebookCellSpecificKernelCompletionProvider( + kernelId, + this.kernel, + this.monacoLanguage, + this.toDispose + ); this.cellCompletionProviders.set(document, provider); } - const stopWatch = new StopWatch(); - const items = await provider.provideCompletionItems(document, position, token, _context); - const duration = stopWatch.elapsedTime; - sendTelemetryEvent( - Telemetry.KernelCodeCompletion, - { duration, resolveDuration: 0 }, - { - kernelId: this.kernelId, - kernelConnectionType: this.kernel.kernelConnectionMetadata.kind, - kernelLanguage: this.monacoLanguage, - cancelled: token.isCancellationRequested - } - ); - const data = { duration, provider }; - items.forEach((item) => this.completionItemsSent.set(item, data)); - return items; + return provider.provideCompletionItems(document, position, token, _context).then((items) => { + items.forEach((item) => this.completionItemsSent.set(item, provider!)); + return items; + }); } async resolveCompletionItem(item: CompletionItem, token: CancellationToken): Promise { - const info = this.completionItemsSent.get(item); - if (!info || kernelIdsThatToNotSupportCompletionResolve.has(this.kernelId)) { - return item; - } - const { duration, provider } = info; - if (!provider.canResolveCompletionItem) { - // Never send the telemetry again and do not try in this session. - kernelIdsThatToNotSupportCompletionResolve.add(this.kernelId); - sendTelemetryEvent(Telemetry.KernelCodeCompletionCannotResolve, undefined, { - kernelId: this.kernelId, - kernelConnectionType: this.kernel.kernelConnectionMetadata.kind, - kernelLanguage: this.monacoLanguage - }); - return item; - } - - const stopWatch = new StopWatch(); - return provider.resolveCompletionItem(item, token).finally(() => { - sendTelemetryEvent( - Telemetry.KernelCodeCompletion, - { duration, resolveDuration: stopWatch.elapsedTime }, - { - kernelId: this.kernelId, - kernelConnectionType: this.kernel.kernelConnectionMetadata.kind, - kernelLanguage: this.monacoLanguage, - cancelled: token.isCancellationRequested, - resolved: true - } - ); - }); + const provider = this.completionItemsSent.get(item); + return provider ? provider.resolveCompletionItem(item, token) : item; } } @@ -383,10 +304,10 @@ export class NonPythonKernelCompletionProvider extends DisposableBase implements const kernelProvider = ServiceContainer.instance.get(IKernelProvider); this._register( kernelProvider.onDidStartKernel(async (e) => { - if (!isKernelCompletionEnabled(e.notebook.uri)) { + const experiment = ServiceContainer.instance.get(IExperimentService); + if (!experiment.inExperiment(Experiments.KernelCompletions)) { return; } - const kernelId = await getTelemetrySafeHashedString(e.kernelConnectionMetadata.id); const language = getKernelLanguageAsMonacoLanguage(e); if (!language || language.toLowerCase() === PYTHON_LANGUAGE.toLowerCase()) { return; @@ -396,9 +317,7 @@ export class NonPythonKernelCompletionProvider extends DisposableBase implements } const notebookProvider = ServiceContainer.instance.get(INotebookEditorProvider); - const completionProvider = this._register( - new KernelSpecificCompletionProvider(kernelId, e, notebookProvider) - ); + const completionProvider = this._register(new KernelSpecificCompletionProvider(e, notebookProvider)); this.kernelCompletionProviders.set(e, completionProvider); }) ); @@ -436,3 +355,53 @@ function getKernelLanguage(kernel: IKernel) { function isKernelCompletionEnabled(resource: Resource) { return workspace.getConfiguration('jupyter', resource).get('enableKernelCompletions', false); } + +function getCompletionTriggerCharacter(kernel: IKernel) { + const triggerCharacters = workspace + .getConfiguration('jupyter', kernel.notebook.uri) + .get>('completionTriggerCharacters'); + + // Check if object, as this used to be a different setting a few years ago (when it was specific to Python). + if (!triggerCharacters || typeof triggerCharacters !== 'object') { + return []; + } + const kernelLanguage = getKernelLanguage(kernel); + const monacoLanguage = getKernelLanguageAsMonacoLanguage(kernel); + // Always use the kernel language first, then the monaco language. + // Thats because kernel language could be something like `bash` + // However there's no such language in vscode (monoca), and those get treated as `shellscript` + // Such the kernel language `bash` ends up getting translated to the monaco language `shellscript`. + // But we need to give preference to the language the users see in their kernelspecs and thats `bash` + if (kernelLanguage in triggerCharacters) { + // Possible a user still has some old setting. + return Array.isArray(triggerCharacters[kernelLanguage]) ? triggerCharacters[kernelLanguage] : []; + } + if (monacoLanguage in triggerCharacters) { + // Possible a user still has some old setting. + return Array.isArray(triggerCharacters[monacoLanguage]) ? triggerCharacters[monacoLanguage] : []; + } + return []; +} + +function logHowToEnableKernelCompletion(kernel: IKernel) { + const kernelLanguage = getKernelLanguage(kernel); + const monacoLanguage = getKernelLanguageAsMonacoLanguage(kernel); + if (kernelLanguage.toLowerCase() === monacoLanguage.toLowerCase()) { + traceWarning( + l10n.t( + `Kernel completions not enabled for '{0}'. \nTo enable Kernel completion for this language please add the following setting \njupyter.completionTriggerCharacters = {1}: []}. \nFor more information please see https://aka.ms/vscodeJupyterCompletion`, + getDisplayNameOrNameOfKernelConnection(kernel.kernelConnectionMetadata), + `{${kernelLanguage}` + ) + ); + } else { + traceWarning( + l10n.t( + `Kernel completions not enabled for '{0}'. \nTo enable Kernel completion for this language please add the following setting \njupyter.completionTriggerCharacters = {1}: []}. \n or the following: \njupyter.completionTriggerCharacters = {2}: []}. \nFor more information please see https://aka.ms/vscodeJupyterCompletion`, + getDisplayNameOrNameOfKernelConnection(kernel.kernelConnectionMetadata), + `{${kernelLanguage}`, + `{${monacoLanguage}` + ) + ); + } +} diff --git a/src/standalone/intellisense/pythonKernelCompletionProvider.ts b/src/standalone/intellisense/pythonKernelCompletionProvider.ts index 6fe37ffb2ac..334ccdf8d52 100644 --- a/src/standalone/intellisense/pythonKernelCompletionProvider.ts +++ b/src/standalone/intellisense/pythonKernelCompletionProvider.ts @@ -19,14 +19,19 @@ import { getDisplayPath } from '../../platform/common/platform/fs-paths'; import { IConfigurationService, IDisposableRegistry } from '../../platform/common/types'; import { isNotebookCell, noop } from '../../platform/common/utils/misc'; import { StopWatch } from '../../platform/common/utils/stopWatch'; -import { IKernelSession, IKernelProvider } from '../../kernels/types'; +import { IKernelSession, IKernelProvider, IKernel } from '../../kernels/types'; import { INotebookCompletionProvider, INotebookEditorProvider } from '../../notebooks/types'; import { mapJupyterKind } from './conversion'; -import { isTestExecution, Settings } from '../../platform/common/constants'; +import { isTestExecution, PYTHON_LANGUAGE, Settings, Telemetry } from '../../platform/common/constants'; import { INotebookCompletion } from './types'; import { getAssociatedJupyterNotebook } from '../../platform/common/utils'; import { raceTimeout } from '../../platform/common/utils/async'; import { isPythonKernelConnection } from '../../kernels/helpers'; +import { sendTelemetryEvent } from '../../telemetry'; +import { getTelemetrySafeHashedString } from '../../platform/telemetry/helpers'; +import { generateSortString } from './helpers'; +import { resolveCompletionItem } from './resolveCompletionItem'; +import { DisposableStore } from '../../platform/common/utils/lifecycle'; let IntellisenseTimeout = Settings.IntellisenseTimeout; export function setIntellisenseTimeout(timeoutMs: number) { @@ -44,6 +49,18 @@ export type JupyterCompletionItem = CompletionItem & { @injectable() export class PythonKernelCompletionProvider implements CompletionItemProvider { private allowStringFilter = false; + private readonly toDispose = new DisposableStore(); + private completionItemsSent = new WeakMap< + CompletionItem, + { + documentRef: WeakRef; + kernelRef: WeakRef; + duration: number; + kernelId: string; + position: Position; + } + >(); + constructor( @inject(IKernelProvider) private readonly kernelProvider: IKernelProvider, @inject(INotebookEditorProvider) private readonly notebookEditorProvider: INotebookEditorProvider, @@ -53,6 +70,7 @@ export class PythonKernelCompletionProvider implements CompletionItemProvider { @inject(IConfigurationService) config: IConfigurationService, @inject(IDisposableRegistry) disposables: IDisposableRegistry ) { + disposables.push(this.toDispose); this.kernelProvider.onDidStartKernel( (kernel) => { if (kernel.session?.kernel && isPythonKernelConnection(kernel.kernelConnectionMetadata)) { @@ -93,6 +111,7 @@ export class PythonKernelCompletionProvider implements CompletionItemProvider { token: CancellationToken, context: CompletionContext ): Promise { + const stopWatch = new StopWatch(); if (!isNotebookCell(document)) { return []; } @@ -109,12 +128,13 @@ export class PythonKernelCompletionProvider implements CompletionItemProvider { } // Allow slower timeouts for CI (testing). traceInfoIfCI(`Notebook completion request for ${document.getText()}, ${document.offsetAt(position)}`); - const [result, pylanceResults] = await Promise.all([ + const [result, pylanceResults, kernelId] = await Promise.all([ raceTimeout( IntellisenseTimeout, this.getJupyterCompletion(kernel.session, document.getText(), document.offsetAt(position), token) ), - raceTimeout(IntellisenseTimeout, this.getPylanceCompletions(document, position, context, token)) + raceTimeout(IntellisenseTimeout, this.getPylanceCompletions(document, position, context, token)), + getTelemetrySafeHashedString(kernel.kernelConnectionMetadata.id) ]); if (!result) { traceInfoIfCI(`Notebook completions not found.`); @@ -166,7 +186,7 @@ export class PythonKernelCompletionProvider implements CompletionItemProvider { } // Filter the list based on where we are in a cell (and the type of cell) - return filterCompletions( + completions = filterCompletions( context.triggerCharacter, this.allowStringFilter, completions, @@ -174,7 +194,56 @@ export class PythonKernelCompletionProvider implements CompletionItemProvider { document, position ); + const documentRef = new WeakRef(document); + const kernelRef = new WeakRef(kernel); + const duration = stopWatch.elapsedTime; + completions.forEach((item) => + this.completionItemsSent.set(item, { + documentRef, + kernelRef, + duration, + kernelId, + position + }) + ); + sendTelemetryEvent( + Telemetry.KernelCodeCompletion, + { duration, completionItems: completions.length, requestDuration: duration }, + { + kernelId, + kernelConnectionType: kernel.kernelConnectionMetadata.kind, + kernelLanguage: PYTHON_LANGUAGE, + cancelled: token.isCancellationRequested, + completed: true, + requestSent: true, + kernelStatusAfterRequest: kernel.status + } + ); + return completions; } + async resolveCompletionItem(item: CompletionItem, token: CancellationToken): Promise { + const info = this.completionItemsSent.get(item); + if (!info) { + return item; + } + const { kernelId, kernelRef, documentRef, position } = info; + const document = documentRef.deref(); + const kernel = kernelRef.deref(); + if (!document || !kernel || !kernel.session?.kernel) { + return item; + } + return resolveCompletionItem( + item, + token, + kernel, + kernelId, + PYTHON_LANGUAGE, + document, + position, + this.toDispose + ); + } + public async getJupyterCompletion( session: IKernelSession, cellCode: string, @@ -254,21 +323,6 @@ function positionInsideString(line: string, position: Position) { return index >= 0 && position.character > index && position.character <= lastIndex; } -export function generateSortString(index: number) { - // If its 0, then use AA, if 25, then use ZZ - // This will give us the ability to sort first 700 items (thats more than enough). - // To keep things fast we'll only sort the first 300. - if (index >= 300) { - return 'ZZZZZZZ'; - } - if (index <= 25) { - return `A${String.fromCharCode(65 + index)}`; - } - const firstChar = String.fromCharCode(65 + Math.ceil(index / 25)); - const secondChar = String.fromCharCode(65 + (index % 25)); - return `${firstChar}${secondChar}`; -} - // Exported for unit testing export function filterCompletions( triggerCharacter: string | undefined, diff --git a/src/standalone/intellisense/pythonKernelCompletionProvider.unit.test.ts b/src/standalone/intellisense/pythonKernelCompletionProvider.unit.test.ts index 07585b3949e..b4b93964d88 100644 --- a/src/standalone/intellisense/pythonKernelCompletionProvider.unit.test.ts +++ b/src/standalone/intellisense/pythonKernelCompletionProvider.unit.test.ts @@ -3,8 +3,9 @@ import { assert } from 'chai'; import * as vscode from 'vscode'; -import { JupyterCompletionItem, generateSortString, filterCompletions } from './pythonKernelCompletionProvider'; +import { JupyterCompletionItem, filterCompletions } from './pythonKernelCompletionProvider'; import { MockDocument } from '../../test/datascience/mockDocument'; +import { generateSortString } from './helpers'; suite('Jupyter Completion Unit Tests', () => { let mockDocument: MockDocument; diff --git a/src/standalone/intellisense/resolveCompletionItem.ts b/src/standalone/intellisense/resolveCompletionItem.ts new file mode 100644 index 00000000000..009b9ce53b7 --- /dev/null +++ b/src/standalone/intellisense/resolveCompletionItem.ts @@ -0,0 +1,186 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +import { CancellationToken, CompletionItem, Disposable, Position, TextDocument } from 'vscode'; +import { IKernel } from '../../kernels/types'; +import { StopWatch } from '../../platform/common/utils/stopWatch'; +import { Telemetry, TelemetryMeasures, TelemetryProperties, sendTelemetryEvent } from '../../telemetry'; +import type { Kernel, KernelMessage } from '@jupyterlab/services'; +import { raceTimeoutError } from '../../platform/common/utils/async'; +import { raceCancellation } from '../../platform/common/cancellation'; +import { DisposableStore } from '../../platform/common/utils/lifecycle'; +import { stripAnsi } from '../../platform/common/utils/regexp'; +import { traceWarning } from '../../platform/logging'; +import { getDisplayNameOrNameOfKernelConnection } from '../../kernels/helpers'; +import { Settings } from '../../platform/common/constants'; + +// Not all kernels support requestInspect method. +// E.g. deno does not support this, hence waiting for this to complete is poinless. +// As that results in a `loading...` method to appear against the completion item. +// If we have n consecutive attempts where the response never comes back in 1s, +// then we'll always ignore `requestInspect` method for this kernel. +export const MAX_ATTEMPTS_BEFORE_IGNORING_RESOLVE_COMPLETION = 5; +const MAX_TIMEOUT_WAITING_FOR_RESOLVE_COMPLETION = Settings.IntellisenseTimeout; + +const kernelIdsThatToNotSupportCompletionResolveOrAreTooSlowToReply = new Set(); +const totalNumberOfTimeoutsWaitingForResolveCompletionPerKernel = new Map(); + +class RequestTimedoutError extends Error { + constructor() { + super('Request timed out'); + } +} + +export async function resolveCompletionItem( + item: CompletionItem, + token: CancellationToken, + kernel: IKernel, + kernelId: string, + monacoLanguage: string, + document: TextDocument, + position: Position, + toDispose: DisposableStore +): Promise { + if (!item.range || !kernel.session?.kernel) { + // We always set a range in the completion item we send. + // Except for Python. + return item; + } + if (kernelIdsThatToNotSupportCompletionResolveOrAreTooSlowToReply.has(kernelId)) { + return item; + } + + const stopWatch = new StopWatch(); + const measures: TelemetryMeasures = { + duration: 0, + requestDuration: 0 + }; + const properties: TelemetryProperties = { + kernelId: kernelId, + kernelConnectionType: kernel.kernelConnectionMetadata.kind, + kernelLanguage: monacoLanguage, + cancelled: false, + completed: false, + completedWithData: false, + kernelStatusBeforeRequest: kernel.status, + requestSent: false + }; + + // We do not want to delay sending completion data because kernel is busy. + // Also we do not want to make things worse, as kernel is already busy why slow it even further. + if (kernel.status !== 'idle') { + sendTelemetryEvent(Telemetry.KernelCodeCompletionResolve, measures, properties); + return item; + } + properties.requestSent = true; + const request = sendInspectRequest(item, document, position, kernel.session.kernel); + + try { + const msg = await raceTimeoutError( + MAX_TIMEOUT_WAITING_FOR_RESOLVE_COMPLETION, + new RequestTimedoutError(), + raceCancellation(token, request) + ); + + properties.kernelStatusAfterRequest = kernel.status; + properties.cancelled = token.isCancellationRequested; + properties.completed = !token.isCancellationRequested; + measures.duration = stopWatch.elapsedTime; + measures.requestDuration = properties.completed ? stopWatch.elapsedTime : 0; + + if (!properties.cancelled && msg?.content?.status === 'ok' && msg?.content?.found) { + const documentation = stripAnsi(msg.content.data['text/plain'] as string); + item.documentation = documentation; + properties.completedWithData = documentation.length > 0; + } + } catch (ex) { + properties.requestTimedout = ex instanceof RequestTimedoutError; + handleKernelRequestTimeout(kernel, monacoLanguage); + } + if (properties.cancelled || properties.requestTimedout) { + checkHowLongKernelTakesToReplyEvenAfterTimeoutOrCancellation( + request, + stopWatch, + properties, + measures, + toDispose + ); + } + + sendTelemetryEvent(Telemetry.KernelCodeCompletionResolve, measures, properties); + return item; +} + +function handleKernelRequestTimeout(kernel: IKernel, monacoLanguage: string) { + const kernelId = kernel.kernelConnectionMetadata.id; + if (kernelIdsThatToNotSupportCompletionResolveOrAreTooSlowToReply.has(kernelId)) { + return; + } + let numberOfFailedAttempts = totalNumberOfTimeoutsWaitingForResolveCompletionPerKernel.get(kernelId) || 0; + numberOfFailedAttempts += 1; + totalNumberOfTimeoutsWaitingForResolveCompletionPerKernel.set(kernelId, numberOfFailedAttempts); + if (numberOfFailedAttempts >= MAX_ATTEMPTS_BEFORE_IGNORING_RESOLVE_COMPLETION) { + traceWarning( + `Failed to resolve completion items for kernel ${getDisplayNameOrNameOfKernelConnection( + kernel.kernelConnectionMetadata + )} ${numberOfFailedAttempts} times.}` + ); + sendTelemetryEvent(Telemetry.KernelCodeCompletionCannotResolve, undefined, { + kernelId: kernelId, + kernelConnectionType: kernel.kernelConnectionMetadata.kind, + kernelLanguage: monacoLanguage + }); + kernelIdsThatToNotSupportCompletionResolveOrAreTooSlowToReply.add(kernelId); + return; + } +} + +function sendInspectRequest( + item: CompletionItem, + document: TextDocument, + position: Position, + kernel: Kernel.IKernelConnection +): Promise { + const code = document.getText(); + const insertText = + (typeof item.insertText === 'string' ? item.insertText : item.insertText?.value) || + (typeof item.label === 'string' ? item.label : item.label.label) || + ''; + const newCode = code.substring(0, position.character) + insertText; + const cursor_pos = position.character + insertText.length; + const contents: KernelMessage.IInspectRequestMsg['content'] = { + code: newCode, + cursor_pos, + detail_level: 0 + }; + + return kernel.requestInspect(contents); +} +function checkHowLongKernelTakesToReplyEvenAfterTimeoutOrCancellation( + request: Promise, + stopWatch: StopWatch, + telemetryInfo: TelemetryProperties, + measures: TelemetryMeasures, + toDispose: DisposableStore +) { + // Do not wait too long + // Some kernels do not support this request, this will give + // an indication that they never work. + const timeout = setTimeout(() => { + telemetryInfo.requestTimedout = true; + measures.requestDuration = stopWatch.elapsedTime; + sendTelemetryEvent(Telemetry.KernelCodeCompletionResolve, measures, telemetryInfo); + }, MAX_TIMEOUT_WAITING_FOR_RESOLVE_COMPLETION * 10); + const timeoutDisposable = new Disposable(() => clearTimeout(timeout)); + toDispose.add(new Disposable(() => clearTimeout(timeout))); + + void request.finally(() => { + timeoutDisposable.dispose(); + measures.requestDuration = stopWatch.elapsedTime; + // Wait for completion and send the total time taken + // Its possible that user may have cancelled this operation, + // but kernel is still busy processing this request. + // With this data we will know that completions take too long and can slow the kernel down. + sendTelemetryEvent(Telemetry.KernelCodeCompletionResolve, measures, telemetryInfo); + }); +} diff --git a/src/standalone/intellisense/resolveCompletionItem.unit.test.ts b/src/standalone/intellisense/resolveCompletionItem.unit.test.ts new file mode 100644 index 00000000000..fd10e41aabd --- /dev/null +++ b/src/standalone/intellisense/resolveCompletionItem.unit.test.ts @@ -0,0 +1,266 @@ +// Copyright (c) Microsoft Corporation. +// Licensed under the MIT License. + +import { assert } from 'chai'; +import uuid from 'uuid/v4'; +import * as fakeTimers from '@sinonjs/fake-timers'; +import { Kernel } from '@jupyterlab/services'; +import { anything, instance, mock, reset, verify, when } from 'ts-mockito'; +import { IKernel, IKernelSession, KernelConnectionMetadata } from '../../kernels/types'; +import { createMockedDocument } from '../../test/datascience/editor-integration/helpers'; +import { + CancellationToken, + CancellationTokenSource, + CompletionItem, + Disposable, + Position, + Range, + TextDocument, + Uri +} from 'vscode'; +import { MAX_ATTEMPTS_BEFORE_IGNORING_RESOLVE_COMPLETION, resolveCompletionItem } from './resolveCompletionItem'; +import { IDisposable } from '../../platform/common/types'; +import { DisposableStore, dispose } from '../../platform/common/utils/lifecycle'; +import { createDeferred } from '../../platform/common/utils/async'; +import { IInspectReplyMsg } from '@jupyterlab/services/lib/kernel/messages'; +import { sleep } from '../../test/core'; + +suite('Jupyter Kernel Completion (requestInspect)', () => { + let kernel: IKernel; + let kernelId = ''; + let kernelConnection: Kernel.IKernelConnection; + let document: TextDocument; + let completionItem: CompletionItem; + let token: CancellationToken; + let tokenSource: CancellationTokenSource; + let disposables: IDisposable[] = []; + let toDispose: DisposableStore; + let clock: fakeTimers.InstalledClock; + setup(() => { + kernelConnection = mock(); + kernel = mock(); + kernelId = uuid(); + when(kernel.id).thenReturn(kernelId); + const kernelConnectionMetadata = mock(); + when(kernel.kernelConnectionMetadata).thenReturn(instance(kernelConnectionMetadata)); + when(kernelConnectionMetadata.id).thenReturn(kernelId); + const session = mock(); + when(kernel.session).thenReturn(instance(session)); + when(session.kernel).thenReturn(instance(kernelConnection)); + document = createMockedDocument('foo.', Uri.parse('a.ipynb'), 1, true); + + tokenSource = new CancellationTokenSource(); + token = tokenSource.token; + toDispose = new DisposableStore(); + + clock = fakeTimers.install(); + + disposables.push(new Disposable(() => clock.uninstall())); + disposables.push(tokenSource); + disposables.push(toDispose); + }); + + teardown(() => { + disposables = dispose(disposables); + }); + test('Return the same item if kernel is not idle', async () => { + completionItem = new CompletionItem('One'); + completionItem.range = new Range(0, 4, 0, 4); + + const statuses: Kernel.Status[] = [ + 'busy', + 'starting', + 'restarting', + 'dead', + 'autorestarting', + 'dead', + 'terminating', + 'unknown' + ]; + + for (const status of statuses) { + when(kernel.status).thenReturn(status); + const result = await resolveCompletionItem( + completionItem, + token, + instance(kernel), + kernelId, + 'python', + document, + new Position(0, 4), + toDispose + ); + + assert.strictEqual(result.documentation, completionItem.documentation); + } + }); + test('Return the same item if cancelled', async () => { + completionItem = new CompletionItem('One'); + completionItem.range = new Range(0, 4, 0, 4); + when(kernel.status).thenReturn('idle'); + const deferred = createDeferred(); + deferred.resolve({ + channel: 'shell', + content: { + status: 'ok', + data: { + 'text/plain': 'Some documentation' + }, + found: true, + metadata: {} + }, + header: {} as any, + metadata: {} as any, + parent_header: {} as any + }); + // Resolve the response 2s later + when(kernelConnection.requestInspect(anything())).thenReturn( + sleep(2000, disposables).then(() => deferred.promise) + ); + + const resultPromise = resolveCompletionItem( + completionItem, + token, + instance(kernel), + kernelId, + 'python', + document, + new Position(0, 4), + toDispose + ); + // Cancel the request 1s later + void sleep(1000, disposables).then(() => tokenSource.cancel()); + const [result] = await Promise.all([resultPromise, clock.tickAsync(5_000)]); + assert.isUndefined(result.documentation); + }); + test('Return the sam item if kernel does not reply in time', async () => { + completionItem = new CompletionItem('One'); + completionItem.range = new Range(0, 4, 0, 4); + when(kernel.status).thenReturn('idle'); + const deferred = createDeferred(); + when(kernelConnection.requestInspect(anything())).thenReturn(deferred.promise); + + const resultPromise = resolveCompletionItem( + completionItem, + token, + instance(kernel), + kernelId, + 'python', + document, + new Position(0, 4), + toDispose + ); + + const [result] = await Promise.all([resultPromise, clock.tickAsync(5_000)]); + + assert.strictEqual(result.documentation, completionItem.documentation); + verify(kernelConnection.requestInspect(anything())).once(); + }); + test('Resolve the documentation', async () => { + completionItem = new CompletionItem('One'); + completionItem.range = new Range(0, 4, 0, 4); + when(kernel.status).thenReturn('idle'); + const deferred = createDeferred(); + deferred.resolve({ + channel: 'shell', + content: { + status: 'ok', + data: { + 'text/plain': 'Some documentation' + }, + found: true, + metadata: {} + }, + header: {} as any, + metadata: {} as any, + parent_header: {} as any + }); + when(kernelConnection.requestInspect(anything())).thenReturn(deferred.promise); + + const resultPromise = resolveCompletionItem( + completionItem, + token, + instance(kernel), + kernelId, + 'python', + document, + new Position(0, 4), + toDispose + ); + const [result] = await Promise.all([resultPromise, clock.tickAsync(5_000)]); + assert.strictEqual(result.documentation, 'Some documentation'); + }); + test('Resolve the documentation, even if it takes a few ms (less than timeout)', async () => { + completionItem = new CompletionItem('One'); + completionItem.range = new Range(0, 4, 0, 4); + when(kernel.status).thenReturn('idle'); + const deferred = createDeferred(); + deferred.resolve({ + channel: 'shell', + content: { + status: 'ok', + data: { + 'text/plain': 'Some documentation' + }, + found: true, + metadata: {} + }, + header: {} as any, + metadata: {} as any, + parent_header: {} as any + }); + when(kernelConnection.requestInspect(anything())).thenReturn(sleep(1000).then(() => deferred.promise)); + + const resultPromise = resolveCompletionItem( + completionItem, + token, + instance(kernel), + kernelId, + 'python', + document, + new Position(0, 4), + toDispose + ); + const [result] = await Promise.all([resultPromise, clock.tickAsync(5_000)]); + assert.strictEqual(result.documentation, 'Some documentation'); + }); + test('Never make any requests if we fail to get a response n times', async () => { + completionItem = new CompletionItem('One'); + completionItem.range = new Range(0, 4, 0, 4); + when(kernel.status).thenReturn('idle'); + const deferred = createDeferred(); + when(kernelConnection.requestInspect(anything())).thenReturn(deferred.promise); + + for (let index = 0; index < MAX_ATTEMPTS_BEFORE_IGNORING_RESOLVE_COMPLETION; index++) { + const resultPromise = resolveCompletionItem( + completionItem, + token, + instance(kernel), + kernelId, + 'python', + document, + new Position(0, 4), + toDispose + ); + const [result] = await Promise.all([resultPromise, clock.tickAsync(5_000)]); + assert.strictEqual(result.documentation, completionItem.documentation); + verify(kernelConnection.requestInspect(anything())).atLeast(index + 1); + } + + reset(kernelConnection); + when(kernelConnection.requestInspect(anything())).thenReturn(deferred.promise); + const resultPromise = resolveCompletionItem( + completionItem, + token, + instance(kernel), + kernelId, + 'python', + document, + new Position(0, 4), + toDispose + ); + const [result] = await Promise.all([resultPromise, clock.tickAsync(5_000)]); + assert.strictEqual(result.documentation, completionItem.documentation); + verify(kernelConnection.requestInspect(anything())).never(); + }); +}); diff --git a/src/telemetry.ts b/src/telemetry.ts index a83b80231a1..15402f3b98c 100644 --- a/src/telemetry.ts +++ b/src/telemetry.ts @@ -47,7 +47,7 @@ type Feature = | 'KernelPicker' | 'Import-Export' | 'VariableViewer'; -type EventTag = 'Cell Execution' | 'Remote' | 'Widgets' | 'KernelStartup' | 'IntelliSense'; +type EventTag = 'Cell Execution' | 'Remote' | 'Widgets' | 'KernelStartup' | 'IntelliSense' | 'Code Execution'; type EventSource = 'User Action' | 'N/A'; type IGdprEventData = { owner: Owner; @@ -2580,17 +2580,45 @@ export class IEventNamePropertyMapping { /** * Sent when a user executes a cell. */ - [Telemetry.ExecuteCell]: TelemetryEventInfo = { + [Telemetry.ExecuteCell]: TelemetryEventInfo = { owner: 'donjayamanne', feature: ['Notebook', 'InteractiveWindow'], source: 'User Action', tags: ['Cell Execution'], + measures: commonClassificationForDurationProperties(), properties: { ...commonClassificationForResourceSpecificTelemetryProperties().properties, ...commonClassificationForErrorProperties() } }; + /** + * Sent when a some code is executed against the kernel + */ + [Telemetry.ExecuteCode]: TelemetryEventInfo< + DurationMeasurement & + ResourceSpecificTelemetryProperties & { + /** + * Extension Id that's attempting to use the API. + */ + extensionId: string; + } + > = { + owner: 'donjayamanne', + feature: ['Notebook', 'InteractiveWindow'], + source: 'User Action', + tags: ['Code Execution'], + measures: commonClassificationForDurationProperties(), + properties: { + ...commonClassificationForResourceSpecificTelemetryProperties().properties, + ...commonClassificationForErrorProperties(), + extensionId: { + classification: 'SystemMetaData', + purpose: 'FeatureInsight' + } + } + }; + /** * Sent when we resume execution of a cell (e.g. when reloading VS Code while a cell was executing). */ @@ -3273,13 +3301,135 @@ export class IEventNamePropertyMapping { */ cancelled: boolean; /** - * Time taken to resolve the documentation. + * Whether we send the request to resolve the completion item. + */ + requestSent: boolean; + /** + * Whether we completed the request. + */ + completed: boolean; + /** + * Number of items returned. + */ + completionItems: number; + /** + * Total time taken to complete the request. + */ + requestDuration: number; + /** + * Status of the kernel at the time we make a request for the resolve completion information + */ + kernelStatusBeforeRequest?: string; + /** + * Status of the kernel at the time we make a request for the resolve completion information + */ + kernelStatusAfterRequest?: string; + } + > = { + owner: 'donjayamanne', + feature: 'N/A', + source: 'N/A', + measures: { + ...commonClassificationForDurationProperties(), + requestDuration: { + classification: 'SystemMetaData', + purpose: 'PerformanceAndHealth', + isMeasurement: true + }, + completionItems: { + classification: 'SystemMetaData', + purpose: 'PerformanceAndHealth', + isMeasurement: true + } + }, + properties: { + kernelConnectionType: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + kernelLanguage: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + kernelId: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + cancelled: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + completed: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + kernelStatusAfterRequest: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + kernelStatusBeforeRequest: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + requestSent: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + } + } + }; + /** + * Telemetry sent with the total time taken to provide completions from a kernel. + */ + [Telemetry.KernelCodeCompletionResolve]: TelemetryEventInfo< + DurationMeasurement & { + /** + * Hash of the Kernel Connection id. */ - resolveDuration: number; + kernelId: string; + /** + * What kind of kernel spec did we fail to create. + */ + kernelConnectionType: + | 'startUsingPythonInterpreter' + | 'startUsingLocalKernelSpec' + | 'startUsingRemoteKernelSpec' + | 'connectToLiveRemoteKernel'; + /** + * Language of the kernel spec. + */ + kernelLanguage: string | undefined; + /** + * Whether we timedout waiting for the request to complete. + */ + requestTimedout?: boolean; + /** + * Whether the completion request was cancelled or not. + */ + cancelled?: boolean; + /** + * Whether we send the request to resolve the completion item. + */ + requestSent: boolean; /** * Whether we resolved the documentation or not. */ - resolved?: boolean; + completed: boolean; + /** + * Total time taken to resolve the documentation. + */ + requestDuration: number; + /** + * Whether the kernel completion resolve request returned any data. + */ + completedWithData?: boolean; + /** + * Status of the kernel at the time we make a request for the resolve completion information + */ + kernelStatusBeforeRequest?: string; + /** + * Status of the kernel at the time we make a request for the resolve completion information + */ + kernelStatusAfterRequest?: string; } > = { owner: 'donjayamanne', @@ -3287,7 +3437,7 @@ export class IEventNamePropertyMapping { source: 'N/A', measures: { ...commonClassificationForDurationProperties(), - resolveDuration: { + requestDuration: { classification: 'SystemMetaData', purpose: 'PerformanceAndHealth', isMeasurement: true @@ -3310,7 +3460,21 @@ export class IEventNamePropertyMapping { classification: 'PublicNonPersonalData', purpose: 'FeatureInsight' }, - resolved: { + kernelStatusBeforeRequest: { classification: 'PublicNonPersonalData', purpose: 'FeatureInsight' }, + kernelStatusAfterRequest: { classification: 'PublicNonPersonalData', purpose: 'FeatureInsight' }, + requestTimedout: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + completedWithData: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + requestSent: { + classification: 'PublicNonPersonalData', + purpose: 'FeatureInsight' + }, + completed: { classification: 'PublicNonPersonalData', purpose: 'FeatureInsight' } diff --git a/src/test/core.ts b/src/test/core.ts index 502c5cf6c48..be153fbb185 100644 --- a/src/test/core.ts +++ b/src/test/core.ts @@ -1,10 +1,17 @@ // Copyright (c) Microsoft Corporation. // Licensed under the MIT License. +import { IDisposable } from '../platform/common/types'; + // File without any dependencies on VS Code. -export async function sleep(milliseconds: number) { - return new Promise((resolve) => setTimeout(resolve, milliseconds)); +export async function sleep(milliseconds: number, disposables?: IDisposable[]) { + return new Promise((resolve) => { + const timeout = setTimeout(resolve, milliseconds); + if (disposables) { + disposables.push({ dispose: () => clearTimeout(timeout) }); + } + }); } // eslint-disable-next-line no-empty,@typescript-eslint/no-empty-function