Add slow recognition diagnostics

Ariver

2026-07-01 2547282e0942a09b67fccfd53cf62a403ccd4a52

 privatevoice.src/app.go

@@ -37,7 +37,8 @@
   silenceTimeoutDuration   = 3 * time.Second // auto-stop after this much silence in free-talk
   silenceGracePeriod       = 2 * time.Second // don't auto-stop within first 2s of free-talk
   holdActivationDelay      = 180 * time.Millisecond
   defaultReleaseTailDelay  = 300 * time.Millisecond
   slowRecognizeThresholdMs = int64(2000)
   slowPipelineThresholdMs  = int64(2500)
   doneIndicatorHideDelayMs = 250
   liveCaptionInterval      = 120 * time.Millisecond
   liveCaptionMaxBytes      = 108
@@ -859,6 +860,8 @@
   hotkeyVK := a.cfg.HotkeyVK
   autoHide := a.cfg.AutoHide
   copyToClipboard := a.cfg.CopyToClipboard
   selectedModelID := a.cfg.SelectedModelID
   languageID := a.cfg.LanguageID
   a.mu.Unlock()

   logger.Info(
@@ -901,12 +904,13 @@
   recognizeStart := time.Now()
   text, err := eng.Recognize(samples)
   recognizeElapsed := time.Since(recognizeStart)
   recognizeElapsedMS := perfDurationMS(recognizeElapsed)
   a.engineMu.Unlock()
   logger.Info(
      "PERF recognize_done id=%d engine_lock_wait_ms=%d recognize_ms=%d samples=%d audio_ms=%d since_start_ms=%d",
      perfID,
      perfDurationMS(engineLockElapsed),
      perfDurationMS(recognizeElapsed),
      recognizeElapsedMS,
      len(samples),
      perfAudioDurationMS(samples),
      perfSinceMS(pipelineStart),
@@ -976,8 +980,70 @@
   if soundFeedback {
      sound.PlayDone()
   }
   logger.Info("PERF pipeline_done id=%d result=success total_ms=%d", perfID, perfSinceMS(pipelineStart))
   totalMS := perfSinceMS(pipelineStart)
   logger.Info("PERF pipeline_done id=%d result=success total_ms=%d", perfID, totalMS)
   logSlowRecognitionIfNeeded(perfID, eng, selectedModelID, languageID, samples, recognizeElapsedMS, totalMS)
   a.delayedHideIf(autoHide, doneIndicatorHideDelayMs)
}

func logSlowRecognitionIfNeeded(perfID int64, eng engine.Engine, modelID, languageID string, samples []float32, recognizeMS, totalMS int64) {
   reason := slowRecognitionReason(recognizeMS, totalMS)
   if reason == "" {
      return
   }

   engineInfo := ""
   if eng != nil {
      engineInfo = eng.HardwareInfo()
   }

   load, hasLoad := currentSystemLoadAverage()
   if hasLoad {
      logger.Info(
         "PERF slow_recognition id=%d reason=%s model_id=%q language_id=%q engine=%q audio_ms=%d samples=%d recognize_ms=%d total_ms=%d load1=%.2f load5=%.2f load15=%.2f",
         perfID,
         reason,
         modelID,
         languageID,
         engineInfo,
         perfAudioDurationMS(samples),
         len(samples),
         recognizeMS,
         totalMS,
         load[0],
         load[1],
         load[2],
      )
      return
   }

   logger.Info(
      "PERF slow_recognition id=%d reason=%s model_id=%q language_id=%q engine=%q audio_ms=%d samples=%d recognize_ms=%d total_ms=%d load_unavailable=true",
      perfID,
      reason,
      modelID,
      languageID,
      engineInfo,
      perfAudioDurationMS(samples),
      len(samples),
      recognizeMS,
      totalMS,
   )
}

func slowRecognitionReason(recognizeMS, totalMS int64) string {
   recognizeSlow := recognizeMS > slowRecognizeThresholdMs
   totalSlow := totalMS > slowPipelineThresholdMs
   switch {
   case recognizeSlow && totalSlow:
      return "recognize,total"
   case recognizeSlow:
      return "recognize"
   case totalSlow:
      return "total"
   default:
      return ""
   }
}

// waitForHotkeyRelease polls until the hotkey is released (max 500ms),
@@ -1114,7 +1180,7 @@
   }
   tailCaptureEng, ok := eng.(engine.ReleaseTailCaptureEngine)
   if !ok {
      return defaultReleaseTailDelay
      return 0
   }
   delay := tailCaptureEng.ReleaseTailCaptureDelay()
   if delay < 0 {