feat(cli): add cli performance telemetry (heroku#2425) (heroku#2435)

* feat(cli): add cli performance telemetry (heroku#2425) * First pass with telemetry collection * Setup cli data collection for telemetry * WIP rollbar not logging with basic catch * WIP Successfully posted to rollbar * Add debugs to telemetry try-catches * Code clean up * WIP setting dev env * WIP trace and span setup * WIP sdk setup. Async not working anymore * WIP otel setup * WIP refactor otel setup * Rebase * WIP setting up new otel setup * WIP add required packages * Add telemetry to otel attributes & code clean up * Code clean up pass * Add bearer token & refactor * Refactor * Code clean up * Setup production environment in exporter * Re-yarn * chore(cli): add telemetry tests (heroku#2434) * First pass with telemetry collection * Setup cli data collection for telemetry * WIP rollbar not logging with basic catch * WIP Successfully posted to rollbar * Add debugs to telemetry try-catches * Code clean up * WIP setting dev env * WIP sdk setup. Async not working anymore * WIP otel setup * WIP refactor otel setup * Rebase * WIP setting up new otel setup * Add telemetry to otel attributes & code clean up * WIP tests for telemetry * Update process.on(exit) functionality & add tests * Code clean up * Rebase * Add types & code clean up * fix: make sure both honeycome and rollbar requests happen before process.ext * Make sendToRollbar awaitable --------- Co-authored-by: RyanDagg <[email protected]> * fix(cli): fix rollbar exitCode returning undefined (heroku#2440) * Fix exitCode bug * Update tests * WIP fix tests * Reinstate tests --------- Co-authored-by: RyanDagg <[email protected]>
usiegj00 · Aug 16, 2023 · 465c806 · 465c806
1 parent 1875102
commit 465c806
Show file tree

Hide file tree

Showing 6 changed files with 577 additions and 34 deletions.
diff --git a/packages/cli/bin/run b/packages/cli/bin/run
@@ -10,6 +10,11 @@ const globalTelemetry = require('../lib/global_telemetry')
 
 process.once('beforeExit', async code => {
   // capture as successful exit
+  if (global.cliTelemetry.isVersionOrHelp) {
+    const cmdStartTime = global.cliTelemetry.commandRunDuration
+    global.cliTelemetry.commandRunDuration = globalTelemetry.computeDuration(cmdStartTime)
+  }
+
   global.cliTelemetry.exitCode = code
   global.cliTelemetry.cliRunDuration = globalTelemetry.computeDuration(cliStartTime)
   const telemetryData = global.cliTelemetry
@@ -18,23 +23,27 @@ process.once('beforeExit', async code => {
 
 process.on('SIGINT', async () => {
   // capture as unsuccessful exit
-  let error = new Error('Received SIGINT')
+  const error = new Error('Received SIGINT')
   error.cliRunDuration = globalTelemetry.computeDuration(cliStartTime)
   await globalTelemetry.sendTelemetry(error)
+  process.exit(1)
 })
 
 process.on('SIGTERM', async () => {
   // capture as unsuccessful exit
-  let error = new Error('Received SIGTERM')
+  const error = new Error('Received SIGTERM')
   error.cliRunDuration = globalTelemetry.computeDuration(cliStartTime)
   await globalTelemetry.sendTelemetry(error)
+  process.exit(1)
 })
 
+globalTelemetry.initializeInstrumentation()
+
 const oclif = require('@oclif/core')
 
 oclif.run().then(require('@oclif/core/flush')).catch(async error => {
   // capture any errors raised by oclif
-  let cliError = error
+  const cliError = error
   cliError.cliRunDuration = globalTelemetry.computeDuration(cliStartTime)
   await globalTelemetry.sendTelemetry(cliError)
   console.log(`Error: ${error.message}`)

diff --git a/packages/cli/package.json b/packages/cli/package.json
@@ -33,6 +33,13 @@
     "@oclif/plugin-version": "^1.2.1",
     "@oclif/plugin-warn-if-update-available": "2.0.29",
     "@oclif/plugin-which": "2.2.8",
+    "@opentelemetry/api": "^1.4.1",
+    "@opentelemetry/exporter-trace-otlp-http": "^0.41.1",
+    "@opentelemetry/instrumentation": "^0.41.1",
+    "@opentelemetry/resources": "^1.15.1",
+    "@opentelemetry/sdk-trace-base": "^1.15.1",
+    "@opentelemetry/sdk-trace-node": "^1.15.1",
+    "@opentelemetry/semantic-conventions": "^1.15.1",
     "ansi-escapes": "3.2.0",
     "async-file": "^2.0.2",
     "chalk": "^2.4.2",
@@ -254,7 +261,8 @@
     "hooks": {
       "init": [
         "./lib/hooks/init/version",
-        "./lib/hooks/init/terms-of-service"
+        "./lib/hooks/init/terms-of-service",
+        "./lib/hooks/init/performance_analytics"
       ],
       "prerun": [
         "./lib/hooks/prerun/analytics"

diff --git a/packages/cli/src/global_telemetry.ts b/packages/cli/src/global_telemetry.ts
@@ -1,52 +1,129 @@
-import * as Rollbar from 'rollbar'
 import 'dotenv/config'
+import * as Rollbar from 'rollbar'
+import {APIClient} from '@heroku-cli/command'
+import {Config} from '@oclif/core'
+import opentelemetry, {SpanStatusCode} from '@opentelemetry/api'
+const {Resource} = require('@opentelemetry/resources')
+const {SemanticResourceAttributes} = require('@opentelemetry/semantic-conventions')
+const {registerInstrumentations} = require('@opentelemetry/instrumentation')
+const {NodeTracerProvider} = require('@opentelemetry/sdk-trace-node')
+const {BatchSpanProcessor} = require('@opentelemetry/sdk-trace-base')
+const {OTLPTraceExporter} = require('@opentelemetry/exporter-trace-otlp-http')
+const {version} = require('../../../packages/cli/package.json')
 const isDev = process.env.IS_DEV_ENVIRONMENT === 'true'
+const path = require('path')
+const root = path.resolve(__dirname, '../../../package.json')
+const config = new Config({root})
+const heroku = new APIClient(config)
+const token = heroku.auth
 
 const debug = require('debug')('global_telemetry')
+
 const rollbar = new Rollbar({
   accessToken: '41f8730238814af69c248e2f7ca59ff2',
   captureUncaught: true,
   captureUnhandledRejections: true,
   environment: isDev ? 'development' : 'production',
 })
 
+registerInstrumentations({
+  instrumentations: [],
+})
+
+const resource = Resource
+  .default()
+  .merge(
+    new Resource({
+      [SemanticResourceAttributes.SERVICE_NAME]: 'heroku-cli',
+      [SemanticResourceAttributes.SERVICE_VERSION]: version,
+    }),
+  )
+
+const provider = new NodeTracerProvider({
+  resource,
+})
+
+const headers = {Authorization: `Bearer ${token}`}
+
+const exporter = new OTLPTraceExporter({
+  url: isDev ? 'https://backboard-staging.herokuapp.com/otel/v1/traces' : 'https://backboard.heroku.com/otel/v1/traces',
+  headers,
+  compression: 'none',
+})
+export const processor = new BatchSpanProcessor(exporter)
+provider.addSpanProcessor(processor)
+
 interface Telemetry {
     command: string,
     os: string,
     version: string,
     exitCode: number,
-    exitState: string[],
+    exitState: string,
     cliRunDuration: number,
     commandRunDuration: number,
     lifecycleHookCompletion: {
       init: boolean,
       prerun: boolean,
       postrun: boolean,
       command_not_found: boolean,
-    }
+    },
+    isVersionOrHelp: boolean
 }
 
 export interface TelemetryGlobal extends NodeJS.Global {
   cliTelemetry?: Telemetry
 }
 
+interface CLIError extends Error {
+  cliRunDuration?: string
+}
+
+export function initializeInstrumentation() {
+  provider.register()
+}
+
 export function setupTelemetry(config: any, opts: any) {
   const now = new Date()
   const cmdStartTime = now.getTime()
-  return {
-    command: opts.Command.id,
-    os: config.platform,
-    version: config.version,
-    exitCode: 0,
-    exitState: [''],
-    cliRunDuration: 0,
-    commandRunDuration: cmdStartTime,
-    lifecycleHookCompletion: {
-      init: true,
-      prerun: true,
-      postrun: false,
-      command_not_found: false,
-    },
+  const isHelpOrVersionCmd = (opts.id === 'version' || opts.id === '--help')
+  const isRegularCmd = Boolean(opts.Command)
+
+  if (isHelpOrVersionCmd) {
+    return {
+      command: opts.id,
+      os: config.platform,
+      version: config.version,
+      exitCode: 0,
+      exitState: 'successful',
+      cliRunDuration: 0,
+      commandRunDuration: cmdStartTime,
+      lifecycleHookCompletion: {
+        init: true,
+        prerun: false,
+        postrun: false,
+        command_not_found: false,
+      },
+      isVersionOrHelp: true,
+    }
+  }
+
+  if (isRegularCmd) {
+    return {
+      command: opts.Command.id,
+      os: config.platform,
+      version: config.version,
+      exitCode: 0,
+      exitState: 'successful',
+      cliRunDuration: 0,
+      commandRunDuration: cmdStartTime,
+      lifecycleHookCompletion: {
+        init: true,
+        prerun: true,
+        postrun: false,
+        command_not_found: false,
+      },
+      isVersionOrHelp: false,
+    }
   }
 }
 
@@ -60,11 +137,11 @@ export function computeDuration(cmdStartTime: any) {
 
 export function reportCmdNotFound(config: any) {
   return {
-    command: '',
+    command: 'invalid_command',
     os: config.platform,
     version: config.version,
     exitCode: 0,
-    exitState: ['command_not_found'],
+    exitState: 'command_not_found',
     cliRunDuration: 0,
     commandRunDuration: 0,
     lifecycleHookCompletion: {
@@ -73,30 +150,81 @@ export function reportCmdNotFound(config: any) {
       postrun: false,
       command_not_found: true,
     },
+    isVersionOrHelp: false,
   }
 }
 
-export async function sendTelemetry(currentTelemetry: any) {
+export async function sendTelemetry(currentTelemetry: any,  rollbarCb?: () => void) {
   // send telemetry to honeycomb and rollbar
-  let telemetry = currentTelemetry
+  const telemetry = currentTelemetry
 
   if (telemetry instanceof Error) {
-    telemetry = {error_message: telemetry.message, error_stack: telemetry.stack}
-    telemetry.cliRunDuration = currentTelemetry.cliRunDuration
-    await sendToRollbar(telemetry)
+    await Promise.all([
+      sendToRollbar(telemetry, rollbarCb),
+      sendToHoneycomb(telemetry),
+    ])
+  } else {
+    await sendToHoneycomb(telemetry)
   }
+}
 
-  // add sendToHoneycomb function here
+export async function sendToHoneycomb(data: Telemetry | CLIError) {
+  try {
+    const tracer = opentelemetry.trace.getTracer('heroku-cli', version)
+    const span = tracer.startSpan('node_app_execution')
+
+    if (data instanceof Error) {
+      span.recordException(data)
+      span.setStatus({
+        code: SpanStatusCode.ERROR,
+        message: data.message,
+      })
+    } else {
+      span.setAttribute('heroku_client.command', data.command)
+      span.setAttribute('heroku_client.os', data.os)
+      span.setAttribute('heroku_client.version', data.version)
+      span.setAttribute('heroku_client.exit_code', data.exitCode)
+      span.setAttribute('heroku_client.exit_state', data.exitState)
+      span.setAttribute('heroku_client.cli_run_duration', data.cliRunDuration)
+      span.setAttribute('heroku_client.command_run_duration', data.commandRunDuration)
+      span.setAttribute('heroku_client.lifecycle_hook.init', data.lifecycleHookCompletion.init)
+      span.setAttribute('heroku_client.lifecycle_hook.prerun', data.lifecycleHookCompletion.prerun)
+      span.setAttribute('heroku_client.lifecycle_hook.postrun', data.lifecycleHookCompletion.postrun)
+      span.setAttribute('heroku_client.lifecycle_hook.command_not_found', data.lifecycleHookCompletion.command_not_found)
+    }
+
+    span.end()
+    processor.forceFlush()
+  } catch {
+    debug('could not send telemetry')
+  }
 }
 
-export async function sendToRollbar(data: any) {
+export async function sendToRollbar(data: CLIError, rollbarCb?: () => void) {
+  // Make this awaitable so we can wait for it to finish before exiting
+  let promiseResolve
+  const rollbarPromise = new Promise((resolve, reject) => {
+    promiseResolve = () => {
+      if (rollbarCb) {
+        try {
+          rollbarCb()
+        } catch (error: any) {
+          reject(error)
+        }
+      }
+
+      resolve(null)
+    }
+  })
+
+  const rollbarError = {name: data.name, message: data.message, stack: data.stack, cli_run_duration: data.cliRunDuration}
   try {
     // send data to rollbar
-    rollbar.error('Failed to complete execution', data, () => {
-      process.exit(1)
-    })
+    rollbar.error('Failed to complete execution', rollbarError, promiseResolve)
   } catch {
     debug('Could not send error report')
-    process.exit(1)
+    return Promise.reject()
   }
+
+  return rollbarPromise
 }
diff --git a/packages/cli/src/hooks/init/performance_analytics.ts b/packages/cli/src/hooks/init/performance_analytics.ts
@@ -0,0 +1,11 @@
+import {Hook} from '@oclif/core'
+
+import * as telemetry from '../../global_telemetry'
+
+declare const global: telemetry.TelemetryGlobal
+
+const performance_analytics: Hook<'init'> = async function (options) {
+  global.cliTelemetry = telemetry.setupTelemetry(this.config, options)
+}
+
+export default performance_analytics