From 2547282e0942a09b67fccfd53cf62a403ccd4a52 Mon Sep 17 00:00:00 2001
From: Ariver <shanghai3168@gmail.com>
Date: Wed, 01 Jul 2026 23:21:18 +0800
Subject: [PATCH] Add slow recognition diagnostics

---
 privatevoice.src/app.go |   74 +++++++++++++++++++++++++++++++++++--
 1 files changed, 70 insertions(+), 4 deletions(-)

diff --git a/privatevoice.src/app.go b/privatevoice.src/app.go
index f9f6cd1..89ea0b6 100755
--- a/privatevoice.src/app.go
+++ b/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 {

--
Gitblit v1.9.3