Add runner completion analytics events (#788)

* use exit code along with stderr for runner

* add integration test for sending error event

* add property detailing if the command was stoppped

* pull out notify of completion function

* pull out notify of output function

* rename new function

* account for error message being different across platforms

* add exit code into runner non error telemetry properties

extension/src/cli/runner.ts

@@ -8,6 +8,8 @@ import { PseudoTerminal } from '../vscode/pseudoTerminal'
 import { createProcess, Process } from '../processExecution'
 import { setContextValue } from '../vscode/context'
 import { StopWatch } from '../util/time'
+import { sendErrorTelemetryEvent, sendTelemetryEvent } from '../telemetry'
+import { EventName } from '../telemetry/constants'
 
 export const autoRegisteredCommands = {
   EXPERIMENT_RUN: 'runExperiment',
@@ -161,21 +163,19 @@ export class CliRunner implements ICli {
 
     this.processStarted.fire(baseEvent)
 
-    process.all?.on('data', chunk =>
-      this.processOutput.fire(
-        chunk
-          .toString()
-          .split(/(\r?\n)/g)
-          .join('\r')
-      )
-    )
+    this.notifyOutput(process)
+
+    let stderr = ''
+    process.stderr?.on('data', chunk => (stderr += chunk.toString()))
 
     process.on('close', exitCode => {
       this.dispose.untrack(process)
-      this.processCompleted.fire({
+      this.notifyCompleted({
         ...baseEvent,
         duration: stopWatch.getElapsedTime(),
-        exitCode
+        exitCode,
+        killed: process.killed,
+        stderr
       })
     })
 
@@ -200,4 +200,69 @@ export class CliRunner implements ICli {
       cwd
     })
   }
+
+  private notifyOutput(process: Process) {
+    process.all?.on('data', chunk =>
+      this.processOutput.fire(
+        chunk
+          .toString()
+          .split(/(\r?\n)/g)
+          .join('\r')
+      )
+    )
+  }
+
+  private notifyCompleted({
+    command,
+    pid,
+    cwd,
+    duration,
+    exitCode,
+    killed,
+    stderr
+  }: CliResult & {
+    killed: boolean
+  }) {
+    this.processCompleted.fire({
+      command,
+      cwd,
+      duration,
+      exitCode,
+      pid,
+      stderr: stderr?.replace(/\n+/g, '\n')
+    })
+
+    this.sendTelemetryEvent({ command, duration, exitCode, killed, stderr })
+  }
+
+  private sendTelemetryEvent({
+    command,
+    exitCode,
+    stderr,
+    duration,
+    killed
+  }: {
+    command: string
+    exitCode: number | null
+    stderr?: string
+    duration: number
+    killed: boolean
+  }) {
+    const properties = { command, exitCode }
+
+    if (!killed && exitCode && stderr) {
+      return sendErrorTelemetryEvent(
+        EventName.EXPERIMENTS_RUNNER_COMPLETED,
+        new Error(stderr),
+        duration,
+        properties
+      )
+    }
+
+    return sendTelemetryEvent(
+      EventName.EXPERIMENTS_RUNNER_COMPLETED,
+      { ...properties, wasStopped: killed },
+      { duration }
+    )
+  }
 }

extension/src/telemetry/constants.ts

@@ -19,6 +19,8 @@ export type ViewOpenedEventName =
 
 export const EventName = Object.assign(
   {
+    EXPERIMENTS_RUNNER_COMPLETED: 'experiments.runner.completed',
+
     EXTENSION_EXECUTION_DETAILS_CHANGED: 'extension.executionDetails.changed',
     EXTENSION_LOAD: 'extension.load',
 
@@ -50,6 +52,12 @@ export interface IEventNamePropertyMapping {
   [EventName.EXTENSION_EXECUTION_DETAILS_CHANGED]: ExtensionProperties
   [EventName.EXTENSION_LOAD]: ExtensionProperties
 
+  [EventName.EXPERIMENTS_RUNNER_COMPLETED]: {
+    command: string
+    exitCode: number | null
+    wasStopped?: boolean
+  }
+
   [EventName.EXPERIMENT_APPLY]: undefined
   [EventName.EXPERIMENT_BRANCH]: undefined
   [EventName.EXPERIMENT_FILTER_ADD]: undefined

extension/src/telemetry/index.ts

@@ -84,22 +84,33 @@ export const sendTelemetryEvent = <
   )
 }
 
-export const sendTelemetryEventAndThrow = <
+export const sendErrorTelemetryEvent = <
   P extends IEventNamePropertyMapping,
   E extends keyof P
 >(
   eventName: E,
   e: Error,
   duration: number,
   properties = {} as P[E]
-) => {
+) =>
   sendTelemetryEvent(
     `errors.${eventName}` as E,
     { ...properties, error: e.message } as P[E],
     {
       duration
     }
   )
+
+export const sendTelemetryEventAndThrow = <
+  P extends IEventNamePropertyMapping,
+  E extends keyof P
+>(
+  eventName: E,
+  e: Error,
+  duration: number,
+  properties = {} as P[E]
+) => {
+  sendErrorTelemetryEvent(eventName, e, duration, properties)
   throw e
 }
 

extension/src/test/suite/cli/runner.test.ts

@@ -1,11 +1,13 @@
 import { afterEach, beforeEach, describe, it, suite } from 'mocha'
 import { expect } from 'chai'
-import { restore, spy } from 'sinon'
+import { restore, spy, stub } from 'sinon'
 import { window, commands, Event, EventEmitter } from 'vscode'
 import { Disposable, Disposer } from '../../../extension'
 import { Config } from '../../../config'
 import { CliRunner } from '../../../cli/runner'
 import { CliResult, CliStarted } from '../../../cli'
+import * as Telemetry from '../../../telemetry'
+import { EventName } from '../../../telemetry/constants'
 
 suite('CLI Runner Test Suite', () => {
   window.showInformationMessage('Start all cli runner tests.')
@@ -125,5 +127,37 @@ suite('CLI Runner Test Suite', () => {
       expect((await eventStream).includes(text)).to.be.true
       return completed
     }).timeout(12000)
+
+    it('should send an error event if the command fails with an exit code and stderr', async () => {
+      const mockSendTelemetryEvent = stub(Telemetry, 'sendErrorTelemetryEvent')
+
+      const cliRunner = disposable.track(new CliRunner({} as Config, 'sleep'))
+
+      const cwd = __dirname
+
+      await cliRunner.run(cwd, '1', '&&', 'then', 'die')
+      const process = cliRunner.getRunningProcess()
+
+      const processCompleted = new Promise(resolve =>
+        process?.on('close', () => resolve(undefined))
+      )
+
+      await expect(process).to.eventually.be.rejectedWith(Error)
+
+      await processCompleted
+
+      const [eventName, error, , properties] =
+        mockSendTelemetryEvent.getCall(0).args
+
+      const { command, exitCode } = properties as {
+        command: string
+        exitCode?: number | undefined
+      }
+
+      expect(eventName).to.equal(EventName.EXPERIMENTS_RUNNER_COMPLETED)
+      expect(error.message).to.have.length.greaterThan(0)
+      expect(command).to.equal('sleep 1 && then die')
+      expect(exitCode).to.be.greaterThan(0)
+    }).timeout(4000)
   })
 })

extension/src/vscode/outputChannel.ts

@@ -37,9 +37,8 @@ export class OutputChannel {
     this.dispose.track(
       cli.onDidCompleteProcess(
         ({ command, duration, exitCode, pid, stderr }) => {
-          const processStatus = stderr
-            ? ProcessStatus.FAILED
-            : ProcessStatus.COMPLETED
+          const processStatus =
+            exitCode && stderr ? ProcessStatus.FAILED : ProcessStatus.COMPLETED
 
           const baseOutput = this.getBaseOutput(pid, command, processStatus)
           const completionOutput = this.getCompletionOutput(
@@ -80,7 +79,7 @@ export class OutputChannel {
 
     completionOutput += ` (${duration}ms)`
 
-    if (stderr) {
+    if (exitCode && stderr) {
       completionOutput += `\n${stderr}`
     }