diff --git a/README.md b/README.md index 1c6a08e..4db1bf1 100644 --- a/README.md +++ b/README.md @@ -72,6 +72,12 @@ Or with pip: pip install piper-tts ``` +The `piper` executable must be located at `~/.local/bin/piper`. If installed in a different location, you can symlink it there instead: + +```bash +ln -s $(which piper) ~/.local/bin/piper +``` + Download a voice model to `~/.local/share/piper-voices/`: ```bash @@ -132,6 +138,13 @@ For unauthenticated local endpoints (e.g. Ollama): - `chatTemplateKwargs` _(optional)_ - extra keyword arguments passed to the model's chat template (e.g. `{"enable_thinking": false}` for Qwen models to disable chain-of-thought) - `retries` _(optional)_ - number of retry attempts for transient LLM failures +### Logging + +The plugin writes diagnostics through OpenCode's structured app logger. If this plugin is not working with your setup, check the OpenCode log file and, optionally, enable debug mode. See the [OpenCode Docs](https://opencode.ai/docs/troubleshooting/#logs) for details. + +Routine plugin diagnostics use `debug`; recoverable issues use `warn`; failed +child processes, API calls, or unexpected exceptions use `error`. + ### STT API transcription (optional) Instead of local `whisper-cli`, you can use an OpenAI-compatible speech-to-text diff --git a/index.js b/index.js index 48661b4..3767338 100644 --- a/index.js +++ b/index.js @@ -31,13 +31,21 @@ import os from "node:os"; import { registerSTT } from "./lib/stt.js"; import { registerTTS } from "./lib/tts.js"; import { createClient } from "./lib/llm-client.js"; +import { createLogger } from "./lib/logger.js"; -function loadPromptFile(filePath) { +function loadPromptFile(filePath, logger, name) { if (!filePath) return null; const resolved = filePath.replace(/^~(?=\/|$)/, os.homedir()); try { - return fs.readFileSync(resolved, "utf-8").trim() || null; - } catch { + const prompt = fs.readFileSync(resolved, "utf-8").trim() || null; + logger?.log( + "plugin", + prompt ? `Loaded ${name} prompt: ${resolved}` : `Ignored empty ${name} prompt: ${resolved}`, + "debug", + ); + return prompt; + } catch (err) { + logger?.log("Plugin", `Failed to load ${name} prompt ${resolved}: ${err.message}`, "warn"); return null; } } @@ -46,16 +54,18 @@ export default { id: "opencode-voice", tui: async (api, options) => { const { kv } = api; - const { complete } = createClient(options); + const logger = createLogger(api.client); + logger.log("plugin", "Initializing", "debug"); + const { complete } = createClient(options, logger); const prompts = { - stt: loadPromptFile(options?.sttPrompt), - ttsAuto: loadPromptFile(options?.ttsAutoPrompt), - ttsManual: loadPromptFile(options?.ttsManualPrompt), + stt: loadPromptFile(options?.sttPrompt, logger, "STT"), + ttsAuto: loadPromptFile(options?.ttsAutoPrompt, logger, "TTS auto"), + ttsManual: loadPromptFile(options?.ttsManualPrompt, logger, "TTS manual"), }; - const sttCommands = registerSTT(api, kv, complete, prompts, options); - const ttsCommands = registerTTS(api, kv, complete, prompts); + const sttCommands = registerSTT(api, kv, complete, prompts, options, logger); + const ttsCommands = registerTTS(api, kv, complete, prompts, logger); api.command.register(() => [...sttCommands, ...ttsCommands]); }, diff --git a/lib/llm-client.js b/lib/llm-client.js index d047c8a..f71b495 100644 --- a/lib/llm-client.js +++ b/lib/llm-client.js @@ -52,9 +52,10 @@ function wait(ms) { * Create an LLM completion function. * * @param {object} [pluginOptions] - Static config from tui.json plugin options + * @param {{ log?: (scope: string, message: string, level?: string) => void }} [logger] * @returns {{ complete: (opts: { system?: string, prompt: string, config?: object }) => Promise<{ text: string | null, error?: string }> }} */ -export function createClient(pluginOptions) { +export function createClient(pluginOptions, logger) { function getConfig() { return { endpoint: pluginOptions?.endpoint, @@ -80,8 +81,14 @@ export function createClient(pluginOptions) { */ async function complete({ system, prompt, config: overrides }) { const cfg = { ...getConfig(), ...overrides }; - if (!cfg.endpoint) return { text: null, error: "LLM endpoint not configured" }; - if (!cfg.model) return { text: null, error: "LLM model not configured" }; + if (!cfg.endpoint) { + logger?.log?.("LLM", "completion skipped: endpoint not configured", "warn"); + return { text: null, error: "LLM endpoint not configured" }; + } + if (!cfg.model) { + logger?.log?.("LLM", "completion skipped: model not configured", "warn"); + return { text: null, error: "LLM model not configured" }; + } const apiKey = cfg.apiKeyEnv ? process.env[cfg.apiKeyEnv] : null; const endpoint = cfg.endpoint.replace(/\/+$/, "") + "/chat/completions"; @@ -100,6 +107,11 @@ export function createClient(pluginOptions) { for (let attempt = 0; attempt <= cfg.retries; attempt++) { try { + logger?.log?.( + "LLM", + `Completion request attempt=${attempt + 1} model=${cfg.model} maxTokens=${cfg.maxTokens} promptChars=${prompt.length}`, + "debug", + ); const response = await fetch(endpoint, { method: "POST", headers: { @@ -110,6 +122,11 @@ export function createClient(pluginOptions) { }); if (!response.ok) { + logger?.log?.( + "LLM", + `Completion response status=${response.status}`, + shouldRetry(response.status) ? "warn" : "error", + ); if (attempt < cfg.retries && shouldRetry(response.status)) { await wait(250 * 2 ** attempt); continue; @@ -119,7 +136,12 @@ export function createClient(pluginOptions) { const data = await response.json(); const text = data?.choices?.[0]?.message?.content || null; - if (text) return { text }; + if (text) { + logger?.log?.("LLM", `Completion succeeded chars=${text.length}`, "debug"); + return { text }; + } + + logger?.log?.("LLM", "Completion returned empty content", "warn"); if (attempt < cfg.retries) { await wait(250 * 2 ** attempt); @@ -127,6 +149,7 @@ export function createClient(pluginOptions) { } return { text: null, error: "Empty LLM response" }; } catch (err) { + logger?.log?.("LLM", `Completion error attempt=${attempt + 1}: ${err.message}`, "warn"); if (attempt < cfg.retries) { await wait(250 * 2 ** attempt); continue; diff --git a/lib/logger.js b/lib/logger.js new file mode 100644 index 0000000..d7a1196 --- /dev/null +++ b/lib/logger.js @@ -0,0 +1,18 @@ +export function createLogger(client) { + async function log(scope, message, level = "debug") { + try { + await client?.app?.log?.({ + body: { + service: "opencode-voice", + level, + message, + extra: { scope }, + }, + }); + } catch { + // Logging should never interrupt voice features. + } + } + + return { log }; +} diff --git a/lib/stt.js b/lib/stt.js index 37f5026..94f508f 100644 --- a/lib/stt.js +++ b/lib/stt.js @@ -63,10 +63,11 @@ let soxStderr = ""; let recording = false; let processing = false; -function forceKillSox() { +function forceKillSox(logger) { if (soxProc) { try { process.kill(soxProc.pid, "SIGKILL"); + logger?.log("STT", `Killed sox pid=${soxProc.pid}`, "debug"); } catch {} soxProc = null; } @@ -75,10 +76,13 @@ function forceKillSox() { } catch {} } -function startRecording(kv, toast) { - if (soxProc) return; +function startRecording(kv, toast, logger) { + if (soxProc) { + logger?.log("STT", "Start recording skipped: sox already running", "debug"); + return; + } - forceKillSox(); + forceKillSox(logger); try { fs.unlinkSync(WAV_FILE); } catch {} @@ -86,6 +90,7 @@ function startRecording(kv, toast) { soxStderr = ""; const mic = kv.get("stt.mic", "") || null; const inputArgs = mic ? ["-t", "coreaudio", mic] : ["-d"]; + logger?.log("STT", `Starting recording mic=${mic || "system default"}`, "debug"); soxProc = spawn( "sox", @@ -102,6 +107,7 @@ function startRecording(kv, toast) { soxProc.on("error", (err) => { soxProc = null; + logger?.log("STT", `Recording failed: ${err.message}`, "error"); if (recording) { recording = false; toast(`Recording failed: ${err.message}`, "error"); @@ -110,6 +116,11 @@ function startRecording(kv, toast) { soxProc.on("exit", (code) => { soxProc = null; + logger?.log( + "STT", + `sox exited code=${code} stderr=${soxStderr.trim()}`, + code === 0 || code === null ? "debug" : "warn", + ); if (recording && code !== 0 && code !== null && !processing) { recording = false; const errLine = soxStderr.trim().split("\n").pop(); @@ -120,16 +131,20 @@ function startRecording(kv, toast) { recording = true; } -function stopRecording() { +function stopRecording(logger) { + logger?.log("STT", "Stopping recording", "debug"); if (soxProc) soxProc.kill("SIGINT"); } -async function waitForSoxExit(timeoutMs = 2000) { +async function waitForSoxExit(logger, timeoutMs = 2000) { const start = Date.now(); while (soxProc && Date.now() - start < timeoutMs) { await new Promise((r) => setTimeout(r, 100)); } - if (soxProc) forceKillSox(); + if (soxProc) { + logger?.log("STT", "sox did not stop before timeout", "warn"); + forceKillSox(logger); + } } function getModelName(kv) { @@ -141,17 +156,21 @@ function getModelPath(kv) { return path.join(getModelsDir(), MODELS[getModelName(kv)].file); } -function transcribe(kv) { +function transcribe(kv, logger) { const mp = getModelPath(kv); + logger?.log("STT", `Local transcription requested model=${mp}`, "debug"); if (!fs.existsSync(mp)) { + logger?.log("STT", `Whisper model missing: ${mp}`, "error"); return Promise.resolve({ error: `Model not found: ${getModelName(kv)}. Download from huggingface.co/ggerganov/whisper.cpp`, }); } if (!fs.existsSync(WAV_FILE)) { + logger?.log("STT", `Recording file missing: ${WAV_FILE}`, "error"); return Promise.resolve({ error: "No recording file - sox may have failed to capture audio" }); } if (fs.statSync(WAV_FILE).size <= 44) { + logger?.log("STT", `Recording file empty: ${WAV_FILE}`, "warn"); return Promise.resolve({ error: "Recording is empty - no audio captured" }); } @@ -161,6 +180,7 @@ function transcribe(kv) { const proc = spawn("whisper-cli", ["-m", mp, "-f", WAV_FILE, "-np", "-nt"], { stdio: ["ignore", "pipe", "pipe"], }); + logger?.log("STT", `Started whisper-cli pid=${proc.pid}`, "debug"); proc.stdout.on("data", (chunk) => { stdout += chunk.toString(); @@ -171,20 +191,24 @@ function transcribe(kv) { const timer = setTimeout(() => { proc.kill("SIGKILL"); + logger?.log("STT", "whisper-cli timed out after 60s", "error"); resolve({ error: "Transcription timed out (60s)" }); }, 60000); proc.on("error", (err) => { clearTimeout(timer); + logger?.log("STT", `whisper-cli error: ${err.message}`, "error"); resolve({ error: `Transcription failed: ${err.message}` }); }); proc.on("exit", (code) => { clearTimeout(timer); if (code !== 0) { + logger?.log("STT", `whisper-cli exited code=${code} stderr=${stderr.trim()}`, "error"); resolve({ error: stderr.trim().split("\n").pop() || `whisper-cli exited (code=${code})` }); return; } + logger?.log("STT", `Local transcription succeeded stdoutChars=${stdout.length}`, "debug"); resolve({ text: stdout .replace(/\[.*?\]/g, "") @@ -228,10 +252,11 @@ CRITICAL DOMAIN CORRECTIONS - Fix common STT homophone errors in software engine Rely heavily on context to fix words that sound similar to programming terminology.`; -async function normalizeTranscription(complete, rawText, sessionTitle, systemPrompt) { +async function normalizeTranscription(complete, rawText, sessionTitle, systemPrompt, logger) { const contextLine = sessionTitle ? ` The user is currently working on: "${sessionTitle}"` : ""; const system = `${systemPrompt}${contextLine}`; + logger?.log("STT", `Normalizing transcription chars=${rawText.length}`, "debug"); const result = await complete({ system, prompt: `Clean up this speech-to-text transcription:\n\n${rawText}`, @@ -239,7 +264,7 @@ async function normalizeTranscription(complete, rawText, sessionTitle, systemPro return result; } -async function getApiModels() { +async function getApiModels(logger) { if (!sttApiEndpoint) return []; try { const url = sttApiEndpoint.endsWith("/") @@ -250,26 +275,32 @@ async function getApiModels() { headers["Authorization"] = "Bearer " + process.env[sttApiKeyEnv]; } const resp = await fetch(url, { headers, signal: AbortSignal.timeout(5000) }); + logger?.log("STT", `Fetched STT API models status=${resp.status}`, resp.ok ? "debug" : "warn"); if (!resp.ok) return []; const data = await resp.json(); return (data.data || []) .filter((m) => m.id && /whisper/i.test(m.id)) .map((m) => ({ value: m.id, label: m.id })); - } catch { + } catch (err) { + logger?.log("STT", `Failed to fetch STT API models: ${err.message}`, "error"); return []; } } -async function transcribeApi(kv) { +async function transcribeApi(kv, logger) { if (!sttApiEndpoint || !sttApiModel) { + logger?.log("STT", "STT API transcription skipped: API not configured", "warn"); return { error: "STT API not configured" }; } const model = kv.get("stt.api.model") || sttApiModel; + logger?.log("STT", `STT API transcription requested model=${model}`, "debug"); if (!fs.existsSync(WAV_FILE)) { + logger?.log("STT", `Recording file missing: ${WAV_FILE}`, "error"); return { error: "No recording file - sox may have failed to capture audio" }; } if (fs.statSync(WAV_FILE).size <= 44) { + logger?.log("STT", `Recording file empty: ${WAV_FILE}`, "warn"); return { error: "Recording is empty - no audio captured" }; } @@ -297,6 +328,7 @@ async function transcribeApi(kv) { body: form, signal: AbortSignal.timeout(60000), }); + logger?.log("STT", `STT API response status=${resp.status}`, resp.ok ? "debug" : "error"); if (!resp.ok) { const body = await resp.text(); @@ -309,8 +341,10 @@ async function transcribeApi(kv) { } const data = await resp.json(); + logger?.log("STT", `STT API transcription succeeded chars=${data.text?.length || 0}`, "debug"); return { text: data.text?.trim() || "" }; } catch (err) { + logger?.log("STT", `STT API request failed: ${err.message}`, "error"); if (err.name === "TimeoutError" || err.name === "AbortError") { return { error: "STT API request timed out (60s)" }; } @@ -323,20 +357,31 @@ async function appendTranscription(client, text, submit) { if (submit) await client.tui.submitPrompt(); } -async function doTranscribePipeline(kv, complete, client, toast, systemPrompt, submit = false) { +async function doTranscribePipeline( + kv, + complete, + client, + toast, + systemPrompt, + submit = false, + logger, +) { processing = true; try { - stopRecording(); - await waitForSoxExit(); + logger?.log("STT", `Pipeline started submit=${submit}`, "debug"); + stopRecording(logger); + await waitForSoxExit(logger); toast("Transcribing..."); - const result = sttApiEndpoint ? await transcribeApi(kv) : await transcribe(kv); + const result = sttApiEndpoint ? await transcribeApi(kv, logger) : await transcribe(kv, logger); if (result.error) { + logger?.log("STT", `Transcription failed: ${result.error}`, "error"); toast(result.error, "error"); return; } if (!result.text) { + logger?.log("STT", "Transcription produced no text", "warn"); toast("No speech detected", "warning"); return; } @@ -348,17 +393,21 @@ async function doTranscribePipeline(kv, complete, client, toast, systemPrompt, s result.text, sessionTitle, systemPrompt, + logger, ); if (!llmResult.text) { + logger?.log("STT", `Normalization failed, using raw input: ${llmResult.error}`, "warn"); toast(`Normalization failed, using raw input: ${llmResult.error}`, "warning"); await appendTranscription(client, result.text, submit); return; } await appendTranscription(client, llmResult.text, submit); + logger?.log("STT", `Pipeline completed normalizedChars=${llmResult.text.length}`, "debug"); toast(submit ? "Transcription submitted" : "Transcription added to prompt", "success"); } catch (err) { + logger?.log("STT", `Pipeline error: ${err.message}`, "error"); toast(`STT error: ${err.message}`, "error"); } finally { processing = false; @@ -368,7 +417,7 @@ async function doTranscribePipeline(kv, complete, client, toast, systemPrompt, s // ---- Public API for TUI plugin ---- -export function registerSTT(api, kv, complete, prompts, opts) { +export function registerSTT(api, kv, complete, prompts, opts, logger) { const client = api.client; const systemPrompt = prompts?.stt || STT_SYSTEM_PROMPT; function toast(message, variant = "info") { @@ -379,6 +428,11 @@ export function registerSTT(api, kv, complete, prompts, opts) { sttApiEndpoint = opts.sttEndpoint; sttApiModel = opts.sttModel || "whisper-large-v3-turbo"; sttApiKeyEnv = opts.sttApiKeyEnv || null; + logger?.log( + "STT", + `Configured STT API endpoint=${sttApiEndpoint} model=${sttApiModel}`, + "debug", + ); } return [ @@ -397,9 +451,9 @@ export function registerSTT(api, kv, complete, prompts, opts) { } if (recording) { toast("Stopping, transcribing..."); - doTranscribePipeline(kv, complete, client, toast, systemPrompt); + doTranscribePipeline(kv, complete, client, toast, systemPrompt, false, logger); } else { - startRecording(kv, toast); + startRecording(kv, toast, logger); if (recording) toast("Recording... press again to transcribe"); } }, @@ -422,7 +476,7 @@ export function registerSTT(api, kv, complete, prompts, opts) { return; } toast("Stopping, transcribing..."); - doTranscribePipeline(kv, complete, client, toast, systemPrompt, true); + doTranscribePipeline(kv, complete, client, toast, systemPrompt, true, logger); }, }, { @@ -433,7 +487,8 @@ export function registerSTT(api, kv, complete, prompts, opts) { onSelect() { if (recording) { recording = false; - forceKillSox(); + forceKillSox(logger); + logger?.log("STT", "Recording cancelled", "debug"); toast("Recording cancelled"); } }, @@ -446,7 +501,7 @@ export function registerSTT(api, kv, complete, prompts, opts) { async onSelect() { if (sttApiEndpoint) { const current = kv.get("stt.api.model") || sttApiModel; - const apiModels = await getApiModels(); + const apiModels = await getApiModels(logger); const options = apiModels.length > 0 ? apiModels : [{ value: current, label: current }]; api.ui.dialog.replace(() => api.ui.DialogSelect({ diff --git a/lib/tts.js b/lib/tts.js index 2044daf..439bb79 100644 --- a/lib/tts.js +++ b/lib/tts.js @@ -105,7 +105,7 @@ async function getTurnAssistantText(client, api) { // ---- Public API for TUI plugin ---- -export function registerTTS(api, kv, complete, prompts) { +export function registerTTS(api, kv, complete, prompts, logger) { const client = api.client; const systemAuto = prompts?.ttsAuto || SYSTEM_AUTO; const systemManual = prompts?.ttsManual || SYSTEM_MANUAL; @@ -121,6 +121,7 @@ export function registerTTS(api, kv, complete, prompts) { } async function normalizeForSpeech(text, systemPrompt) { + logger?.log?.("TTS", `Normalizing speech chars=${text.length}`, "debug"); return complete({ system: systemPrompt, prompt: `Convert for text-to-speech:\n\n${text}`, @@ -156,16 +157,21 @@ export function registerTTS(api, kv, complete, prompts) { killProcs(); const voiceModel = getVoiceModel(); + logger?.log?.("TTS", `Speak requested chars=${line.length} voice=${voiceModel}`, "debug"); if (!fs.existsSync(PIPER_BIN)) { + logger?.log?.("TTS", `Piper binary not found at ${PIPER_BIN}`, "warn"); toast(`Piper binary not found at ${PIPER_BIN}`, "warning"); return Promise.resolve(); } if (!fs.existsSync(voiceModel)) { + logger?.log?.("TTS", `Voice model not found: ${voiceModel}`, "warn"); toast(`Voice model not found: ${voiceModel}`, "warning"); return Promise.resolve(); } return new Promise((resolve) => { + let piperStderr = ""; + let playStderr = ""; playProc = spawn( "play", [ @@ -182,11 +188,18 @@ export function registerTTS(api, kv, complete, prompts) { "-q", "-", ], - { stdio: ["pipe", "ignore", "ignore"] }, + { stdio: ["pipe", "ignore", "pipe"] }, ); piperProc = spawn(PIPER_BIN, ["-m", voiceModel, "--output_raw"], { - stdio: ["pipe", "pipe", "ignore"], + stdio: ["pipe", "pipe", "pipe"], + }); + + piperProc.stderr.on("data", (chunk) => { + piperStderr += chunk.toString(); + }); + playProc.stderr.on("data", (chunk) => { + playStderr += chunk.toString(); }); piperProc.stdout.on("data", (chunk) => { @@ -195,23 +208,33 @@ export function registerTTS(api, kv, complete, prompts) { } }); - piperProc.on("close", () => { + piperProc.on("close", (code) => { + if (code !== 0 && code !== null) { + logger?.log?.("TTS", `piper exited code=${code} stderr=${piperStderr.trim()}`, "error"); + } if (playProc?.stdin && !playProc.stdin.destroyed) { playProc.stdin.end(); } }); - playProc.on("close", () => { + playProc.on("close", (code) => { + if (code !== 0 && code !== null) { + logger?.log?.("TTS", `play exited code=${code} stderr=${playStderr.trim()}`, "error"); + } else { + logger?.log?.("TTS", "playback finished", "debug"); + } piperProc = null; playProc = null; resolve(); }); - piperProc.on("error", () => { + piperProc.on("error", (err) => { + logger?.log?.("TTS", `piper error: ${err.message}`, "error"); killProcs(); resolve(); }); - playProc.on("error", () => { + playProc.on("error", (err) => { + logger?.log?.("TTS", `play error: ${err.message}`, "error"); killProcs(); resolve(); }); @@ -264,10 +287,12 @@ export function registerTTS(api, kv, complete, prompts) { toast("Normalizing response..."); const llmResult = await normalizeForSpeech(result.text, systemAuto); if (!llmResult.text) { + logger?.log?.("TTS", `Auto normalization failed: ${llmResult.error}`, "warn"); toast(`TTS normalization failed: ${llmResult.error}`, "warning"); return; } + logger?.log?.("TTS", `Auto normalization succeeded chars=${llmResult.text.length}`, "debug"); await speakWithSessionPrefix(sessionID, llmResult.text, "Ready for your input."); }); @@ -299,10 +324,12 @@ export function registerTTS(api, kv, complete, prompts) { toast("Normalizing response..."); const llmResult = await normalizeForSpeech(result.text, systemManual); if (!llmResult.text) { + logger?.log?.("TTS", `Manual normalization failed: ${llmResult.error}`, "warn"); toast(`TTS normalization failed: ${llmResult.error}`, "warning"); return; } + logger?.log?.("TTS", `Manual normalization succeeded chars=${llmResult.text.length}`, "debug"); toast("Speaking last response"); await speak(llmResult.text); }