@@ -13,7 +13,6 @@ import { CopilotCompletionContextResult } from './client';
1313import { CopilotCompletionContextTelemetry } from './copilotCompletionContextTelemetry' ;
1414import { getCopilotApi } from './copilotProviders' ;
1515import { clients } from './extension' ;
16- import { ProjectContext } from './lmTool' ;
1716import { CppSettings } from './settings' ;
1817
1918class DefaultValueFallback extends Error {
@@ -82,6 +81,9 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
8281 private completionContextCancellation = new vscode . CancellationTokenSource ( ) ;
8382 private contextProviderDisposable : vscode . Disposable | undefined ;
8483
84+ constructor ( private readonly logger : Logger ) {
85+ }
86+
8587 private async waitForCompletionWithTimeoutAndCancellation < T > ( promise : Promise < T > , defaultValue : T | undefined ,
8688 timeout : number , copilotToken : vscode . CancellationToken ) : Promise < [ T | undefined , CopilotCompletionKind ] > {
8789 const defaultValuePromise = new Promise < T > ( ( _resolve , reject ) => setTimeout ( ( ) => {
@@ -123,7 +125,7 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
123125 // Get the completion context with a timeout and a cancellation token.
124126 // The cancellationToken indicates that the value should not be returned nor cached.
125127 private async getCompletionContextWithCancellation ( context : ResolveRequest , featureFlag : CopilotCompletionContextFeatures ,
126- startTime : number , out : Logger , telemetry : CopilotCompletionContextTelemetry , internalToken : vscode . CancellationToken ) :
128+ startTime : number , telemetry : CopilotCompletionContextTelemetry , internalToken : vscode . CancellationToken ) :
127129 Promise < CopilotCompletionContextResult | undefined > {
128130 const documentUri = context . documentContext . uri ;
129131 const caretOffset = context . documentContext . offset ;
@@ -133,55 +135,42 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
133135 telemetry . addRequestMetadata ( documentUri , caretOffset , context . completionId ,
134136 context . documentContext . languageId , { featureFlag : snippetsFeatureFlag } ) ;
135137 const docUri = vscode . Uri . parse ( documentUri ) ;
138+ const getClientForTime = performance . now ( ) ;
136139 const client = clients . getClientFor ( docUri ) ;
140+ const getClientForDuration = CopilotCompletionContextProvider . getRoundedDuration ( getClientForTime ) ;
141+ telemetry . addGetClientForElapsed ( getClientForDuration ) ;
137142 if ( ! client ) { throw WellKnownErrors . clientNotFound ( ) ; }
138143 const getCompletionContextStartTime = performance . now ( ) ;
139144
140- // Start collection of project traits concurrently with the completion context computation.
141- const projectContextPromise = ( async ( ) : Promise < ProjectContext | undefined > => {
142- const elapsedTimeMs = performance . now ( ) ;
143- const projectContext = await client . getChatContext ( docUri , internalToken ) ;
144- telemetry . addCppStandardVersionMetadata ( projectContext . standardVersion ,
145- CopilotCompletionContextProvider . getRoundedDuration ( elapsedTimeMs ) ) ;
146- return projectContext ;
147- } ) ( ) ;
148-
149145 const copilotCompletionContext : CopilotCompletionContextResult =
150146 await client . getCompletionContext ( docUri , caretOffset , snippetsFeatureFlag , internalToken ) ;
151- copilotCompletionContext . codeSnippetsCount = copilotCompletionContext . snippets . length ;
152147 telemetry . addRequestId ( copilotCompletionContext . requestId ) ;
153- logMessage += ` (id:${ copilotCompletionContext . requestId } )` ;
154- // Collect project traits and if any add them to the completion context.
155- const projectContext = await projectContextPromise ;
156- if ( projectContext ?. standardVersion ) {
157- copilotCompletionContext . snippets . push ( { name : "C++ language standard version" , value : `This project uses the ${ projectContext . standardVersion } language standard version.` } ) ;
158- copilotCompletionContext . traitsCount = 1 ;
148+ logMessage += `(id:${ copilotCompletionContext . requestId } ) (getClientFor elapsed:${ getClientForDuration } ms)` ;
149+ if ( ! copilotCompletionContext . areSnippetsMissing ) {
150+ const resultMismatch = copilotCompletionContext . sourceFileUri !== docUri . toString ( ) ;
151+ if ( resultMismatch ) { logMessage += ` (mismatch TU vs result)` ; }
159152 }
160-
161- let resultMismatch = false ;
162- if ( ! copilotCompletionContext . areCodeSnippetsMissing ) {
163- resultMismatch = copilotCompletionContext . translationUnitUri !== docUri . toString ( ) ;
164- const cacheEntryId = randomUUID ( ) . toString ( ) ;
165- this . completionContextCache . set ( copilotCompletionContext . translationUnitUri , [ cacheEntryId , copilotCompletionContext ] ) ;
166- const duration = CopilotCompletionContextProvider . getRoundedDuration ( startTime ) ;
167- telemetry . addCacheComputedData ( duration , cacheEntryId ) ;
168- if ( resultMismatch ) { logMessage += `, mismatch TU vs result` ; }
169- logMessage += `, cached ${ copilotCompletionContext . snippets . length } snippets in ${ duration } ms` ;
170- logMessage += `, response.featureFlag:${ copilotCompletionContext . featureFlag } ,\
171- ${ copilotCompletionContext . translationUnitUri } :${ copilotCompletionContext . caretOffset } ,\
172- snippetsCount:${ copilotCompletionContext . codeSnippetsCount } , traitsCount:${ copilotCompletionContext . traitsCount } ` ;
173- } else {
174- logMessage += ` (snippets are missing) ` ;
153+ const cacheEntryId = randomUUID ( ) . toString ( ) ;
154+ this . completionContextCache . set ( copilotCompletionContext . sourceFileUri , [ cacheEntryId , copilotCompletionContext ] ) ;
155+ const duration = CopilotCompletionContextProvider . getRoundedDuration ( startTime ) ;
156+ telemetry . addCacheComputedData ( duration , cacheEntryId ) ;
157+ logMessage += ` cached in ${ duration } ms ${ copilotCompletionContext . traits . length } trait(s)` ;
158+ if ( copilotCompletionContext . areSnippetsMissing ) { logMessage += ` (missing code-snippets) ` ; }
159+ else {
160+ logMessage += ` and ${ copilotCompletionContext . snippets . length } snippet(s)` ;
161+ logMessage += `, response.featureFlag:${ copilotCompletionContext . featureFlag } , \
162+ response.uri:${ copilotCompletionContext . sourceFileUri || "<not-set>" } :${ copilotCompletionContext . caretOffset } ` ;
175163 }
176- telemetry . addResponseMetadata ( copilotCompletionContext . areCodeSnippetsMissing , copilotCompletionContext . snippets . length , copilotCompletionContext . codeSnippetsCount ,
177- copilotCompletionContext . traitsCount , copilotCompletionContext . caretOffset , copilotCompletionContext . featureFlag ) ;
164+
165+ telemetry . addResponseMetadata ( copilotCompletionContext . areSnippetsMissing , copilotCompletionContext . snippets . length ,
166+ copilotCompletionContext . traits . length , copilotCompletionContext . caretOffset , copilotCompletionContext . featureFlag ) ;
178167 telemetry . addComputeContextElapsed ( CopilotCompletionContextProvider . getRoundedDuration ( getCompletionContextStartTime ) ) ;
179168
180- return resultMismatch ? undefined : copilotCompletionContext ;
169+ return copilotCompletionContext ;
181170 } catch ( e : any ) {
182171 if ( e instanceof vscode . CancellationError || e . message === CancellationError . Canceled ) {
183172 telemetry . addInternalCanceled ( CopilotCompletionContextProvider . getRoundedDuration ( startTime ) ) ;
184- logMessage += `, (internal cancellation)` ;
173+ logMessage += ` (internal cancellation) ` ;
185174 throw InternalCancellationError ;
186175 }
187176
@@ -190,14 +179,11 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
190179 }
191180
192181 telemetry . addError ( ) ;
193- if ( e . message && e . stack ) {
194- out . appendLine ( `Copilot: getCompletionContextWithCancellation(${ documentUri } : ${ caretOffset } ): Error: '${ e . message } ', stack '${ e . stack } ` ) ;
195- } else {
196- out . appendLine ( `Copilot: getCompletionContextWithCancellation(${ documentUri } : ${ caretOffset } ): Error: '${ e } '` ) ;
197- }
182+ this . logger . appendLineAtLevel ( 7 , `Copilot: getCompletionContextWithCancellation(${ documentUri } : ${ caretOffset } ): Error: '${ e } '` ) ;
198183 return undefined ;
199184 } finally {
200- out . appendLineAtLevel ( 6 , logMessage ) ;
185+ this . logger .
186+ appendLineAtLevel ( 7 , logMessage ) ;
201187 telemetry . send ( "cache" ) ;
202188 }
203189 }
@@ -251,7 +237,7 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
251237 }
252238
253239 public static async Create ( ) {
254- const copilotCompletionProvider = new CopilotCompletionContextProvider ( ) ;
240+ const copilotCompletionProvider = new CopilotCompletionContextProvider ( getOutputChannelLogger ( ) ) ;
255241 await copilotCompletionProvider . registerCopilotContextProvider ( ) ;
256242 return copilotCompletionProvider ;
257243 }
@@ -267,26 +253,26 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
267253
268254 public async resolve ( context : ResolveRequest , copilotCancel : vscode . CancellationToken ) : Promise < SupportedContextItem [ ] > {
269255 const resolveStartTime = performance . now ( ) ;
270- const out : Logger = getOutputChannelLogger ( ) ;
271- let logMessage = `Copilot: resolve(${ context . documentContext . uri } :${ context . documentContext . offset } ): ` ;
256+ let logMessage = `Copilot: resolve(${ context . documentContext . uri } :${ context . documentContext . offset } ):` ;
272257 const timeBudgetFactor = await this . fetchTimeBudgetFactor ( context ) ;
273258 const maxCaretDistance = await this . fetchMaxDistanceToCaret ( context ) ;
274259 const telemetry = new CopilotCompletionContextTelemetry ( ) ;
275260 let copilotCompletionContext : CopilotCompletionContextResult | undefined ;
276261 let copilotCompletionContextKind : CopilotCompletionKind = CopilotCompletionKind . Unknown ;
277262 let featureFlag : CopilotCompletionContextFeatures | undefined ;
263+ const docUri = context . documentContext . uri ;
264+ const docOffset = context . documentContext . offset ;
278265 try {
279266 featureFlag = await this . getEnabledFeatureFlag ( context ) ;
280267 telemetry . addRequestMetadata ( context . documentContext . uri , context . documentContext . offset ,
281268 context . completionId , context . documentContext . languageId , { featureFlag, timeBudgetFactor, maxCaretDistance } ) ;
282269 if ( featureFlag === undefined ) { return [ ] ; }
283270 this . completionContextCancellation . cancel ( ) ;
284271 this . completionContextCancellation = new vscode . CancellationTokenSource ( ) ;
285- const docUri = context . documentContext . uri ;
286272 const cacheEntry : CacheEntry | undefined = this . completionContextCache . get ( docUri . toString ( ) ) ;
287273 const defaultValue = cacheEntry ?. [ 1 ] ;
288274 const computeSnippetsPromise = this . getCompletionContextWithCancellation ( context , featureFlag ,
289- resolveStartTime , out , telemetry . fork ( ) , this . completionContextCancellation . token ) ;
275+ resolveStartTime , telemetry . fork ( ) , this . completionContextCancellation . token ) ;
290276 [ copilotCompletionContext , copilotCompletionContextKind ] = await this . waitForCompletionWithTimeoutAndCancellation (
291277 computeSnippetsPromise , defaultValue , context . timeBudget * timeBudgetFactor , copilotCancel ) ;
292278 // Fix up copilotCompletionContextKind accounting for stale-cache-hits.
@@ -307,7 +293,7 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
307293 throw new CopilotCancellationError ( ) ;
308294 }
309295 logMessage += ` (id:${ copilotCompletionContext ?. requestId } ) ` ;
310- return copilotCompletionContext ?. snippets ?? [ ] ;
296+ return [ ... copilotCompletionContext ?. snippets ?? [ ] , ... copilotCompletionContext ?. traits ?? [ ] ] as SupportedContextItem [ ] ;
311297 } catch ( e : any ) {
312298 if ( e instanceof CopilotCancellationError ) {
313299 telemetry . addCopilotCanceled ( CopilotCompletionContextProvider . getRoundedDuration ( resolveStartTime ) ) ;
@@ -326,22 +312,20 @@ export class CopilotCompletionContextProvider implements ContextResolver<Support
326312 throw e ;
327313 } finally {
328314 const duration : number = CopilotCompletionContextProvider . getRoundedDuration ( resolveStartTime ) ;
329- logMessage += ` featureFlag:${ featureFlag ?. toString ( ) } ,` ;
315+ logMessage += `featureFlag:${ featureFlag ?. toString ( ) } ,` ;
330316 if ( copilotCompletionContext === undefined ) {
331317 logMessage += ` result is undefined and no snippets provided (${ copilotCompletionContextKind . toString ( ) } ), elapsed time:${ duration } ms` ;
332318 } else {
333- const uri = copilotCompletionContext . translationUnitUri ? copilotCompletionContext . translationUnitUri : "<undefined-uri>" ;
334- logMessage += ` for ${ uri } provided ${ copilotCompletionContext . codeSnippetsCount } code-snippets (${ copilotCompletionContextKind . toString ( ) } ,\
335- ${ copilotCompletionContext ?. areCodeSnippetsMissing ? " missing code-snippets" : "" } ) and ${ copilotCompletionContext . traitsCount } traits, elapsed time:${ duration } ms`;
319+ logMessage += ` for ${ docUri } :${ docOffset } provided ${ copilotCompletionContext . snippets . length } code-snippet(s) (${ copilotCompletionContextKind . toString ( ) } \
320+ ${ copilotCompletionContext ?. areSnippetsMissing ? ", missing code-snippets" : "" } ) and ${ copilotCompletionContext . traits . length } trait(s), elapsed time:${ duration } ms`;
336321 }
337- telemetry . addResponseMetadata ( copilotCompletionContext ?. areCodeSnippetsMissing ?? true ,
338- copilotCompletionContext ?. snippets ?. length ,
339- copilotCompletionContext ?. codeSnippetsCount , copilotCompletionContext ?. traitsCount ,
322+ telemetry . addResponseMetadata ( copilotCompletionContext ?. areSnippetsMissing ?? true ,
323+ copilotCompletionContext ?. snippets . length , copilotCompletionContext ?. traits . length ,
340324 copilotCompletionContext ?. caretOffset , copilotCompletionContext ?. featureFlag ) ;
341325 telemetry . addResolvedElapsed ( duration ) ;
342326 telemetry . addCacheSize ( this . completionContextCache . size ) ;
343327 telemetry . send ( ) ;
344- out . appendLineAtLevel ( 6 , logMessage ) ;
328+ this . logger . appendLineAtLevel ( 7 , logMessage ) ;
345329 }
346330 }
347331
0 commit comments