diff --git a/Sources/HeardCore/AppModel.swift b/Sources/HeardCore/AppModel.swift index c0ec364..3f528ce 100644 --- a/Sources/HeardCore/AppModel.swift +++ b/Sources/HeardCore/AppModel.swift @@ -50,6 +50,10 @@ public final class AppModel: ObservableObject { public static func bootstrap() -> AppModel { try? FileManager.default.ensureHeardDirectories() + let version = Bundle.main.infoDictionary?["CFBundleShortVersionString"] as? String ?? "?" + DebugFileLog.log("=== bootstrap — Heard v\(version) starting ===") + DebugFileLog.startMainThreadHeartbeat() + let settingsStore = SettingsStore() let speakerStore = SpeakerStore() let queueStore = PipelineQueueStore() @@ -309,14 +313,25 @@ public var filteredSpeakers: [SpeakerProfile] { // MARK: - Dictation public func toggleDictation() { + DebugFileLog.log("toggleDictation entered — isDictating=\(isDictating) inFlight=\(dictationToggleInFlight) activeSession=\(recordingManager.activeSession != nil)") // Drop rapid presses while a start/stop is already in progress. - guard !dictationToggleInFlight else { return } + guard !dictationToggleInFlight else { + DebugFileLog.log("toggleDictation dropped — inFlight=true") + return + } // Don't start dictation while a meeting is being recorded. - if !isDictating && recordingManager.activeSession != nil { return } + if !isDictating && recordingManager.activeSession != nil { + DebugFileLog.log("toggleDictation dropped — meeting active and not currently dictating") + return + } dictationToggleInFlight = true Task { - defer { dictationToggleInFlight = false } + defer { + dictationToggleInFlight = false + DebugFileLog.log("toggleDictation task finished — inFlight cleared") + } if isDictating { + DebugFileLog.log("taking STOP branch") // Update UI immediately so the user gets instant feedback — don't // wait for mgr.finish() to return (it flushes remaining audio and // can take several seconds, keeping the HUD up and blocking further @@ -327,7 +342,9 @@ public var filteredSpeakers: [SpeakerProfile] { if settingsStore.settings.showDictationHUD { DictationHUD.shared.hide() } dictationManager.modelKeepAliveSeconds = TimeInterval(settingsStore.settings.modelKeepAlive * 60) await dictationManager.stop() + DebugFileLog.log("STOP branch completed (dictationManager.stop returned)") } else { + DebugFileLog.log("taking START branch") do { dictationAXLost = false dictationManager.customVocabulary = settingsStore.settings.customVocabulary @@ -350,10 +367,12 @@ public var filteredSpeakers: [SpeakerProfile] { // Observe partial transcript and watch for AX revocation observeDictationPartials() startAXPolling() + DebugFileLog.log("START branch completed — isDictating=true") } catch { isDictating = false dictationError = error.localizedDescription NSLog("Heard: Dictation start failed: \(error)") + DebugFileLog.log("START branch threw: \(error)") } } } diff --git a/Sources/HeardCore/DebugFileLog.swift b/Sources/HeardCore/DebugFileLog.swift new file mode 100644 index 0000000..03cb0c8 --- /dev/null +++ b/Sources/HeardCore/DebugFileLog.swift @@ -0,0 +1,62 @@ +import Foundation + +/// Append-only debug logger that writes to a known file path. Used when +/// NSLog/unified-log diagnostics aren't reaching `log stream` reliably and +/// we need a guaranteed observation channel for live debugging. +/// +/// Tail it with: +/// tail -F ~/Library/Application\ Support/Heard/dict-debug.log +public enum DebugFileLog { + private static let queue = DispatchQueue(label: "com.execsumo.heard.debuglog") + private static let formatter: DateFormatter = { + let f = DateFormatter() + f.dateFormat = "HH:mm:ss.SSS" + return f + }() + private static var heartbeatTimer: Timer? + + public static var fileURL: URL { + FileManager.default.heardAppSupportDirectory.appendingPathComponent("dict-debug.log") + } + + /// Installs a Timer on the main RunLoop that logs every second. Gaps in + /// these heartbeat lines correspond directly to main-thread stalls — if + /// you see "heartbeat tick=12" followed by "heartbeat tick=13" 8 seconds + /// later, main was unresponsive for those 8 seconds. + @MainActor + public static func startMainThreadHeartbeat() { + guard heartbeatTimer == nil else { return } + var tick = 0 + heartbeatTimer = Timer.scheduledTimer(withTimeInterval: 1.0, repeats: true) { _ in + tick += 1 + DebugFileLog.log("heartbeat tick=\(tick)") + } + if let timer = heartbeatTimer { + RunLoop.main.add(timer, forMode: .common) + } + log("heartbeat installed") + } + + public static func log(_ message: String) { + let ts = formatter.string(from: Date()) + let line = "[\(ts)] \(message)\n" + NSLog("Heard: [DICT-DBG] \(message)") + queue.async { + let url = fileURL + let data = Data(line.utf8) + if FileManager.default.fileExists(atPath: url.path) { + if let handle = try? FileHandle(forWritingTo: url) { + defer { try? handle.close() } + _ = try? handle.seekToEnd() + try? handle.write(contentsOf: data) + } + } else { + try? FileManager.default.createDirectory( + at: url.deletingLastPathComponent(), + withIntermediateDirectories: true + ) + try? data.write(to: url) + } + } + } +} diff --git a/Sources/HeardCore/DictationHUD.swift b/Sources/HeardCore/DictationHUD.swift index b2f39cc..ad4307f 100644 --- a/Sources/HeardCore/DictationHUD.swift +++ b/Sources/HeardCore/DictationHUD.swift @@ -18,10 +18,12 @@ public final class DictationHUD { private static let fadeDelay: TimeInterval = 2.5 public func show() { + let panelExisted = panel != nil if panel == nil { buildPanel() } fadeTimer?.invalidate() panel?.alphaValue = Self.activeAlpha panel?.orderFront(nil) + DebugFileLog.log("HUD.show — panelExisted=\(panelExisted) isVisible=\(panel?.isVisible ?? false) alpha=\(panel?.alphaValue ?? -1)") // Dim after a delay — stays visible but unobtrusive while recording fadeTimer = Timer.scheduledTimer(withTimeInterval: Self.fadeDelay, repeats: false) { [weak self] _ in Task { @MainActor [weak self] in @@ -31,6 +33,7 @@ public final class DictationHUD { } public func hide() { + DebugFileLog.log("HUD.hide entry — panel=\(panel != nil) isVisible=\(panel?.isVisible ?? false) alpha=\(panel?.alphaValue ?? -1)") fadeTimer?.invalidate() fadeTimer = nil // Hide synchronously — the user just asked for stop, they want the @@ -38,6 +41,7 @@ public final class DictationHUD { // hiccups can leave the HUD stuck visible even after stop fully runs. panel?.alphaValue = 0 panel?.orderOut(nil) + DebugFileLog.log("HUD.hide done — isVisible=\(panel?.isVisible ?? false)") } private func animateAlpha(to target: CGFloat, duration: TimeInterval, completion: (@Sendable () -> Void)? = nil) { diff --git a/Sources/HeardCore/DictationManager.swift b/Sources/HeardCore/DictationManager.swift index 8dd67cf..7cfccb1 100644 --- a/Sources/HeardCore/DictationManager.swift +++ b/Sources/HeardCore/DictationManager.swift @@ -80,13 +80,19 @@ public final class DictationManager: ObservableObject { // MARK: - Public API public func start() async throws { - guard state == .idle else { throw DictationError.notIdle(current: state) } + DebugFileLog.log("DictationManager.start entry — state=\(state.rawValue) asrLoaded=\(asrManager != nil) inputUID=\(inputDeviceUID ?? "default")") + guard state == .idle else { + DebugFileLog.log("DictationManager.start refused — not idle (state=\(state.rawValue))") + throw DictationError.notIdle(current: state) + } // Surface mic-permission denial up front rather than letting the user // stare at a silently-failing HUD — without mic access, AVAudioEngine // starts but no tap callbacks fire. let micStatus = AVCaptureDevice.authorizationStatus(for: .audio) + DebugFileLog.log("DictationManager.start mic auth status=\(micStatus.rawValue)") if micStatus == .denied || micStatus == .restricted { + DebugFileLog.log("DictationManager.start throwing microphoneDenied") throw DictationError.microphoneDenied } @@ -99,6 +105,7 @@ public final class DictationManager: ObservableObject { // can start immediately instead of paying a cold-start cost while the // user waits for text to appear. try await ensureAsrManagerLoaded() + DebugFileLog.log("DictationManager.start ASR loaded ok") // Apply custom formatting commands TextNormalizer.shared.clearRules() @@ -111,18 +118,25 @@ public final class DictationManager: ObservableObject { try startMicCapture() state = .listening + DebugFileLog.log("DictationManager.start success — state=listening") } public func stop() async { - guard state == .listening else { return } + DebugFileLog.log("DictationManager.stop entry — state=\(state.rawValue) bufferCount=\(bufferCount) sampleCount=\(audioBuffer.count)") + guard state == .listening else { + DebugFileLog.log("DictationManager.stop refused — not listening (state=\(state.rawValue))") + return + } // Drain mic — see drainAndStopMicCapture for why awaiting matters. await drainAndStopMicCapture() + DebugFileLog.log("DictationManager.stop drain complete — sampleCount=\(audioBuffer.count)") state = .transcribing defer { state = .idle scheduleModelUnload() + DebugFileLog.log("DictationManager.stop exit — back to idle") } // Snapshot and clear the buffer so a fast next-start doesn't see @@ -134,23 +148,35 @@ public final class DictationManager: ObservableObject { let minSamples = 16_000 guard samples.count >= minSamples else { NSLog("Heard: Dictation audio too short to transcribe (%d samples)", samples.count) + DebugFileLog.log("DictationManager.stop short audio — sampleCount=\(samples.count) < \(minSamples)") return } - guard let mgr = asrManager else { return } + guard let mgr = asrManager else { + DebugFileLog.log("DictationManager.stop no asrManager — skipping transcription") + return + } do { var decoderState = TdtDecoderState.make() + DebugFileLog.log("DictationManager.stop calling transcribe — samples=\(samples.count)") let result = try await mgr.transcribe( samples, decoderState: &decoderState, language: .english ) + DebugFileLog.log("DictationManager.stop transcribe returned — rawText=\"\(result.text)\" (len=\(result.text.count))") let boosted = await rescoreWithVocabulary(result: result, samples: samples) let normalized = TextNormalizer.shared.normalize(result: boosted).text let trimmed = normalized.trimmingCharacters(in: .whitespacesAndNewlines) - guard !trimmed.isEmpty else { return } + DebugFileLog.log("DictationManager.stop final text=\"\(trimmed)\" (len=\(trimmed.count))") + guard !trimmed.isEmpty else { + DebugFileLog.log("DictationManager.stop empty after normalize — skipping inject") + return + } + DebugFileLog.log("DictationManager.stop firing onUtterance") onUtterance?(trimmed) } catch { NSLog("Heard: Dictation transcription failed: %@", error.localizedDescription) + DebugFileLog.log("DictationManager.stop transcribe threw: \(error)") } } @@ -260,6 +286,7 @@ public final class DictationManager: ObservableObject { // MARK: - Mic Capture private func startMicCapture() throws { + DebugFileLog.log("startMicCapture entry — requestedUID=\(inputDeviceUID ?? "default")") let engine = AVAudioEngine() let applied = AudioInputDevices.apply(uid: inputDeviceUID, to: engine) let inputNode = engine.inputNode @@ -271,6 +298,7 @@ public final class DictationManager: ObservableObject { hwFormat.channelCount, applied ? (inputDeviceUID ?? "default") : "default" ) + DebugFileLog.log("startMicCapture mic format — sr=\(hwFormat.sampleRate) ch=\(hwFormat.channelCount) deviceApplied=\(applied)") // Buffers from the tap callback are only valid for the duration of the // callback (AVAudioEngine reuses the underlying memory), so we @@ -302,7 +330,13 @@ public final class DictationManager: ObservableObject { } engine.prepare() - try engine.start() + do { + try engine.start() + DebugFileLog.log("startMicCapture engine.start ok — running=\(engine.isRunning)") + } catch { + DebugFileLog.log("startMicCapture engine.start threw: \(error)") + throw error + } micEngine = engine } @@ -311,8 +345,10 @@ public final class DictationManager: ObservableObject { bufferCount += 1 if bufferCount == 1 { NSLog("Heard: Dictation received first mic buffer") + DebugFileLog.log("appendSamples first buffer received — samples=\(samples.count)") } else if bufferCount % 60 == 0 { NSLog("Heard: Dictation buffers streamed=%d totalSamples=%d", bufferCount, audioBuffer.count) + DebugFileLog.log("appendSamples buffers=\(bufferCount) totalSamples=\(audioBuffer.count)") } } diff --git a/Sources/HeardCore/HotkeyManager.swift b/Sources/HeardCore/HotkeyManager.swift index abd1e67..4c8bda0 100644 --- a/Sources/HeardCore/HotkeyManager.swift +++ b/Sources/HeardCore/HotkeyManager.swift @@ -228,10 +228,12 @@ public final class HotkeyManager { } func handleHotkeyPressed() { + DebugFileLog.log("handleHotkeyPressed id=\(id)") onPressed?() } func handleHotkeyReleased() { + DebugFileLog.log("handleHotkeyReleased id=\(id)") onReleased?() } diff --git a/Sources/HeardCore/TextInjector.swift b/Sources/HeardCore/TextInjector.swift index f9f6749..e78a01c 100644 --- a/Sources/HeardCore/TextInjector.swift +++ b/Sources/HeardCore/TextInjector.swift @@ -4,9 +4,6 @@ import Foundation /// Injects text into the focused text field of any app using CGEvent unicode insertion. public enum TextInjector { - /// Maximum UTF-16 units per CGEvent (macOS limit). - private static let cgEventUnicodeLimit = 20 - /// Check and prompt for Accessibility permission (needed for text injection). /// Call this when enabling dictation so the user gets the prompt early. @discardableResult @@ -20,107 +17,30 @@ public enum TextInjector { return true } - /// Above this length, prefer clipboard paste over per-character CGEvent - /// unicode insertion. Rich-text apps (Notes, Word, Pages, modern web - /// editors) frequently drop events when they arrive in a rapid burst of - /// 12+ small chunks, so the "succeeded" CGEvents silently never show up. - /// Clipboard paste is a single Cmd+V — much more reliable for paragraphs. - private static let clipboardPasteThreshold = 50 - - /// Inject text into the currently focused app. + /// Inject text into the currently focused app via clipboard paste. + /// + /// We previously had a "short text < 50 chars uses CGEvent unicode insertion" + /// fast path to avoid touching the clipboard, but observed it dropping events + /// silently for short transcripts in Code/Electron apps even at 1–2 chunks. + /// CGEvent.postToPid returned success and the events never landed. Clipboard + /// paste is one Cmd+V regardless of length and works reliably; the original + /// pasteboard contents are restored after a short delay. public static func inject(_ text: String) { - guard AXIsProcessTrusted() else { + let trusted = AXIsProcessTrusted() + DebugFileLog.log("TextInjector.inject text=\"\(text)\" (len=\(text.count)) axTrusted=\(trusted)") + guard trusted else { NSLog("Heard: TextInjector cannot inject text — Accessibility not granted") return } - // Get the frontmost app's PID - guard let frontApp = NSWorkspace.shared.frontmostApplication else { return } - let pid = frontApp.processIdentifier - - // Long text → clipboard paste (reliable, one Cmd+V instead of dozens of - // chunked unicode events that rich-text editors drop). - if text.count >= clipboardPasteThreshold { - insertViaClipboard(text) - return + if let frontApp = NSWorkspace.shared.frontmostApplication { + DebugFileLog.log("TextInjector injecting into frontApp=\(frontApp.localizedName ?? "?") pid=\(frontApp.processIdentifier)") } - // Short text → CGEvent unicode insertion (fast, no clipboard side effect). - if insertTextBulk(text, targetPID: pid) { - return - } - - // Fallback: try HID tap (no PID targeting) - if insertTextBulkHID(text) { - return - } - - // Last resort: clipboard paste insertViaClipboard(text) } - // MARK: - CGEvent Unicode Insertion - - /// Send text as unicode keyboard events to a specific PID. - private static func insertTextBulk(_ text: String, targetPID: pid_t) -> Bool { - let utf16Array = Array(text.utf16) - - // Split into chunks if needed - var offset = 0 - while offset < utf16Array.count { - let end = min(offset + cgEventUnicodeLimit, utf16Array.count) - let chunk = Array(utf16Array[offset.. Bool { - let utf16Array = Array(text.utf16) - - var offset = 0 - while offset < utf16Array.count { - let end = min(offset + cgEventUnicodeLimit, utf16Array.count) - let chunk = Array(utf16Array[offset..