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/internal/engine/engine_darwin.go | 17 +++-
privatevoice.src/internal/engine/engine_darwin_test.go | 29 +++++-
privatevoice.src/app.go | 74 +++++++++++++++++-
privatevoice.src/app_live_caption_test.go | 28 ++++++
privatevoice.src/internal/engine/engine_windows.go | 5 +
privatevoice.src/internal/engine/release_tail.go | 5 +
privatevoice.src/system_load_darwin.go | 16 ++++
privatevoice.src/system_load_other.go | 7 +
privatevoice.src/internal/engine/engine_linux.go | 5 +
9 files changed, 169 insertions(+), 17 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 {
diff --git a/privatevoice.src/app_live_caption_test.go b/privatevoice.src/app_live_caption_test.go
index c8380a7..321f388 100644
--- a/privatevoice.src/app_live_caption_test.go
+++ b/privatevoice.src/app_live_caption_test.go
@@ -38,12 +38,12 @@
}
}
-func TestReleaseTailCaptureDelayDefaultsToProtectionWindow(t *testing.T) {
+func TestReleaseTailCaptureDelayDefaultsToNoProtectionWindow(t *testing.T) {
a := &App{}
a.replaceEngine(plainTestEngine{})
- if got := a.releaseTailCaptureDelay(); got != defaultReleaseTailDelay {
- t.Fatalf("releaseTailCaptureDelay() = %v, want %v", got, defaultReleaseTailDelay)
+ if got := a.releaseTailCaptureDelay(); got != 0 {
+ t.Fatalf("releaseTailCaptureDelay() = %v, want 0", got)
}
}
@@ -56,6 +56,28 @@
}
}
+func TestSlowRecognitionReason(t *testing.T) {
+ tests := []struct {
+ name string
+ recognizeMS int64
+ totalMS int64
+ want string
+ }{
+ {name: "fast", recognizeMS: 2000, totalMS: 2500, want: ""},
+ {name: "recognize", recognizeMS: 2001, totalMS: 2400, want: "recognize"},
+ {name: "total", recognizeMS: 1000, totalMS: 2501, want: "total"},
+ {name: "both", recognizeMS: 2001, totalMS: 2501, want: "recognize,total"},
+ }
+
+ for _, tt := range tests {
+ t.Run(tt.name, func(t *testing.T) {
+ if got := slowRecognitionReason(tt.recognizeMS, tt.totalMS); got != tt.want {
+ t.Fatalf("slowRecognitionReason(%d, %d) = %q, want %q", tt.recognizeMS, tt.totalMS, got, tt.want)
+ }
+ })
+ }
+}
+
func TestHoldPreCaptureUsesEngineCapability(t *testing.T) {
a := &App{}
a.replaceEngine(holdPreCaptureTestEngine{enabled: true})
diff --git a/privatevoice.src/internal/engine/engine_darwin.go b/privatevoice.src/internal/engine/engine_darwin.go
index b45349d..ddf1ad8 100755
--- a/privatevoice.src/internal/engine/engine_darwin.go
+++ b/privatevoice.src/internal/engine/engine_darwin.go
@@ -27,8 +27,9 @@
)
type sherpaEngine struct {
- recognizer *sherpa.OfflineRecognizer
- hwInfo string
+ recognizer *sherpa.OfflineRecognizer
+ backendKind string
+ hwInfo string
}
type xasrStreamingEngine struct {
@@ -66,8 +67,9 @@
info := fmt.Sprintf("%s ยท %s", resolved.Profile.DisplayName, p.name)
logger.Info("Engine initialized: %s", info)
return &sherpaEngine{
- recognizer: recognizer,
- hwInfo: info,
+ recognizer: recognizer,
+ backendKind: resolved.BackendKind,
+ hwInfo: info,
}, nil
}
logger.Info("Failed to init with %s, trying next provider", p.name)
@@ -313,6 +315,13 @@
return e.hwInfo
}
+func (e *sherpaEngine) ReleaseTailCaptureDelay() time.Duration {
+ if e.backendKind == model.BackendSenseVoice {
+ return senseVoiceReleaseTailDelay
+ }
+ return 0
+}
+
func (e *xasrStreamingEngine) HardwareInfo() string {
return e.hwInfo
}
diff --git a/privatevoice.src/internal/engine/engine_darwin_test.go b/privatevoice.src/internal/engine/engine_darwin_test.go
index 0ffea21..245adc7 100644
--- a/privatevoice.src/internal/engine/engine_darwin_test.go
+++ b/privatevoice.src/internal/engine/engine_darwin_test.go
@@ -187,15 +187,32 @@
}
}
-func TestXASREnablesHoldPreCapture(t *testing.T) {
- if !(&xasrStreamingEngine{}).HoldPreCaptureEnabled() {
- t.Fatal("X-ASR should enable hold pre-capture")
+func TestSenseVoiceRequestsReleaseTailCaptureDelay(t *testing.T) {
+ got := (&sherpaEngine{backendKind: model.BackendSenseVoice}).ReleaseTailCaptureDelay()
+ if got != 100*time.Millisecond {
+ t.Fatalf("ReleaseTailCaptureDelay() = %v, want 100ms", got)
}
}
-func TestOfflineSherpaDoesNotRequestReleaseTailCapture(t *testing.T) {
- if _, ok := any(&sherpaEngine{}).(ReleaseTailCaptureEngine); ok {
- t.Fatal("offline sherpa engine should not request release tail capture")
+func TestOtherSherpaModelsDoNotRequestReleaseTailCaptureDelay(t *testing.T) {
+ for _, backendKind := range []string{
+ model.BackendMoonshine,
+ model.BackendTransducer,
+ model.BackendNemoTransducer,
+ model.BackendQwen3ASR,
+ } {
+ t.Run(backendKind, func(t *testing.T) {
+ got := (&sherpaEngine{backendKind: backendKind}).ReleaseTailCaptureDelay()
+ if got != 0 {
+ t.Fatalf("ReleaseTailCaptureDelay() = %v, want 0", got)
+ }
+ })
+ }
+}
+
+func TestXASREnablesHoldPreCapture(t *testing.T) {
+ if !(&xasrStreamingEngine{}).HoldPreCaptureEnabled() {
+ t.Fatal("X-ASR should enable hold pre-capture")
}
}
diff --git a/privatevoice.src/internal/engine/engine_linux.go b/privatevoice.src/internal/engine/engine_linux.go
index 41e18de..f452f33 100755
--- a/privatevoice.src/internal/engine/engine_linux.go
+++ b/privatevoice.src/internal/engine/engine_linux.go
@@ -4,6 +4,7 @@
import (
"fmt"
+ "time"
"voicesnap/internal/logger"
"voicesnap/internal/model"
@@ -57,6 +58,10 @@
return e.hwInfo
}
+func (e *sherpaEngine) ReleaseTailCaptureDelay() time.Duration {
+ return senseVoiceReleaseTailDelay
+}
+
func (e *sherpaEngine) Close() {
if e.recognizer != nil {
sherpa.DeleteOfflineRecognizer(e.recognizer)
diff --git a/privatevoice.src/internal/engine/engine_windows.go b/privatevoice.src/internal/engine/engine_windows.go
index 8df88fb..18d0b24 100755
--- a/privatevoice.src/internal/engine/engine_windows.go
+++ b/privatevoice.src/internal/engine/engine_windows.go
@@ -4,6 +4,7 @@
import (
"fmt"
+ "time"
"voicesnap/internal/logger"
"voicesnap/internal/model"
@@ -68,6 +69,10 @@
return e.hwInfo
}
+func (e *sherpaEngine) ReleaseTailCaptureDelay() time.Duration {
+ return senseVoiceReleaseTailDelay
+}
+
func (e *sherpaEngine) Close() {
if e.recognizer != nil {
sherpa.DeleteOfflineRecognizer(e.recognizer)
diff --git a/privatevoice.src/internal/engine/release_tail.go b/privatevoice.src/internal/engine/release_tail.go
new file mode 100644
index 0000000..9dd2bae
--- /dev/null
+++ b/privatevoice.src/internal/engine/release_tail.go
@@ -0,0 +1,5 @@
+package engine
+
+import "time"
+
+const senseVoiceReleaseTailDelay = 100 * time.Millisecond
diff --git a/privatevoice.src/system_load_darwin.go b/privatevoice.src/system_load_darwin.go
new file mode 100644
index 0000000..79000c5
--- /dev/null
+++ b/privatevoice.src/system_load_darwin.go
@@ -0,0 +1,16 @@
+//go:build darwin
+
+package main
+
+/*
+#include <stdlib.h>
+*/
+import "C"
+
+func currentSystemLoadAverage() ([3]float64, bool) {
+ var values [3]C.double
+ if C.getloadavg(&values[0], 3) != 3 {
+ return [3]float64{}, false
+ }
+ return [3]float64{float64(values[0]), float64(values[1]), float64(values[2])}, true
+}
diff --git a/privatevoice.src/system_load_other.go b/privatevoice.src/system_load_other.go
new file mode 100644
index 0000000..02f681d
--- /dev/null
+++ b/privatevoice.src/system_load_other.go
@@ -0,0 +1,7 @@
+//go:build !darwin
+
+package main
+
+func currentSystemLoadAverage() ([3]float64, bool) {
+ return [3]float64{}, false
+}
--
Gitblit v1.9.3