Add slow recognition diagnostics

Ariver

2026-07-01 2547282e0942a09b67fccfd53cf62a403ccd4a52

 privatevoice.src/internal/input/paste_darwin.go

@@ -24,6 +24,11 @@
    [pb setString:str forType:NSPasteboardTypeString];
}

static void clearClipboardText(void) {
    NSPasteboard* pb = [NSPasteboard generalPasteboard];
    [pb clearContents];
}

static char* getClipboardText(void) {
    NSPasteboard* pb = [NSPasteboard generalPasteboard];
    NSString* str = [pb stringForType:NSPasteboardTypeString];
@@ -91,46 +96,141 @@

import (
   "fmt"
   "sync"
   "time"
   "unsafe"
   "voicesnap/internal/logger"
)

const (
   darwinClipboardVerifyTimeout = 500 * time.Millisecond
   darwinClipboardPollInterval  = 15 * time.Millisecond
   darwinClipboardRestoreDelay  = 900 * time.Millisecond
)

type darwinPaster struct{}

type darwinClipboardSnapshot struct {
   text    string
   hasText bool
}

type darwinPasteState struct {
   mu             sync.Mutex
   generation     uint64
   pendingRestore bool
   pendingText    string
   restoreTo      darwinClipboardSnapshot
}

var globalDarwinPasteState darwinPasteState

func newPlatformPaster() Paster {
   return &darwinPaster{}
}

func (p *darwinPaster) Paste(text string, keepClipboard bool) error {
   pasteStart := time.Now()
   textRunes := len([]rune(text))

   permissionStart := time.Now()
   if C.ensureInputPermission() == 0 {
      logger.Info(
         "PERF paste_clipboard_done result=permission_error permission_ms=%d text_runes=%d keep_clipboard=%t total_ms=%d",
         time.Since(permissionStart).Milliseconds(),
         textRunes,
         keepClipboard,
         time.Since(pasteStart).Milliseconds(),
      )
      return fmt.Errorf("accessibility permission is required to paste")
   }
   permissionElapsed := time.Since(permissionStart)

   var oldClip *string
   state := &globalDarwinPasteState
   stateLockStart := time.Now()
   state.mu.Lock()
   stateLockElapsed := time.Since(stateLockStart)
   state.generation++
   generation := state.generation

   snapshotStart := time.Now()
   originalClipboard := currentDarwinClipboardSnapshot()
   if !keepClipboard {
      cOld := C.getClipboardText()
      if cOld != nil {
         old := C.GoString(cOld)
         oldClip = &old
         C.free(unsafe.Pointer(cOld))
      }
      originalClipboard = resolveDarwinRestoreTarget(
         originalClipboard,
         state.pendingRestore,
         state.pendingText,
         state.restoreTo,
      )
   }
   snapshotElapsed := time.Since(snapshotStart)

   cstr := C.CString(text)
   defer C.free(unsafe.Pointer(cstr))
   setClipboardStart := time.Now()
   C.setClipboardText(cstr)
   time.Sleep(60 * time.Millisecond)
   C.simulateCmdV()
   setClipboardElapsed := time.Since(setClipboardStart)

   if !keepClipboard && oldClip != nil {
      go func(old string) {
         time.Sleep(600 * time.Millisecond)
         cOld := C.CString(old)
         defer C.free(unsafe.Pointer(cOld))
         C.setClipboardText(cOld)
      }(*oldClip)
   verifyStart := time.Now()
   if !waitForDarwinClipboardText(text, darwinClipboardVerifyTimeout) {
      verifyElapsed := time.Since(verifyStart)
      state.pendingRestore = false
      state.mu.Unlock()
      logger.Info(
         "PERF paste_clipboard_done result=verify_failed permission_ms=%d state_lock_ms=%d snapshot_ms=%d set_ms=%d verify_ms=%d text_runes=%d keep_clipboard=%t total_ms=%d",
         permissionElapsed.Milliseconds(),
         stateLockElapsed.Milliseconds(),
         snapshotElapsed.Milliseconds(),
         setClipboardElapsed.Milliseconds(),
         verifyElapsed.Milliseconds(),
         textRunes,
         keepClipboard,
         time.Since(pasteStart).Milliseconds(),
      )
      return fmt.Errorf("clipboard verification failed before paste")
   }
   verifyElapsed := time.Since(verifyStart)

   cmdVStart := time.Now()
   C.simulateCmdV()
   cmdVElapsed := time.Since(cmdVStart)

   if keepClipboard {
      state.pendingRestore = false
      state.mu.Unlock()
      logger.Info(
         "PERF paste_clipboard_done result=success permission_ms=%d state_lock_ms=%d snapshot_ms=%d set_ms=%d verify_ms=%d cmdv_ms=%d text_runes=%d keep_clipboard=%t total_ms=%d",
         permissionElapsed.Milliseconds(),
         stateLockElapsed.Milliseconds(),
         snapshotElapsed.Milliseconds(),
         setClipboardElapsed.Milliseconds(),
         verifyElapsed.Milliseconds(),
         cmdVElapsed.Milliseconds(),
         textRunes,
         keepClipboard,
         time.Since(pasteStart).Milliseconds(),
      )
      return nil
   }

   state.pendingRestore = true
   state.pendingText = text
   state.restoreTo = originalClipboard
   state.mu.Unlock()

   go restoreDarwinClipboardAfterPaste(generation, text, originalClipboard)
   logger.Info(
      "PERF paste_clipboard_done result=success permission_ms=%d state_lock_ms=%d snapshot_ms=%d set_ms=%d verify_ms=%d cmdv_ms=%d text_runes=%d keep_clipboard=%t total_ms=%d",
      permissionElapsed.Milliseconds(),
      stateLockElapsed.Milliseconds(),
      snapshotElapsed.Milliseconds(),
      setClipboardElapsed.Milliseconds(),
      verifyElapsed.Milliseconds(),
      cmdVElapsed.Milliseconds(),
      textRunes,
      keepClipboard,
      time.Since(pasteStart).Milliseconds(),
   )
   return nil
}

@@ -143,3 +243,82 @@
   }
   return nil
}

func currentDarwinClipboardSnapshot() darwinClipboardSnapshot {
   cText := C.getClipboardText()
   if cText == nil {
      return darwinClipboardSnapshot{}
   }
   defer C.free(unsafe.Pointer(cText))
   return darwinClipboardSnapshot{
      text:    C.GoString(cText),
      hasText: true,
   }
}

func resolveDarwinRestoreTarget(current darwinClipboardSnapshot, pending bool, pendingText string, restoreTo darwinClipboardSnapshot) darwinClipboardSnapshot {
   if pending && current.hasText && current.text == pendingText {
      return restoreTo
   }
   return current
}

func waitForDarwinClipboardText(expected string, timeout time.Duration) bool {
   deadline := time.Now().Add(timeout)
   for {
      current := currentDarwinClipboardSnapshot()
      if current.hasText && current.text == expected {
         return true
      }
      if time.Now().After(deadline) {
         return false
      }
      time.Sleep(darwinClipboardPollInterval)
   }
}

func restoreDarwinClipboardAfterPaste(generation uint64, pastedText string, restoreTo darwinClipboardSnapshot) {
   time.Sleep(darwinClipboardRestoreDelay)

   state := &globalDarwinPasteState
   state.mu.Lock()
   defer state.mu.Unlock()

   if state.generation != generation || !state.pendingRestore || state.pendingText != pastedText {
      return
   }

   current := currentDarwinClipboardSnapshot()
   if !shouldRestoreDarwinClipboard(
      state.generation,
      generation,
      state.pendingRestore,
      state.pendingText,
      pastedText,
      current,
   ) {
      state.pendingRestore = false
      return
   }

   restoreDarwinClipboardSnapshot(restoreTo)
   state.pendingRestore = false
}

func shouldRestoreDarwinClipboard(currentGeneration, restoreGeneration uint64, pending bool, pendingText, pastedText string, current darwinClipboardSnapshot) bool {
   if currentGeneration != restoreGeneration || !pending || pendingText != pastedText {
      return false
   }
   return current.hasText && current.text == pastedText
}

func restoreDarwinClipboardSnapshot(snapshot darwinClipboardSnapshot) {
   if !snapshot.hasText {
      C.clearClipboardText()
      return
   }

   cText := C.CString(snapshot.text)
   defer C.free(unsafe.Pointer(cText))
   C.setClipboardText(cText)
}