fix: restore beforeExit handler for version commands and add comprehensive telemetry debug logging (#3657)

* fix: restore beforeExit handler for version commands and add comprehensive telemetry debug logging

* Clean up linting

Author: eablack

bin/run.js

@@ -12,9 +12,11 @@ process.env.HEROKU_UPDATE_INSTRUCTIONS = process.env.HEROKU_UPDATE_INSTRUCTIONS
 const now = new Date()
 const cliStartTime = now.getTime()
 
-const {isTelemetryEnabled} = await import('../dist/lib/analytics-telemetry/telemetry-utils.js')
+const {isTelemetryEnabled, getTelemetryDisabledReason, telemetryDebug} = await import('../dist/lib/analytics-telemetry/telemetry-utils.js')
+const enableTelemetry = isTelemetryEnabled()
 
-if (isTelemetryEnabled()) {
+if (enableTelemetry) {
+  telemetryDebug('Telemetry enabled: setting up handlers (beforeExit, SIGINT, SIGTERM)')
   // Dynamically import telemetry modules
   const {setupTelemetryHandlers} = await import('../dist/lib/analytics-telemetry/worker-client.js')
   const {computeDuration} = await import('../dist/lib/analytics-telemetry/telemetry-utils.js')
@@ -23,8 +25,11 @@ if (isTelemetryEnabled()) {
   setupTelemetryHandlers({
     cliStartTime,
     computeDuration,
-    enableTelemetry: isTelemetryEnabled(),
+    enableTelemetry,
   })
+} else {
+  const reason = getTelemetryDisabledReason()
+  telemetryDebug('Telemetry disabled (%s): skipping telemetry handler setup', reason)
 }
 
 await execute({dir: import.meta.url})

src/hooks/command_not_found/setup-otel-telemetry.ts

@@ -1,13 +1,16 @@
 import {Hook} from '@oclif/core/hooks'
 
 const performance_analytics: Hook<'command_not_found'> = async function () {
-  const {isTelemetryEnabled} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
+  const {isTelemetryEnabled, getTelemetryDisabledReason, telemetryDebug} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
 
   // Use the consolidated telemetry check
   if (!isTelemetryEnabled()) {
+    const reason = getTelemetryDisabledReason()
+    telemetryDebug('Telemetry disabled (%s): skipping command_not_found hook, not setting up telemetry for invalid command', reason)
     return
   }
 
+  telemetryDebug('Telemetry enabled: command_not_found hook setting up telemetry for invalid command')
   const {telemetryManager} = await import('../../lib/analytics-telemetry/telemetry-manager.js')
   const globalAny = global as any
   globalAny.cliTelemetry = telemetryManager.reportCmdNotFound(this.config)

src/hooks/finally/send-otel-and-sentry-errors.ts

@@ -40,13 +40,16 @@ const finallyHook: Hook<'finally'> = async function (options) {
     return
   }
 
-  const {isTelemetryEnabled, spawnTelemetryWorker} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
+  const {isTelemetryEnabled, getTelemetryDisabledReason, spawnTelemetryWorker, telemetryDebug} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
 
   // Use the consolidated telemetry check
   if (!isTelemetryEnabled()) {
+    const reason = getTelemetryDisabledReason()
+    telemetryDebug('Telemetry disabled (%s): skipping finally hook, not sending error: %s', reason, options.error.message)
     return
   }
 
+  telemetryDebug('Telemetry enabled: finally hook spawning worker to send error: %s', options.error.message)
   // Spawn background process to send error without blocking
   spawnTelemetryWorker(options.error)
 }

src/hooks/init/setup-otel-telemetry.ts

@@ -1,13 +1,16 @@
 import {Hook} from '@oclif/core/hooks'
 
 const performance_analytics: Hook<'init'> = async function (options) {
-  const {isTelemetryEnabled} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
+  const {isTelemetryEnabled, getTelemetryDisabledReason, telemetryDebug} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
 
   // Use the consolidated telemetry check
   if (!isTelemetryEnabled()) {
+    const reason = getTelemetryDisabledReason()
+    telemetryDebug('Telemetry disabled (%s): skipping init hook, not setting up telemetry object', reason)
     return
   }
 
+  telemetryDebug('Telemetry enabled: init hook setting up telemetry object for command')
   const {telemetryManager} = await import('../../lib/analytics-telemetry/telemetry-manager.js')
   const globalAny = global as any
   globalAny.cliTelemetry = telemetryManager.setupTelemetry(this.config, options)

src/hooks/postrun/send-otel-telemetry.ts

@@ -7,19 +7,25 @@ const performance_analytics: Hook<'postrun'> = async function () {
     return
   }
 
-  const {computeDuration, isTelemetryEnabled, spawnTelemetryWorker} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
+  const {computeDuration, isTelemetryEnabled, getTelemetryDisabledReason, spawnTelemetryWorker, telemetryDebug} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
 
   // Use the consolidated telemetry check
   if (!isTelemetryEnabled()) {
+    const reason = getTelemetryDisabledReason()
+    telemetryDebug('Telemetry disabled (%s): skipping postrun hook, not sending telemetry for command: %s', reason, globalAny.cliTelemetry.command)
     return
   }
 
+  telemetryDebug('Telemetry enabled: postrun hook spawning worker to send telemetry for command: %s', globalAny.cliTelemetry.command)
   const cmdStartTime = globalAny.cliTelemetry.commandRunDuration
   globalAny.cliTelemetry.commandRunDuration = computeDuration(cmdStartTime)
   globalAny.cliTelemetry.lifecycleHookCompletion.postrun = true
 
   // Spawn background process to send telemetry without blocking
   spawnTelemetryWorker(globalAny.cliTelemetry)
+
+  // Mark telemetry as sent to prevent duplicate sends from beforeExit handler
+  globalAny.telemetrySent = true
 }
 
 export default performance_analytics

src/hooks/prerun/collect-and-send-herokulytics.ts

@@ -1,13 +1,16 @@
 import {Hook} from '@oclif/core/hooks'
 
 const analytics: Hook<'prerun'> = async function (options) {
-  const {isTelemetryEnabled, spawnTelemetryWorker} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
+  const {isTelemetryEnabled, getTelemetryDisabledReason, spawnTelemetryWorker, telemetryDebug} = await import('../../lib/analytics-telemetry/telemetry-utils.js')
 
   // Use the consolidated telemetry check
   if (!isTelemetryEnabled()) {
+    const reason = getTelemetryDisabledReason()
+    telemetryDebug('Telemetry disabled (%s): skipping prerun hook, not sending Herokulytics for command: %s', reason, options.Command.id)
     return
   }
 
+  telemetryDebug('Telemetry enabled: prerun hook spawning worker to send Herokulytics for command: %s', options.Command.id)
   const {telemetryManager} = await import('../../lib/analytics-telemetry/telemetry-manager.js')
   const globalAny = global as any
 

src/lib/analytics-telemetry/telemetry-manager.ts

@@ -65,7 +65,6 @@ class TelemetryManager {
    */
   async sendTelemetry(currentTelemetry: TelemetryData): Promise<void> {
     if (!isTelemetryEnabled()) {
-      telemetryDebug('Telemetry disabled, skipping send')
       return
     }
 

src/lib/analytics-telemetry/telemetry-utils.ts

@@ -71,6 +71,7 @@ export type TelemetryData = CLIError | Telemetry
 
 export interface TelemetryGlobal {
   cliTelemetry?: Telemetry
+  telemetrySent?: boolean
 }
 
 // All data types that can be sent via worker
@@ -85,6 +86,25 @@ export function computeDuration(cmdStartTime: number): number {
   return cmdFinishTime - cmdStartTime
 }
 
+/**
+ * Get the reason why telemetry is disabled (for logging purposes)
+ */
+export function getTelemetryDisabledReason(): null | string {
+  if (process.env.DISABLE_TELEMETRY === 'true') {
+    return 'DISABLE_TELEMETRY=true'
+  }
+
+  if (process.platform === 'win32' && process.env.ENABLE_WINDOWS_TELEMETRY !== 'true') {
+    return 'Windows platform requires ENABLE_WINDOWS_TELEMETRY=true'
+  }
+
+  if (process.env.IS_HEROKU_TEST_ENV === 'true') {
+    return 'IS_HEROKU_TEST_ENV=true'
+  }
+
+  return null
+}
+
 /**
  * Get authentication token, cached to avoid recreating Config/APIClient
  * Lazy-loads @heroku-cli/command and @oclif/core/config to avoid loading them during CLI init
@@ -119,11 +139,21 @@ export function getVersion(): string {
 
 /**
  * Check if telemetry is enabled based on environment variables
+ * Returns both the enabled status and a reason string for logging
  */
 export function isTelemetryEnabled(): boolean {
-  if (process.env.DISABLE_TELEMETRY === 'true') return false
-  if (process.platform === 'win32' && process.env.ENABLE_WINDOWS_TELEMETRY !== 'true') return false
-  if (process.env.IS_HEROKU_TEST_ENV === 'true') return false
+  if (process.env.DISABLE_TELEMETRY === 'true') {
+    return false
+  }
+
+  if (process.platform === 'win32' && process.env.ENABLE_WINDOWS_TELEMETRY !== 'true') {
+    return false
+  }
+
+  if (process.env.IS_HEROKU_TEST_ENV === 'true') {
+    return false
+  }
+
   return true
 }
 

src/lib/analytics-telemetry/worker-client.ts

@@ -1,10 +1,13 @@
 /* eslint-disable n/no-process-exit */
-import {CLIError, spawnTelemetryWorker, TelemetryGlobal} from './telemetry-utils.js'
+/* eslint-disable no-var */
+import {
+  CLIError, spawnTelemetryWorker, telemetryDebug, TelemetryGlobal,
+} from './telemetry-utils.js'
 
 // Extend global with telemetry property
 declare global {
-  // eslint-disable-next-line no-var
   var cliTelemetry: TelemetryGlobal['cliTelemetry']
+  var telemetrySent: TelemetryGlobal['telemetrySent']
 }
 
 interface SetupTelemetryOptions {
@@ -14,17 +17,31 @@ interface SetupTelemetryOptions {
 }
 
 /**
- * Setup telemetry handlers for signal handlers
- * Note: Normal command completion telemetry is handled by the postrun hook.
- * This only handles SIGINT/SIGTERM cases where hooks don't run.
+ * Setup telemetry handlers for beforeExit and signal handlers
+ * - beforeExit: Fallback for commands where postrun hook doesn't run (e.g., version, --help flags)
+ * - postrun hook: Handles regular commands (sets telemetrySent flag to prevent duplicates)
+ * - SIGINT/SIGTERM: Handles interrupted commands
  */
 export function setupTelemetryHandlers(options: SetupTelemetryOptions): void {
   const {cliStartTime, computeDuration, enableTelemetry} = options
 
   if (!enableTelemetry) return
 
-  // Note: beforeExit handler removed to avoid duplicate telemetry sends.
-  // The postrun hook now handles normal command completion telemetry.
+  // Fallback handler for commands that don't trigger postrun hook
+  // (e.g., version, --version, --help flags handled by oclif)
+  process.once('beforeExit', code => {
+    // Only send if telemetry wasn't already sent by postrun hook
+    if (global.cliTelemetry && !global.telemetrySent) {
+      telemetryDebug('Telemetry enabled: beforeExit spawning worker to send telemetry for command: %s (postrun did not run)', global.cliTelemetry.command)
+      const cmdStartTime = global.cliTelemetry.commandRunDuration
+      global.cliTelemetry.commandRunDuration = computeDuration(cmdStartTime)
+      global.cliTelemetry.exitCode = code
+      global.cliTelemetry.cliRunDuration = computeDuration(cliStartTime)
+
+      spawnTelemetryWorker(global.cliTelemetry)
+      global.telemetrySent = true
+    }
+  })
 
   process.on('SIGINT', () => {
     // Spawn background process to send telemetry