Handy/src-tauri/src/managers/transcription.rs
CJ Pais 18536aa81e
Add file based debug logging (#347)
* add basic logging to handy

* 100kb of logs

* add open button to the ui for logs

* use log everywhere

* some minor cleanup

* finish debug logging
2025-11-17 12:55:24 +07:00

438 lines
16 KiB
Rust

use crate::audio_toolkit::apply_custom_words;
use crate::managers::model::{EngineType, ModelManager};
use crate::settings::{get_settings, ModelUnloadTimeout};
use anyhow::Result;
use log::{debug, error, info, warn};
use serde::Serialize;
use std::sync::atomic::{AtomicBool, AtomicU64, Ordering};
use std::sync::{Arc, Condvar, Mutex};
use std::thread;
use std::time::{Duration, SystemTime};
use tauri::{AppHandle, Emitter};
use transcribe_rs::{
engines::{
parakeet::{
ParakeetEngine, ParakeetInferenceParams, ParakeetModelParams, TimestampGranularity,
},
whisper::{WhisperEngine, WhisperInferenceParams},
},
TranscriptionEngine,
};
#[derive(Clone, Debug, Serialize)]
pub struct ModelStateEvent {
pub event_type: String,
pub model_id: Option<String>,
pub model_name: Option<String>,
pub error: Option<String>,
}
enum LoadedEngine {
Whisper(WhisperEngine),
Parakeet(ParakeetEngine),
}
#[derive(Clone)]
pub struct TranscriptionManager {
engine: Arc<Mutex<Option<LoadedEngine>>>,
model_manager: Arc<ModelManager>,
app_handle: AppHandle,
current_model_id: Arc<Mutex<Option<String>>>,
last_activity: Arc<AtomicU64>,
shutdown_signal: Arc<AtomicBool>,
watcher_handle: Arc<Mutex<Option<thread::JoinHandle<()>>>>,
is_loading: Arc<Mutex<bool>>,
loading_condvar: Arc<Condvar>,
}
impl TranscriptionManager {
pub fn new(app_handle: &AppHandle, model_manager: Arc<ModelManager>) -> Result<Self> {
let manager = Self {
engine: Arc::new(Mutex::new(None)),
model_manager,
app_handle: app_handle.clone(),
current_model_id: Arc::new(Mutex::new(None)),
last_activity: Arc::new(AtomicU64::new(
SystemTime::now()
.duration_since(SystemTime::UNIX_EPOCH)
.unwrap()
.as_millis() as u64,
)),
shutdown_signal: Arc::new(AtomicBool::new(false)),
watcher_handle: Arc::new(Mutex::new(None)),
is_loading: Arc::new(Mutex::new(false)),
loading_condvar: Arc::new(Condvar::new()),
};
// Start the idle watcher
{
let app_handle_cloned = app_handle.clone();
let manager_cloned = manager.clone();
let shutdown_signal = manager.shutdown_signal.clone();
let handle = thread::spawn(move || {
while !shutdown_signal.load(Ordering::Relaxed) {
thread::sleep(Duration::from_secs(10)); // Check every 10 seconds
// Check shutdown signal again after sleep
if shutdown_signal.load(Ordering::Relaxed) {
break;
}
let settings = get_settings(&app_handle_cloned);
let timeout_seconds = settings.model_unload_timeout.to_seconds();
if let Some(limit_seconds) = timeout_seconds {
// Skip polling-based unloading for immediate timeout since it's handled directly in transcribe()
if settings.model_unload_timeout == ModelUnloadTimeout::Immediately {
continue;
}
let last = manager_cloned.last_activity.load(Ordering::Relaxed);
let now_ms = SystemTime::now()
.duration_since(SystemTime::UNIX_EPOCH)
.unwrap()
.as_millis() as u64;
if now_ms.saturating_sub(last) > limit_seconds * 1000 {
// idle -> unload
if manager_cloned.is_model_loaded() {
let unload_start = std::time::Instant::now();
debug!("Starting to unload model due to inactivity");
if let Ok(()) = manager_cloned.unload_model() {
let _ = app_handle_cloned.emit(
"model-state-changed",
ModelStateEvent {
event_type: "unloaded".to_string(),
model_id: None,
model_name: None,
error: None,
},
);
let unload_duration = unload_start.elapsed();
debug!(
"Model unloaded due to inactivity (took {}ms)",
unload_duration.as_millis()
);
}
}
}
}
}
debug!("Idle watcher thread shutting down gracefully");
});
*manager.watcher_handle.lock().unwrap() = Some(handle);
}
Ok(manager)
}
pub fn is_model_loaded(&self) -> bool {
let engine = self.engine.lock().unwrap();
engine.is_some()
}
pub fn unload_model(&self) -> Result<()> {
let unload_start = std::time::Instant::now();
debug!("Starting to unload model");
{
let mut engine = self.engine.lock().unwrap();
if let Some(ref mut loaded_engine) = *engine {
match loaded_engine {
LoadedEngine::Whisper(ref mut whisper) => whisper.unload_model(),
LoadedEngine::Parakeet(ref mut parakeet) => parakeet.unload_model(),
}
}
*engine = None; // Drop the engine to free memory
}
{
let mut current_model = self.current_model_id.lock().unwrap();
*current_model = None;
}
// Emit unloaded event
let _ = self.app_handle.emit(
"model-state-changed",
ModelStateEvent {
event_type: "unloaded".to_string(),
model_id: None,
model_name: None,
error: None,
},
);
let unload_duration = unload_start.elapsed();
debug!(
"Model unloaded manually (took {}ms)",
unload_duration.as_millis()
);
Ok(())
}
pub fn load_model(&self, model_id: &str) -> Result<()> {
let load_start = std::time::Instant::now();
debug!("Starting to load model: {}", model_id);
// Emit loading started event
let _ = self.app_handle.emit(
"model-state-changed",
ModelStateEvent {
event_type: "loading_started".to_string(),
model_id: Some(model_id.to_string()),
model_name: None,
error: None,
},
);
let model_info = self
.model_manager
.get_model_info(model_id)
.ok_or_else(|| anyhow::anyhow!("Model not found: {}", model_id))?;
if !model_info.is_downloaded {
let error_msg = "Model not downloaded";
let _ = self.app_handle.emit(
"model-state-changed",
ModelStateEvent {
event_type: "loading_failed".to_string(),
model_id: Some(model_id.to_string()),
model_name: Some(model_info.name.clone()),
error: Some(error_msg.to_string()),
},
);
return Err(anyhow::anyhow!(error_msg));
}
let model_path = self.model_manager.get_model_path(model_id)?;
// Create appropriate engine based on model type
let loaded_engine = match model_info.engine_type {
EngineType::Whisper => {
let mut engine = WhisperEngine::new();
engine.load_model(&model_path).map_err(|e| {
let error_msg = format!("Failed to load whisper model {}: {}", model_id, e);
let _ = self.app_handle.emit(
"model-state-changed",
ModelStateEvent {
event_type: "loading_failed".to_string(),
model_id: Some(model_id.to_string()),
model_name: Some(model_info.name.clone()),
error: Some(error_msg.clone()),
},
);
anyhow::anyhow!(error_msg)
})?;
LoadedEngine::Whisper(engine)
}
EngineType::Parakeet => {
let mut engine = ParakeetEngine::new();
engine
.load_model_with_params(&model_path, ParakeetModelParams::int8())
.map_err(|e| {
let error_msg =
format!("Failed to load parakeet model {}: {}", model_id, e);
let _ = self.app_handle.emit(
"model-state-changed",
ModelStateEvent {
event_type: "loading_failed".to_string(),
model_id: Some(model_id.to_string()),
model_name: Some(model_info.name.clone()),
error: Some(error_msg.clone()),
},
);
anyhow::anyhow!(error_msg)
})?;
LoadedEngine::Parakeet(engine)
}
};
// Update the current engine and model ID
{
let mut engine = self.engine.lock().unwrap();
*engine = Some(loaded_engine);
}
{
let mut current_model = self.current_model_id.lock().unwrap();
*current_model = Some(model_id.to_string());
}
// Emit loading completed event
let _ = self.app_handle.emit(
"model-state-changed",
ModelStateEvent {
event_type: "loading_completed".to_string(),
model_id: Some(model_id.to_string()),
model_name: Some(model_info.name.clone()),
error: None,
},
);
let load_duration = load_start.elapsed();
debug!(
"Successfully loaded transcription model: {} (took {}ms)",
model_id,
load_duration.as_millis()
);
Ok(())
}
/// Kicks off the model loading in a background thread if it's not already loaded
pub fn initiate_model_load(&self) {
let mut is_loading = self.is_loading.lock().unwrap();
if *is_loading || self.is_model_loaded() {
return;
}
*is_loading = true;
let self_clone = self.clone();
thread::spawn(move || {
let settings = get_settings(&self_clone.app_handle);
if let Err(e) = self_clone.load_model(&settings.selected_model) {
error!("Failed to load model: {}", e);
}
let mut is_loading = self_clone.is_loading.lock().unwrap();
*is_loading = false;
self_clone.loading_condvar.notify_all();
});
}
pub fn get_current_model(&self) -> Option<String> {
let current_model = self.current_model_id.lock().unwrap();
current_model.clone()
}
pub fn transcribe(&self, audio: Vec<f32>) -> Result<String> {
// Update last activity timestamp
self.last_activity.store(
SystemTime::now()
.duration_since(SystemTime::UNIX_EPOCH)
.unwrap()
.as_millis() as u64,
Ordering::Relaxed,
);
let st = std::time::Instant::now();
debug!("Audio vector length: {}", audio.len());
if audio.len() == 0 {
debug!("Empty audio vector");
return Ok(String::new());
}
// Check if model is loaded, if not try to load it
{
// If the model is loading, wait for it to complete.
let mut is_loading = self.is_loading.lock().unwrap();
while *is_loading {
is_loading = self.loading_condvar.wait(is_loading).unwrap();
}
let engine_guard = self.engine.lock().unwrap();
if engine_guard.is_none() {
return Err(anyhow::anyhow!("Model is not loaded for transcription."));
}
}
// Get current settings for configuration
let settings = get_settings(&self.app_handle);
// Perform transcription with the appropriate engine
let result = {
let mut engine_guard = self.engine.lock().unwrap();
let engine = engine_guard.as_mut().ok_or_else(|| {
anyhow::anyhow!(
"Model failed to load after auto-load attempt. Please check your model settings."
)
})?;
match engine {
LoadedEngine::Whisper(whisper_engine) => {
let params = WhisperInferenceParams {
language: if settings.selected_language == "auto" {
None
} else {
Some(settings.selected_language.clone())
},
translate: settings.translate_to_english,
..Default::default()
};
whisper_engine
.transcribe_samples(audio, Some(params))
.map_err(|e| anyhow::anyhow!("Whisper transcription failed: {}", e))?
}
LoadedEngine::Parakeet(parakeet_engine) => {
let params = ParakeetInferenceParams {
timestamp_granularity: TimestampGranularity::Segment,
..Default::default()
};
parakeet_engine
.transcribe_samples(audio, Some(params))
.map_err(|e| anyhow::anyhow!("Parakeet transcription failed: {}", e))?
}
}
};
// Apply word correction if custom words are configured
let corrected_result = if !settings.custom_words.is_empty() {
apply_custom_words(
&result.text,
&settings.custom_words,
settings.word_correction_threshold,
)
} else {
result.text
};
let et = std::time::Instant::now();
let translation_note = if settings.translate_to_english {
" (translated)"
} else {
""
};
info!(
"Transcription completed in {}ms{}",
(et - st).as_millis(),
translation_note
);
let final_result = corrected_result.trim().to_string();
if final_result.is_empty() {
info!("Transcription result is empty");
} else {
info!("Transcription result: {}", final_result);
}
// Check if we should immediately unload the model after transcription
if settings.model_unload_timeout == ModelUnloadTimeout::Immediately {
info!("Immediately unloading model after transcription");
if let Err(e) = self.unload_model() {
error!("Failed to immediately unload model: {}", e);
}
}
Ok(final_result)
}
}
impl Drop for TranscriptionManager {
fn drop(&mut self) {
debug!("Shutting down TranscriptionManager");
// Signal the watcher thread to shutdown
self.shutdown_signal.store(true, Ordering::Relaxed);
// Wait for the thread to finish gracefully
if let Some(handle) = self.watcher_handle.lock().unwrap().take() {
if let Err(e) = handle.join() {
warn!("Failed to join idle watcher thread: {:?}", e);
} else {
debug!("Idle watcher thread joined successfully");
}
}
}
}