22 * Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
33 * SPDX-License-Identifier: Apache-2.0
44 */
5-
5+ import * as vscode from 'vscode'
66import {
77 CancellationToken ,
88 InlineCompletionContext ,
@@ -32,7 +32,6 @@ import {
3232 ImportAdderProvider ,
3333 CodeSuggestionsState ,
3434 vsCodeState ,
35- inlineCompletionsDebounceDelay ,
3635 noInlineSuggestionsMsg ,
3736 getDiagnosticsDifferences ,
3837 getDiagnosticsOfCurrentFile ,
@@ -42,7 +41,7 @@ import { LineTracker } from './stateTracker/lineTracker'
4241import { InlineTutorialAnnotation } from './tutorials/inlineTutorialAnnotation'
4342import { TelemetryHelper } from './telemetryHelper'
4443import { Experiments , getLogger , sleep } from 'aws-core-vscode/shared'
45- import { debounce , messageUtils } from 'aws-core-vscode/utils'
44+ import { messageUtils } from 'aws-core-vscode/utils'
4645import { showEdits } from './EditRendering/imageRenderer'
4746import { ICursorUpdateRecorder } from './cursorUpdateManager'
4847import { DocumentEventListener } from './documentEventListener'
@@ -164,6 +163,11 @@ export class InlineCompletionManager implements Disposable {
164163 const onInlineRejection = async ( ) => {
165164 try {
166165 vsCodeState . isCodeWhispererEditing = true
166+ if ( this . sessionManager . getActiveSession ( ) === undefined ) {
167+ return
168+ }
169+ const requestStartTime = this . sessionManager . getActiveSession ( ) ! . requestStartTime
170+ const totalSessionDisplayTime = performance . now ( ) - requestStartTime
167171 await commands . executeCommand ( 'editor.action.inlineSuggest.hide' )
168172 // TODO: also log the seen state for other suggestions in session
169173 this . disposable . dispose ( )
@@ -185,6 +189,7 @@ export class InlineCompletionManager implements Disposable {
185189 discarded : false ,
186190 } ,
187191 } ,
192+ totalSessionDisplayTime : totalSessionDisplayTime ,
188193 }
189194 this . languageClient . sendNotification ( this . logSessionResultMessageName , params )
190195 // clear session manager states once rejected
@@ -198,7 +203,7 @@ export class InlineCompletionManager implements Disposable {
198203}
199204
200205export class AmazonQInlineCompletionItemProvider implements InlineCompletionItemProvider {
201- private logger = getLogger ( 'nextEditPrediction' )
206+ private logger = getLogger ( )
202207 constructor (
203208 private readonly languageClient : LanguageClient ,
204209 private readonly recommendationService : RecommendationService ,
@@ -208,13 +213,23 @@ export class AmazonQInlineCompletionItemProvider implements InlineCompletionItem
208213 ) { }
209214
210215 private readonly logSessionResultMessageName = 'aws/logInlineCompletionSessionResults'
211- provideInlineCompletionItems = debounce (
212- this . _provideInlineCompletionItems . bind ( this ) ,
213- inlineCompletionsDebounceDelay ,
214- true
215- )
216216
217- private async _provideInlineCompletionItems (
217+ // Ideally use this API handleDidShowCompletionItem
218+ // https://github.com/microsoft/vscode/blob/main/src/vscode-dts/vscode.proposed.inlineCompletionsAdditions.d.ts#L83
219+ // we need this because the returned items of provideInlineCompletionItems may not be actually rendered on screen
220+ // if VS Code believes the user is actively typing then it will not show such item
221+ async checkWhetherInlineCompletionWasShown ( ) {
222+ // this line is to force VS Code to re-render the inline completion
223+ // if it decides the inline completion can be shown
224+ await vscode . commands . executeCommand ( 'editor.action.inlineSuggest.trigger' )
225+ // yield event loop to let backend state transition finish plus wait for vsc to render
226+ await sleep ( 10 )
227+ // run the command to detect if inline suggestion is really shown or not
228+ await vscode . commands . executeCommand ( `aws.amazonq.checkInlineSuggestionVisibility` )
229+ }
230+
231+ // this method is automatically invoked by VS Code as user types
232+ async provideInlineCompletionItems (
218233 document : TextDocument ,
219234 position : Position ,
220235 context : InlineCompletionContext ,
@@ -299,26 +314,28 @@ export class AmazonQInlineCompletionItemProvider implements InlineCompletionItem
299314 }
300315 // re-use previous suggestions as long as new typed prefix matches
301316 if ( prevItemMatchingPrefix . length > 0 ) {
302- getLogger ( ) . debug ( `Re-using suggestions that match user typed characters` )
317+ logstr += `- not call LSP and reuse previous suggestions that match user typed characters
318+ - duration between trigger to completion suggestion is displayed ${ performance . now ( ) - t0 } `
319+ void this . checkWhetherInlineCompletionWasShown ( )
303320 return prevItemMatchingPrefix
304321 }
305- getLogger ( ) . debug ( `Auto rejecting suggestions from previous session` )
306- // if no such suggestions, report the previous suggestion as Reject
322+
323+ // if no such suggestions, report the previous suggestion as Reject or Discarded
307324 const params : LogInlineCompletionSessionResultsParams = {
308325 sessionId : prevSessionId ,
309326 completionSessionResult : {
310327 [ prevItemId ] : {
311- seen : true ,
328+ seen : prevSession . displayed ,
312329 accepted : false ,
313- discarded : false ,
330+ discarded : ! prevSession . displayed ,
314331 } ,
315332 } ,
333+ totalSessionDisplayTime : performance . now ( ) - prevSession . requestStartTime ,
316334 }
317335 this . languageClient . sendNotification ( this . logSessionResultMessageName , params )
318336 this . sessionManager . clear ( )
319337 }
320338
321- // TODO: this line will take ~200ms each trigger, need to root cause and maybe better to disable it for now
322339 // tell the tutorial that completions has been triggered
323340 await this . inlineTutorialAnnotation . triggered ( context . triggerKind )
324341
@@ -346,12 +363,13 @@ export class AmazonQInlineCompletionItemProvider implements InlineCompletionItem
346363
347364 const t2 = performance . now ( )
348365
349- logstr = logstr += `- number of suggestions: ${ items . length }
366+ logstr += `- number of suggestions: ${ items . length }
350367- sessionId: ${ this . sessionManager . getActiveSession ( ) ?. sessionId }
351368- first suggestion content (next line):
352369${ itemLog }
353- - duration since trigger to before sending Flare call: ${ t1 - t0 } ms
354- - duration since trigger to receiving responses from Flare: ${ t2 - t0 } ms
370+ - duration between trigger to before sending LSP call: ${ t1 - t0 } ms
371+ - duration between trigger to after receiving LSP response: ${ t2 - t0 } ms
372+ - duration between before sending LSP call to after receving LSP response: ${ t2 - t1 } ms
355373`
356374 const session = this . sessionManager . getActiveSession ( )
357375
@@ -361,16 +379,13 @@ ${itemLog}
361379 }
362380
363381 if ( ! session || ! items . length || ! editor ) {
364- getLogger ( ) . debug (
365- `Failed to produce inline suggestion results. Received ${ items . length } items from service`
366- )
382+ logstr += `Failed to produce inline suggestion results. Received ${ items . length } items from service`
367383 return [ ]
368384 }
369385
370386 const cursorPosition = document . validatePosition ( position )
371387
372388 if ( position . isAfter ( editor . selection . active ) ) {
373- getLogger ( ) . debug ( `Cursor moved behind trigger position. Discarding suggestion...` )
374389 const params : LogInlineCompletionSessionResultsParams = {
375390 sessionId : session . sessionId ,
376391 completionSessionResult : {
@@ -383,6 +398,7 @@ ${itemLog}
383398 }
384399 this . languageClient . sendNotification ( this . logSessionResultMessageName , params )
385400 this . sessionManager . clear ( )
401+ logstr += `- cursor moved behind trigger position. Discarding suggestion...`
386402 return [ ]
387403 }
388404
@@ -410,9 +426,7 @@ ${itemLog}
410426 // Check if Next Edit Prediction feature flag is enabled
411427 if ( Experiments . instance . get ( 'amazonqLSPNEP' , true ) ) {
412428 await showEdits ( item , editor , session , this . languageClient , this )
413- const t3 = performance . now ( )
414- logstr = logstr + `- duration since trigger to NEP suggestion is displayed: ${ t3 - t0 } ms`
415- this . logger . info ( logstr )
429+ logstr += `- duration between trigger to edits suggestion is displayed: ${ performance . now ( ) - t0 } ms`
416430 }
417431 return [ ]
418432 }
@@ -438,9 +452,6 @@ ${itemLog}
438452
439453 // report discard if none of suggestions match typeahead
440454 if ( itemsMatchingTypeahead . length === 0 ) {
441- getLogger ( ) . debug (
442- `Suggestion does not match user typeahead from insertion position. Discarding suggestion...`
443- )
444455 const params : LogInlineCompletionSessionResultsParams = {
445456 sessionId : session . sessionId ,
446457 completionSessionResult : {
@@ -453,17 +464,22 @@ ${itemLog}
453464 }
454465 this . languageClient . sendNotification ( this . logSessionResultMessageName , params )
455466 this . sessionManager . clear ( )
467+ logstr += `- suggestion does not match user typeahead from insertion position. Discarding suggestion...`
456468 return [ ]
457469 }
458470
459471 this . sessionManager . updateCodeReferenceAndImports ( )
460472 // suggestions returned here will be displayed on screen
473+ logstr += `- duration between trigger to completion suggestion is displayed: ${ performance . now ( ) - t0 } ms`
474+ void this . checkWhetherInlineCompletionWasShown ( )
461475 return itemsMatchingTypeahead as InlineCompletionItem [ ]
462476 } catch ( e ) {
463477 getLogger ( 'amazonqLsp' ) . error ( 'Failed to provide completion items: %O' , e )
478+ logstr += `- failed to provide completion items ${ ( e as Error ) . message } `
464479 return [ ]
465480 } finally {
466481 vsCodeState . isRecommendationsActive = false
482+ this . logger . info ( logstr )
467483 }
468484 }
469485}
0 commit comments