Autocomplete: Log the number of lines of an accepted completion and f…

…ix a bug (#53878)

This PR does two things:

- First we add the number of lines of an accepted completion. Cool
- But then I noticed an oversight on my side. When you hover over the
autocomplete preview, the VS Code backends sends a new completion
request concurrently which our previous logic was using the _clear the
number of open completion requests_. That means that whenever we
accepted a solution _after that_, we would not log it because we've
already GCed it.
- To fix this, I’m now using the LRU cache to keep more completions
around (which will also help later as we need to do more shenanigans
with the logger)


## Test plan

- Trigger a multi-line completion
- Hover over the suggested completion
- Select a different one with a lower number of lines
- Accept the completion
- Observe that the right number for `lines` is logged



https://github.com/sourcegraph/sourcegraph/assets/458591/4618d890-2491-4ac8-880d-8eba5c3622ba


<!-- All pull requests REQUIRE a test plan:
https://docs.sourcegraph.com/dev/background-information/testing_principles
-->

client/cody/CHANGELOG.md

@@ -12,6 +12,7 @@ Starting from `0.2.0`, Cody is using `major.EVEN_NUMBER.patch` for release versi
 
 ### Fixed
 
+- Autocomplete: Include the number of lines of an accepted autocomplete recommendation and fix an issue where sometimes accepted completions would not be logged correctly. [pull/53878](https://github.com/sourcegraph/sourcegraph/pull/53878)
 - Stop-Generating button does not stop Cody from responding if pressed before answer is generating. [pull/53827](https://github.com/sourcegraph/sourcegraph/pull/53827)
 - Endpoint setting out of sync issue. [pull/53434](https://github.com/sourcegraph/sourcegraph/pull/53434)
 

client/cody/src/completions/index.ts

@@ -320,7 +320,7 @@ function toInlineCompletionItems(logId: string, completions: Completion[]): vsco
             new vscode.InlineCompletionItem(completion.content, undefined, {
                 title: 'Completion accepted',
                 command: 'cody.completions.inline.accepted',
-                arguments: [{ codyLogId: logId }],
+                arguments: [{ codyLogId: logId, codyLines: completion.content.split('\n').length }],
             })
     )
 }

client/cody/src/completions/logger.ts

@@ -1,3 +1,5 @@
+import { LRUCache } from 'lru-cache'
+
 import { logEvent } from '../event-logger'
 
 interface CompletionEvent {
@@ -11,8 +13,16 @@ interface CompletionEvent {
         }
         languageId: string
     }
+    // The timestamp when the request started
     startedAt: number
+    // The timestamp of when the suggestion was first displayed to a users
+    // screen
     suggestedAt: number | null
+    // The timestamp of when the suggestion was logged to our analytics backend
+    // This is to avoid double-logging
+    suggestionLoggedAt: number | null
+    // The timestamp of when a completion was accepted and logged to our backend
+    acceptedAt: number | null
     // When set, the completion will always be marked as `read`. This helps us
     // to avoid not counting a suggested event in case where the user accepts
     // the completion below the default timeout
@@ -21,7 +31,9 @@ interface CompletionEvent {
 
 const READ_TIMEOUT = 750
 
-const displayedCompletions: Map<string, CompletionEvent> = new Map()
+const displayedCompletions = new LRUCache<string, CompletionEvent>({
+    max: 100, // Maximum number of completions that we are keeping track of
+})
 
 export function logCompletionEvent(name: string, params?: unknown): void {
     logEvent(`CodyVSCodeExtension:completion:${name}`, params, params)
@@ -33,6 +45,8 @@ export function start(params: CompletionEvent['params']): string {
         params,
         startedAt: Date.now(),
         suggestedAt: null,
+        suggestionLoggedAt: null,
+        acceptedAt: null,
         forceRead: false,
     })
 
@@ -41,25 +55,26 @@ export function start(params: CompletionEvent['params']): string {
     return id
 }
 
-// Suggested completions will not logged individually. Instead, we log them when we either hide them
-// again (they are NOT accepted) or when they ARE accepted. This way, we can calculate the duration
-// they were actually visible.
+// Suggested completions will not logged individually. Instead, we log them when
+// we either hide them again (they are NOT accepted) or when they ARE accepted.
+// This way, we can calculate the duration they were actually visible.
 export function suggest(id: string): void {
     const event = displayedCompletions.get(id)
     if (event) {
         event.suggestedAt = Date.now()
     }
 }
 
-export function accept(id: string): void {
+export function accept(id: string, lines: number): void {
     const completionEvent = displayedCompletions.get(id)
-    if (!completionEvent) {
+    if (!completionEvent || completionEvent.acceptedAt) {
         return
     }
     completionEvent.forceRead = true
+    completionEvent.acceptedAt = Date.now()
 
     logSuggestionEvent()
-    logCompletionEvent('accepted', completionEvent.params)
+    logCompletionEvent('accepted', { ...completionEvent.params, lines })
 }
 
 export function noResponse(id: string): void {
@@ -68,7 +83,8 @@ export function noResponse(id: string): void {
 }
 
 /**
- * This callback should be triggered whenever VS Code tries to highlight a new completion and it's
+ * This callback should be triggered whenever VS Code tries to highlight a new
+ * completion and it's
  * used to measure how long previous completions were visible.
  */
 export function clear(): void {
@@ -81,12 +97,16 @@ function createId(): string {
 
 function logSuggestionEvent(): void {
     const now = Date.now()
-    for (const completionEvent of displayedCompletions.values()) {
-        const { suggestedAt, startedAt, params, forceRead } = completionEvent
-
-        if (!suggestedAt) {
-            continue
+    // eslint-disable-next-line ban/ban
+    displayedCompletions.forEach(completionEvent => {
+        const { suggestedAt, suggestionLoggedAt, startedAt, params, forceRead } = completionEvent
+
+        // Only log events that were already suggested to the user and have not
+        // been logged yet.
+        if (!suggestedAt || suggestionLoggedAt) {
+            return
         }
+        completionEvent.suggestionLoggedAt = now
 
         const latency = suggestedAt - startedAt
         const displayDuration = now - suggestedAt
@@ -98,6 +118,9 @@ function logSuggestionEvent(): void {
             displayDuration,
             read: forceRead || read,
         })
-    }
-    displayedCompletions.clear()
+    })
+
+    // Completions are kept in the LRU cache for longer. This is because they
+    // can still become visible if e.g. they are served from the cache and we
+    // need to retain the ability to mark them as seen
 }

client/cody/src/main.ts

@@ -383,8 +383,8 @@ function createCompletionsProvider(
         vscode.commands.registerCommand('cody.manual-completions', async () => {
             await manualCompletionService.fetchAndShowManualCompletions()
         }),
-        vscode.commands.registerCommand('cody.completions.inline.accepted', ({ codyLogId }) => {
-            CompletionsLogger.accept(codyLogId)
+        vscode.commands.registerCommand('cody.completions.inline.accepted', ({ codyLogId, codyLines }) => {
+            CompletionsLogger.accept(codyLogId, codyLines)
         }),
         vscode.languages.registerInlineCompletionItemProvider('*', completionsProvider)
     )