diff --git a/CLAUDE.md b/CLAUDE.md index 700a130..bee021a 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -5,8 +5,9 @@ This file provides guidance to Claude Code (claude.ai/code) when working with co **Note:** zee - push-to-talk transcription app. Runs as a system tray icon on macOS. ## Rules -- **CHANGELOG.md** — only log code/behavior changes. No docs, README, or comment-only updates. Be concise. +- **CHANGELOG.md** — do not touch it. It is written only at release time, by hand. Never add an entry for a fix, a feature, or anything else during normal work. - **docs/design-notes.md** — the *why* behind non-obvious choices, and the record of what was measured (including options tried and rejected). Read it before revisiting an engine/model/backend decision; a surprising line of code usually has its reason there. Add an entry when a decision rests on a measurement or a rejected alternative — facts, not narrative. When new evidence supersedes an entry, mark the old one superseded rather than deleting it; the code often still reflects why it *used* to be true. +- **No performance numbers in code comments** — they are machine-specific and go stale silently. Say *what* is slow and *why* ("-play blocks while it starts the audio hardware"), and put the measurement in `docs/design-notes.md`, where the hardware is on the record. If a number really must appear in a comment, name the machine with it (e.g. "~47 ms on an M5 Pro"). - **Clean package interface** — every package must expose a single, platform-neutral interface describing *what it provides*, defined once (typically in `.go`). Public API, shared types, and guard logic live there; platform/provider files (build-tag variants) only implement the backend hooks. Never duplicate the public API across build-tag files (see `audio/`: `audio.go` owns the capture interface plus `PlayStart/PlayEnd/...`, platform files provide only the backends — `initSound`/`playOne` for playback, the malgo/pulse capture impls). ## Build & Run diff --git a/audio/beep_darwin.m b/audio/beep_darwin.m index 56be133..5f3df5d 100644 --- a/audio/beep_darwin.m +++ b/audio/beep_darwin.m @@ -1,12 +1,23 @@ #import // Feedback tones via AVAudioPlayer: the OS owns the audio machinery, so a beep -// is fire-and-forget with no app-managed device to init, keep warm, or -// serialize against capture. Players are built once from in-memory WAV bytes; -// each play restarts from the top so a rapid start-then-end beep both sound. +// needs no app-managed device to init, keep warm, or serialize against capture. +// Players are built once from in-memory WAV bytes; each play restarts from the +// top so a rapid start-then-end beep both sound. static AVAudioPlayer *_players[8]; +// Serial, so two beeps never touch one player's currentTime concurrently — +// AVAudioPlayer is not documented thread-safe. +static dispatch_queue_t beepQueue(void) { + static dispatch_queue_t q; + static dispatch_once_t once; + dispatch_once(&once, ^{ + q = dispatch_queue_create("dev.zee.beep", DISPATCH_QUEUE_SERIAL); + }); + return q; +} + void zeeBeepLoad(int idx, const void *wav, int len) { NSData *data = [NSData dataWithBytes:wav length:(NSUInteger)len]; AVAudioPlayer *p = [[AVAudioPlayer alloc] initWithData:data error:nil]; @@ -14,9 +25,16 @@ void zeeBeepLoad(int idx, const void *wav, int len) { _players[idx] = p; } +// zeeBeepPlay dispatches instead of playing inline: -play blocks while it starts +// the audio hardware — prepareToPlay does not prevent it, and the hardware powers +// back down between beeps — and that landed on the push-to-talk path twice per +// dictation, at press and at release. The user hears the tone at the same moment; +// only the caller's wait is gone. Measured cost in docs/design-notes.md. void zeeBeepPlay(int idx) { AVAudioPlayer *p = _players[idx]; if (p == nil) return; - p.currentTime = 0; - [p play]; + dispatch_async(beepQueue(), ^{ + p.currentTime = 0; + [p play]; + }); } diff --git a/clipboard/clipboard.go b/clipboard/clipboard.go index 50fb860..46a5569 100644 --- a/clipboard/clipboard.go +++ b/clipboard/clipboard.go @@ -1,11 +1,7 @@ package clipboard -import cb "github.com/atotto/clipboard" +// Read returns the clipboard's current text, or "" when it holds none. +func Read() (string, error) { return read() } -func Read() (string, error) { - return cb.ReadAll() -} - -func Copy(text string) error { - return cb.WriteAll(text) -} +// Copy replaces the clipboard contents with text. +func Copy(text string) error { return write(text) } diff --git a/clipboard/clipboard_darwin.go b/clipboard/clipboard_darwin.go index 1b54785..270d904 100644 --- a/clipboard/clipboard_darwin.go +++ b/clipboard/clipboard_darwin.go @@ -1,9 +1,14 @@ package clipboard /* -#cgo LDFLAGS: -framework ApplicationServices +#cgo LDFLAGS: -framework AppKit -framework ApplicationServices +#include #include +int clipCopy(const char *utf8); +char *clipRead(void); +void clipPaste(void); + static int testAccessibility() { return AXIsProcessTrusted(); } @@ -11,50 +16,38 @@ static int testAccessibility() { import "C" import ( - "os" - "strings" - "sync" - - "github.com/micmonay/keybd_event" + "errors" + "unsafe" ) -var ( - kb keybd_event.KeyBonding - kbOnce sync.Once - kbErr error -) +// Init is a no-op on macOS — NSPasteboard and CGEvent need no setup. It exists +// because the Linux backend must open /dev/uinput before the first paste. +func Init() error { return nil } -// ensureUTF8Locale guarantees pbcopy/pbpaste interpret text as UTF-8. -// GUI apps launched from Finder inherit no LANG/LC_CTYPE, so pbcopy falls -// back to a legacy encoding and mangles multi-byte characters (e.g. Turkish -// ğ ş ı İ ç ö ü). Setting LC_CTYPE to a UTF-8 locale fixes this for the child -// process that atotto/clipboard exec's. We only override when the current -// ctype locale is not already UTF-8, so an explicit tr_TR.UTF-8 etc. is kept. -func init() { - isUTF8 := func(v string) bool { - v = strings.ToLower(v) - return strings.Contains(v, "utf-8") || strings.Contains(v, "utf8") +func write(text string) error { + c := C.CString(text) + defer C.free(unsafe.Pointer(c)) + if C.clipCopy(c) == 0 { + return errors.New("pasteboard rejected the write") } - if isUTF8(os.Getenv("LC_ALL")) || isUTF8(os.Getenv("LC_CTYPE")) || isUTF8(os.Getenv("LANG")) { - return - } - os.Setenv("LC_CTYPE", "en_US.UTF-8") + return nil } -func Init() error { - kbOnce.Do(func() { - kb, kbErr = keybd_event.NewKeyBonding() - }) - return kbErr +func read() (string, error) { + c := C.clipRead() + if c == nil { + return "", nil // no text on the pasteboard; not an error + } + defer C.free(unsafe.Pointer(c)) + return C.GoString(c), nil } +// Paste fires Cmd+V. macOS reports nothing when Accessibility is missing — the +// events are simply dropped — so there is no error to return here; the setup +// wizard uses CheckAccessibility to catch that case up front. func Paste() error { - if err := Init(); err != nil { - return err - } - kb.SetKeys(keybd_event.VK_V) - kb.HasSuper(true) // Cmd+V on macOS - return kb.Launching() + C.clipPaste() + return nil } func CheckAccessibility() bool { diff --git a/clipboard/clipboard_darwin.m b/clipboard/clipboard_darwin.m new file mode 100644 index 0000000..0355f5b --- /dev/null +++ b/clipboard/clipboard_darwin.m @@ -0,0 +1,55 @@ +#import +#import +#include + +// NSPasteboard + CGEvent, called from clipboard_darwin.go. (Objective-C can't +// live in a cgo preamble — it is compiled as C — so it goes here, mirroring +// permissions/permissions_darwin.m.) +// +// Both replace things that cost real felt latency: pbcopy/pbpaste fork(), and +// fork freezes every thread for O(resident memory), which is significant once a +// local model is resident — while keybd_event held Cmd+V down for a hardcoded +// 100 ms sleep. Measurements in docs/design-notes.md. + +// clipCopy replaces the pasteboard with one UTF-8 text item. Returns 1 on +// success. No locale involved, unlike the pbcopy child process it replaces. +int clipCopy(const char *utf8) { + @autoreleasepool { + NSString *s = [NSString stringWithUTF8String:utf8]; + if (s == nil) { + return 0; + } + NSPasteboard *pb = [NSPasteboard generalPasteboard]; + [pb clearContents]; + return [pb setString:s forType:NSPasteboardTypeString] ? 1 : 0; + } +} + +// clipRead returns the pasteboard's text, malloc'd for the caller to free, or +// NULL when it holds no text (empty, or an image). +char *clipRead(void) { + @autoreleasepool { + NSString *s = [[NSPasteboard generalPasteboard] stringForType:NSPasteboardTypeString]; + if (s == nil) { + return NULL; + } + return strdup([s UTF8String]); + } +} + +// clipPaste synthesizes Cmd+V into whichever app has focus. Deliberately the +// same event mechanism as the keybd_event call it replaces — NULL source, +// annotated session tap, flags set explicitly so a physically-held modifier +// cannot leak in — minus the sleep between down and up. Requires Accessibility; +// without it macOS drops the events silently. +void clipPaste(void) { + const CGKeyCode kVK_V = 0x09; + CGEventRef down = CGEventCreateKeyboardEvent(NULL, kVK_V, true); + CGEventRef up = CGEventCreateKeyboardEvent(NULL, kVK_V, false); + CGEventSetFlags(down, kCGEventFlagMaskCommand); + CGEventSetFlags(up, kCGEventFlagMaskCommand); + CGEventPost(kCGAnnotatedSessionEventTap, down); + CGEventPost(kCGAnnotatedSessionEventTap, up); + CFRelease(down); + CFRelease(up); +} diff --git a/clipboard/clipboard_darwin_test.go b/clipboard/clipboard_darwin_test.go new file mode 100644 index 0000000..a275061 --- /dev/null +++ b/clipboard/clipboard_darwin_test.go @@ -0,0 +1,35 @@ +package clipboard + +import "testing" + +// Round-trips through the real pasteboard, restoring whatever was there. The +// Turkish characters are the point: the pbcopy backend mangled them unless +// LC_CTYPE was forced to UTF-8, and NSPasteboard takes an NSString directly, so +// the locale hack could go. +func TestCopyReadRoundTrip(t *testing.T) { + prev, err := Read() + if err != nil { + t.Fatalf("Read: %v", err) + } + t.Cleanup(func() { Copy(prev) }) + + const want = "zee ğşıİçöü — naïve 日本語" + if err := Copy(want); err != nil { + t.Fatalf("Copy: %v", err) + } + got, err := Read() + if err != nil { + t.Fatalf("Read: %v", err) + } + if got != want { + t.Errorf("round trip: got %q, want %q", got, want) + } +} + +func BenchmarkCopy(b *testing.B) { + prev, _ := Read() + b.Cleanup(func() { Copy(prev) }) + for b.Loop() { + Copy("the quick brown fox jumps over the lazy dog") + } +} diff --git a/clipboard/clipboard_linux.go b/clipboard/clipboard_linux.go index 80dad22..e8d580f 100644 --- a/clipboard/clipboard_linux.go +++ b/clipboard/clipboard_linux.go @@ -7,8 +7,15 @@ import ( "sync" "syscall" "time" + + cb "github.com/atotto/clipboard" ) +// xclip/xsel via atotto: the fork cost that made macOS go native is not worth +// a second native backend here, where no local model inflates resident memory. +func read() (string, error) { return cb.ReadAll() } +func write(text string) error { return cb.WriteAll(text) } + // ioctl constants from linux/uinput.h const ( uiSetEvbit = 0x40045564 // UI_SET_EVBIT diff --git a/clipboard_session.go b/clipboard_session.go index 4b12ccc..6ec0d47 100644 --- a/clipboard_session.go +++ b/clipboard_session.go @@ -19,18 +19,23 @@ type clipboardSession struct { var clip clipboardSession -func (c *clipboardSession) PasteText(text string) { +func (c *clipboardSession) PasteText(text string) (copyMs, keyMs float64) { c.mu.Lock() defer c.mu.Unlock() // Log failures — a broken paste (revoked Accessibility, pbcopy error) is // otherwise indistinguishable from "no text" for the user. + t := time.Now() if err := clipboard.Copy(text); err != nil { log.Warnf("paste: clipboard copy failed: %v", err) return } + copyMs = float64(time.Since(t).Microseconds()) / 1000 + t = time.Now() if err := clipboard.Paste(); err != nil { log.Warnf("paste: keystroke failed (Accessibility?): %v", err) } + keyMs = float64(time.Since(t).Microseconds()) / 1000 + return copyMs, keyMs } func (c *clipboardSession) SaveCurrent() string { diff --git a/docs/design-notes.md b/docs/design-notes.md index 5789e87..ab2a47e 100644 --- a/docs/design-notes.md +++ b/docs/design-notes.md @@ -509,6 +509,77 @@ Kept enabled because it only costs when it fires, and when it fires it is rescuing quality on hard audio. Revisit if diagnostics ever show an `inference_ms` far above its `audio_s` peers (the stall signature). +## How the Core ML/ANE path actually works (mechanism, source-verified 2026-08-04) + +Reference for the entry above ("Metal, not Core ML/ANE"). Recorded because the +shape of this path is counter-intuitive and the decision only makes sense once +you see it. Verified by reading `third_party/whisper.cpp` at v1.9.1 (`f049fff9`) +and inspecting the PoC bundle in `~/Desktop/p/personal/zee-whisper-poc/models`. + +**The ANE runs the encoder only. It never runs the model.** `whisper_encode_ +external()` (`src/whisper.cpp:1958`) returns true when a Core ML context is +loaded; the mel-conv and encoder ggml graphs are then skipped entirely and +`whisper_coreml_encode()` writes straight into `wstate.embd_enc` +(`src/whisper.cpp:2412`). Everything after that — the autoregressive decoder, +KV caches, sampling — stays on ggml/Metal, untouched. Split: + +``` +audio → mel → [conv + ENCODER] → ANE, Core ML, fp16, .mlmodelc, one pass + ↓ embd_enc + [DECODER loop] → ggml/Metal + CPU, q5_0, .gguf + ↓ + text +``` + +**Why only the encoder, structurally.** The encoder is a single pass over a +fixed 1500-frame window — static shapes, big matmuls, exactly what the ANE +compiler wants. The decoder runs once per token with a growing KV cache and +variable length; Core ML can't express that usefully. Upstream converted it +once and shelved it: `models/convert-whisper-to-coreml.py` still carries +`convert_decoder()`, but `generate-coreml-model.sh` hardcodes +`--encoder-only True` and ends with `# TODO: decoder (sometime in the future +maybe)`. This is a property of the ANE, not a whisper.cpp gap — the same +constraint is why FluidAudio/VoiceInk can put *Parakeet* on the ANE (small, +static, CTC/TDT head) but nobody ships an ANE Whisper decoder. + +**So you download both files, and the second one is additive.** The full gguf +is always loaded (it holds the decoder); the mlmodelc is loaded *on top* +(`src/whisper.cpp:3440`). Hence "+1.2 GB per model", not "1.2 GB instead of +547 MB". + +**gguf quantization can never reach the ANE.** whisper derives the bundle path +from the model path and explicitly strips a `-qX_X` suffix +(`whisper_get_coreml_path_encoder`, `src/whisper.cpp:3326`): `ggml-large-v3- +turbo-q5_0.bin` → `ggml-large-v3-turbo-encoder.mlmodelc`. One encoder bundle +serves every quantization of a model family, by design. There is therefore no +"quantized model on the ANE" configuration to test — the ANE measurements in +the entry above were *already* q5_0-gguf + fp16-ANE-encoder, which is the only +shape this path has. + +**What the bundle is, measured.** `weight.bin` = 1,273,969,152 B ≈ 635 M params +× 2 B → fp16. `metadata.json`: `storagePrecision: Float16`, `computePrecision: +Mixed (Float16, Float32, Int32)`. Note the converter's `--quantize` flag means +*fp32 → fp16*, not int8 (`convert-whisper-to-coreml.py:303`, default False, and +`generate-coreml-model.sh` never passes it) — our 1.27 GB bundle is fp16 because +it came prebuilt from HuggingFace, not from that script. A leftover empty +`ggml-large-v3-turbo-q5_0-encoder.mlmodelc/` in the PoC is the dead end from +before the strip logic was understood. + +**The one untested variant, and why it is not the win it sounds like.** The +mlmodelc has its own compression track — `coremltools.optimize.coreml` +(palettization, int8 linear) — never tried here. It would attack payload +(1.27 GB → maybe ~350 MB) but not latency: ANE compute is fp16 regardless, so +compressed weights are expanded before the math. It also leaves both real +blockers intact — the per-update ANE recompile (~2.5 min on M1) and a second +asset pipeline. Worth trying only inside the still-open "ANE on M1-class +hardware only" idea, where it makes the payload tolerable. + +**Corollary: ANE and `audio_ctx` sizing compete for the same win.** Both +accelerate the encoder and nothing else — but Core ML fixes the encoder input +at 1500 frames, so they are mutually exclusive, and sizing measured ~6× on the +encoder against ANE's ~1.2×, with no second file and no recompile. + + ## Parakeet v3 back as the fast multilingual option (2026-07-26) models-v2 retired `parakeet-v3-multi` on the premise that Whisper *strictly* @@ -776,8 +847,14 @@ Two findings, each sufficient on its own: - **medium is dominated, never an option.** It is *slower* than the quantized turbo on both language settings AND less accurate. The reason is structural: turbo pairs the large encoder with a 4-layer decoder, medium carries a full - 24-layer decoder — and decode runs on CPU, so medium pays 201 ms vs turbo's - 42 ms on this clip. There is no clip length or hardware where medium wins. + 24-layer decoder, so medium pays 201 ms vs turbo's 42 ms on this clip. There + is no clip length or hardware where medium wins. (An earlier draft of this + note blamed "decode runs on CPU" — that is wrong. `sched_decode` is built + over the same `{Metal, CPU}` backend list as the encoder, + `third_party/whisper.cpp/src/whisper.cpp:874`. The cost is structural to + batch-1 autoregressive decoding — one sequential pass per token, dominated + by kernel-launch and weight-read latency rather than FLOPs — which is + exactly the regime where GPU offload buys the least.) - **small's speed is real but its accuracy is not good enough.** ~1.8× faster than turbo with a forced language, ~2.4× with auto-detect (detect cost scales with encoder size: +58 ms vs +265 ms). But on the code-switched clip @@ -819,6 +896,49 @@ to turbo-auto on low confidence?), memory cost of a second loaded model irrelevant), and whether the detect pass can run on a short prefix. +## Open/untested: Voxtral as a local engine (recorded 2026-08-04) + +**Never measured.** Voxtral exists in zee only as a cloud provider +(`transcriber/mistral.go`, `voxtral-mini-latest`). No local Voxtral has been +run, so nothing below is a measurement — it is desk research plus one +structural argument that is itself unverified. Recorded so the next person +starts from the open question rather than from scratch. + +Two candidate local paths, and why neither has been tried: + +- **`antirez/voxtral.c`** — runs Voxtral Realtime 4B (0.6B encoder + 3.4B + decoder). Rejected on size alone, without benchmarking: **BF16 only, no + quantization supported or planned**. 8.9 GB weights on disk, ~8.4 GB GPU + weight cache, ~1.8 GB KV. zee's whole multilingual model is 547 MB. Its + published M3 Max numbers — 284 ms encoder for 3.6 s of audio, 23.5 ms/decode + step — put a 10 s dictation somewhere near 1.5–2 s against turbo-q5's + ~330 ms, but that comparison was never run head-to-head here. It also + carries its own hand-written Metal kernels rather than ggml, so it would be + a *third* engine outside the single-ggml build, not a backend swap. Author's + own caveat: "mostly tested against few samples, and likely requires some + more work to be production quality." +- **Voxtral-Mini-3B via llama.cpp `mtmd`** — this is the path that is actually + open. Quantized GGUFs exist (`ggml-org/Voxtral-Mini-3B-2507-GGUF`, + bartowski's variants; Q4_K ≈ 2 GB), and it is the same ggml family zee + already builds. **The reason it looks unattractive is a hypothesis, not a + result:** a 3B LLM decoder generating token-by-token should land in the same + regime that made whisper-medium lose to turbo (see the note above) — the + cost of autoregressive decode scales with decoder depth × tokens and is + latency-bound, so Metal offload does not rescue it. But that reasoning is + extrapolated from whisper's 24-layer decoder to a different architecture on + a different runtime, and llama.cpp is far better optimised for exactly this + workload (batched KV, flash-attn, Metal graph reuse) than whisper.cpp's + decode path is. **It could be wrong.** Nobody has timed a Q4 Voxtral-Mini on + an M-series chip against turbo-q5 on the same clip. + +Cheapest way to close the question, in order: (1) run the existing *cloud* +Voxtral over saved samples (`/wer-wolf`) — if its accuracy on code-switched +tr/en is not clearly better than turbo, the local port is moot regardless of +speed; (2) only if it is, time `llama-mtmd-cli` with a Q4 GGUF against +`whisper-cli` with `ggml-large-v3-turbo-q5_0.bin` on the same clip, and +settle the decode-cost hypothesis with a number. + + ## STT landscape: what comparable apps ship (reference, verified 2026-08-03) Reference material for engine decisions, not a decision itself. Verified by @@ -851,3 +971,56 @@ Takeaways: English-only today); Apple Speech as a zero-download built-in fallback (offline, supports tr-TR, accuracy below turbo); ONNX Parakeet (Handy) only matters for a Windows/Linux port. + +## The felt-latency tail is paste, not inference (measured 2026-08-06) + +`felt_latency` used to log one number, so "parakeet feels slow" could not be +attributed. It now itemizes the release→text window (tail wait, mic stop, PCM +convert, inference, clipboard save, paste copy, paste keystroke, plus an +`unaccounted_ms` remainder). What that showed, over ~57 dictations: + +- **Felt latency was near-constant (~900–1100 ms) while inference swung + 100→700 ms.** That signature means fixed overhead dominated, not the model. + It also explains an earlier misreading: inference looked *inversely* + correlated with clip length, which was an artifact of the constant total. +- **The overhead was the clipboard, not the engine.** On a representative + 22.6 s clip: inference 298 ms against 255 ms of serial paste work — + `paste_copy_ms` 141 ms (pbcopy) + `paste_key_ms` 114 ms (keybd_event). + +Two distinct causes, both now removed on macOS (`clipboard/clipboard_darwin.m`): + +- **fork() cost scales with resident memory.** atotto's Copy/Read exec pbcopy + and pbpaste; fork freezes every thread while the kernel clones page tables, + which is ~140–250 ms once a local model is resident (RSS ~660 MB). Replaced + with NSPasteboard: **172 µs** for a copy, ~800x faster, and it removes the + `LC_CTYPE=en_US.UTF-8` hack that existed only so the pbcopy *child* would not + mangle Turkish characters — NSString carries the encoding itself. +- **keybd_event slept 100 ms between key down and key up** (`tapKey`, with the + comment "ignore if speed is most in my test system"). Replaced with a direct + CGEvent pair, deliberately using the same mechanism it had proven — NULL + source, `kCGAnnotatedSessionEventTap`, explicit flags — minus the sleep. + +**The feedback beep was blocking the release path (M5 Pro).** With the clipboard +fixed, a stubborn ~50 ms remainder was left in `unaccounted_ms`. One-off probes +across every unmeasured segment found all of them clean (tray 0.18 ms, meter +stats 0.09 ms, goroutine handoff 0.04 ms, `updatesDone` 0.00 ms, `captureRSS` +23 us despite gopsutil dlopen/dlclose-ing libproc per call) except one: +`audio.PlayEnd()` at **46-49 ms**, matching the remainder almost exactly. + +AVAudioPlayer's `-play` blocks while it starts the audio hardware. `prepareToPlay` +at load does not prevent it, and the cost recurs every time — the hardware powers +back down between beeps — so it was not warmup. The header comment claiming +"fire-and-forget" was aspirational; the call was inline and synchronous. Now +dispatched to a serial queue (`audio/beep_darwin.m`): the tone still sounds at the +same instant, the caller no longer waits. It was on the push-to-talk path *twice* +per dictation, so `PlayStart` at press was paying it too, inflating +`press_to_record_ms`. + +**The clipboard *save* fork was already free, and that is worth remembering.** +`clip_save_ms` ran 241 ms but `clip_wait_ms` was 0: it overlaps inference by +design (saved lazily after recording ends, never during the press — see +`main.go`). It only becomes visible when inference is faster than the fork, so +the fix had to cover Read as well as Copy, not just the obviously-serial half. + +Linux keeps the atotto backend: no local model inflates RSS there, so the fork +is cheap and a second native backend would not pay for itself. diff --git a/go.mod b/go.mod index d2b8ce1..03e632b 100644 --- a/go.mod +++ b/go.mod @@ -12,7 +12,6 @@ require ( github.com/jfreymuth/pulse v0.1.1 github.com/maxhawkins/go-webrtcvad v0.0.0-20210121163624-be60036f3083 github.com/mewkiz/flac v1.0.13 - github.com/micmonay/keybd_event v1.1.2 github.com/rs/zerolog v1.34.0 github.com/shirou/gopsutil/v4 v4.26.5 golang.design/x/hotkey v0.4.1 diff --git a/go.sum b/go.sum index 778d0c2..41aafd8 100644 --- a/go.sum +++ b/go.sum @@ -89,8 +89,6 @@ github.com/mewkiz/pkg v0.0.0-20250417130911-3f050ff8c56d h1:IL2tii4jXLdhCeQN69HN github.com/mewkiz/pkg v0.0.0-20250417130911-3f050ff8c56d/go.mod h1:SIpumAnUWSy0q9RzKD3pyH3g1t5vdawUAPcW5tQrUtI= github.com/mewpkg/term v0.0.0-20241026122259-37a80af23985 h1:h8O1byDZ1uk6RUXMhj1QJU3VXFKXHDZxr4TXRPGeBa8= github.com/mewpkg/term v0.0.0-20241026122259-37a80af23985/go.mod h1:uiPmbdUbdt1NkGApKl7htQjZ8S7XaGUAVulJUJ9v6q4= -github.com/micmonay/keybd_event v1.1.2 h1:RpgvPJKOh4Jc+ZYe0OrVzGd2eNMCfuVg3dFTCsuSah4= -github.com/micmonay/keybd_event v1.1.2/go.mod h1:CGMWMDNgsfPljzrAWoybUOSKafQPZpv+rLigt2LzNGI= github.com/mitchellh/hashstructure/v2 v2.0.2 h1:vGKWl0YJqUNxE8d+h8f6NJLcCJrgbhC4NcD46KavDd4= github.com/mitchellh/hashstructure/v2 v2.0.2/go.mod h1:MG3aRVU/N29oo/V/IhBX8GR/zz4kQkprJgF2EVszyDE= github.com/muesli/cancelreader v0.2.2 h1:3I4Kt4BQjOR54NavqnDogx/MIoWBFa0StPA8ELUXHmA= diff --git a/log/log.go b/log/log.go index 46f1cbb..fe03e28 100644 --- a/log/log.go +++ b/log/log.go @@ -232,16 +232,54 @@ func HotkeyPress(downToUpMs float64, mode string) { diagLog.Info().Float64("down_to_up_ms", downToUpMs).Str("mode", mode).Msg("hotkey_press") } +// LatencyBreakdown itemizes the release→text window so a slow felt_latency line +// decomposes into its stages. ClipSaveMs is the pbpaste fork's own duration; it +// runs concurrently with inference, so only ClipWaitMs — how long the finish +// path actually blocked waiting for it — belongs to the serial sum. Zero fields +// are stages that didn't run (stream path, autoPaste off) and are omitted. +type LatencyBreakdown struct { + TailWaitMs float64 // configured mic tail-wait after release + MicStopMs float64 // capture device stop + callback clear + ConvertMs float64 // local path: PCM→f32 + PCM→WAV before inference + InferenceMs float64 // engine/provider time (repeated from the transcription line) + ClipSaveMs float64 // pbpaste fork, concurrent with inference — informational + ClipWaitMs float64 // block on the pbpaste fork after inference returned + PasteCopyMs float64 // pbcopy fork inside PasteText + PasteKeyMs float64 // Cmd+V keystroke synthesis inside PasteText +} + // ReleaseToText records the one latency the user actually feels: hotkey release // (or silence auto-close) → text delivered to the clipboard/paste. It spans the // whole tail — mic tail-wait, device stop, encode, inference, network, paste — so // it is the number to watch for "why did that feel slow", and it is emitted for // batch and streaming providers alike, unlike the per-mode metrics lines. -func ReleaseToText(ms float64) { +// unaccounted_ms is the window minus every measured serial stage; a large value +// means something unmeasured (scheduling, updatesDone) is eating time. +func ReleaseToText(ms float64, b LatencyBreakdown) { if !logReady.Load() { return } - diagLog.Info().Float64("release_to_text_ms", ms).Msg("felt_latency") + serial := b.TailWaitMs + b.MicStopMs + b.ConvertMs + b.InferenceMs + + b.ClipWaitMs + b.PasteCopyMs + b.PasteKeyMs + ev := diagLog.Info().Float64("release_to_text_ms", ms) + for _, f := range []struct { + key string + val float64 + }{ + {"tail_wait_ms", b.TailWaitMs}, + {"mic_stop_ms", b.MicStopMs}, + {"convert_ms", b.ConvertMs}, + {"inference_ms", b.InferenceMs}, + {"clip_save_ms", b.ClipSaveMs}, + {"clip_wait_ms", b.ClipWaitMs}, + {"paste_copy_ms", b.PasteCopyMs}, + {"paste_key_ms", b.PasteKeyMs}, + } { + if f.val > 0 { + ev = ev.Float64(f.key, f.val) + } + } + ev.Float64("unaccounted_ms", ms-serial).Msg("felt_latency") } func TranscriptionText(text string) { diff --git a/main.go b/main.go index 8673d21..ad27be3 100644 --- a/main.go +++ b/main.go @@ -109,6 +109,15 @@ type recordingConfig struct { tailWait time.Duration // mic kept open after release so a fast keyup doesn't clip the last word pressToRecordMs float64 // press→mic-live, filled at record start; logged with the transcription metrics releasedAt time.Time // recording end, filled once it happens; start of the felt-latency metric + micStopMs float64 // capture stop duration, filled after the record loop ends +} + +// clipSave carries the saved clipboard content plus how long the pbpaste fork +// took, so the felt-latency breakdown can separate the fork's cost from how +// long the finish path actually waited on it. +type clipSave struct { + prev string + saveMs float64 } var configMu sync.Mutex @@ -1156,9 +1165,15 @@ func handleRecording(capture audio.CaptureDevice, sess recSession) (<-chan struc // kernel clones the page tables (~0.5s with a local model loaded), which // delays keyup delivery and misreads a quick tap as a hold. Saved lazily // instead: at the first streamed paste, or once recording has ended. - clipCh := make(chan string, 1) + clipCh := make(chan clipSave, 1) var clipOnce sync.Once - saveClip := func() { clipOnce.Do(func() { clipCh <- clip.SaveCurrent() }) } + saveClip := func() { + clipOnce.Do(func() { + t := time.Now() + prev := clip.SaveCurrent() + clipCh <- clipSave{prev: prev, saveMs: float64(time.Since(t).Microseconds()) / 1000} + }) + } updatesDone := make(chan struct{}) go func() { @@ -1191,6 +1206,7 @@ func handleRecording(capture audio.CaptureDevice, sess recSession) (<-chan struc } rec.Wait() cfg.releasedAt = rec.ReleasedAt() + cfg.micStopMs = rec.micStopMs if rec.totalFrames < uint64(encoder.SampleRate/10) { tSess.Close() @@ -1209,13 +1225,18 @@ func handleRecording(capture audio.CaptureDevice, sess recSession) (<-chan struc return done, nil } -func finishTranscription(sess transcriber.Session, clipCh chan string, updatesDone <-chan struct{}, skipPaste bool, recDur time.Duration, cfg recordingConfig) { +func finishTranscription(sess transcriber.Session, clipCh chan clipSave, updatesDone <-chan struct{}, skipPaste bool, recDur time.Duration, cfg recordingConfig) { result, closeErr := sess.Close() <-updatesDone var clipPrev string + var lat log.LatencyBreakdown if cfg.autoPaste { - clipPrev = <-clipCh + t := time.Now() + cs := <-clipCh + clipPrev = cs.prev + lat.ClipSaveMs = cs.saveMs + lat.ClipWaitMs = float64(time.Since(t).Microseconds()) / 1000 } if closeErr != nil { @@ -1244,7 +1265,7 @@ func finishTranscription(sess transcriber.Session, clipCh chan string, updatesDo } if closeErr == nil && !cfg.stream && result.HasText && cfg.autoPaste && !skipPaste { - clip.PasteText(result.Text) + lat.PasteCopyMs, lat.PasteKeyMs = clip.PasteText(result.Text) } // The text is delivered by here on both paths — streamed pastes were joined @@ -1252,7 +1273,13 @@ func finishTranscription(sess transcriber.Session, clipCh chan string, updatesDo // the wait the user perceives, whether it ended in a paste or in text they // still have to hit Cmd+V for. if closeErr == nil && result.HasText && !cfg.releasedAt.IsZero() { - log.ReleaseToText(float64(time.Since(cfg.releasedAt).Microseconds()) / 1000) + lat.TailWaitMs = float64(cfg.tailWait.Milliseconds()) + lat.MicStopMs = cfg.micStopMs + if result.Batch != nil { + lat.ConvertMs = result.Batch.ConvertMs + lat.InferenceMs = result.Batch.InferenceMs + } + log.ReleaseToText(float64(time.Since(cfg.releasedAt).Microseconds())/1000, lat) } if cfg.autoPaste && !skipPaste { diff --git a/recording.go b/recording.go index 784a83b..387a4f8 100644 --- a/recording.go +++ b/recording.go @@ -29,6 +29,8 @@ type recordingSession struct { mon *silenceMonitor tailWait time.Duration // mic stays open this long after release (anti-clip) + micStopMs float64 // capture.Stop()+ClearCallback duration; written by Wait, read after it returns + mu sync.Mutex totalFrames uint64 meterLevel float32 @@ -361,8 +363,10 @@ func (r *recordingSession) ReleasedAt() time.Time { func (r *recordingSession) Wait() { <-r.done + stopStart := time.Now() r.capture.Stop() r.capture.ClearCallback() + r.micStopMs = float64(time.Since(stopStart).Microseconds()) / 1000 r.mu.Lock() r.stopped = true diff --git a/transcriber/local_session.go b/transcriber/local_session.go index 3da22a8..cc6a048 100644 --- a/transcriber/local_session.go +++ b/transcriber/local_session.go @@ -37,6 +37,7 @@ func (s *localSession) Close() (SessionResult, error) { raw := s.pcm s.mu.Unlock() + convStart := time.Now() f32 := audio.PCMToF32(raw) n := len(f32) if n == 0 { @@ -44,6 +45,7 @@ func (s *localSession) Close() (SessionResult, error) { } audioData := audio.PCMToWAV(raw) + convertMs := float64(time.Since(convStart).Microseconds()) / 1000 start := time.Now() text, err := s.engine.Transcribe(f32, s.lang, s.hints) @@ -67,6 +69,7 @@ func (s *localSession) Close() (SessionResult, error) { AudioLengthS: audioSec, RawSizeKB: rawKB, InferenceMs: inferenceMs, + ConvertMs: convertMs, TotalTimeMs: inferenceMs, }, Metrics: []string{ diff --git a/transcriber/session.go b/transcriber/session.go index ad3b150..8eaa0c6 100644 --- a/transcriber/session.go +++ b/transcriber/session.go @@ -38,6 +38,7 @@ type BatchStats struct { TLSProtocol string Confidence float64 InferenceMs float64 + ConvertMs float64 // local path: PCM→f32 + PCM→WAV conversion before inference } type StreamStats struct {