From 711a6ce6923b395bb1f030cfaa372c9a671336cc Mon Sep 17 00:00:00 2001 From: Adolfo Reyna Date: Mon, 9 Mar 2026 21:33:11 -0400 Subject: [PATCH] Add session logging and tuned runtime preset --- history.md | 11 ++++++ transcribe.py | 94 ++++++++++++++++++++++++++++++++++++++++++--------- 2 files changed, 89 insertions(+), 16 deletions(-) diff --git a/history.md b/history.md index 56aa0b6..0d5dbbe 100644 --- a/history.md +++ b/history.md @@ -203,3 +203,14 @@ The project now features a high-performance, Apple Silicon-optimized pipeline th - Routed post-correct and merge-decider requests through a shared Ollama caller with keep-alive support. - Added flags for warmup timeout and optional warmup skip for troubleshooting. - **Outcome:** Lower first-request latency and fewer fallback-to-rules events due to local model cold starts. + +## Phase 25: Session Logging + Tuned Live Preset +- **Goal:** Preserve reliable debugging context while locking in the best-performing live settings discovered through manual testing. +- **Approach:** + - Added session file logging hooks so finalized captions, revisions, startup state, and runtime errors can be written to a dedicated log via `--session-log-file`. + - Improved interactive terminal behavior by clearing stale draft lines cleanly and right-aligning Arabic output more consistently against terminal width. + - Recorded the current preferred live preset for English-first filtered transcription with multilingual output and local LLM post-correction: + ```bash + python3 transcribe.py --silence 100 -q -s -c -es -en -fr -ar --lang en --filter-lang --mt-max-chars 450 --mt-max-new-tokens 220 --smart-correct --post-correct --post-correct-llm --post-correct-model qwen2.5:3b-instruct --session-log-file debug_session_1.log + ``` +- **Outcome:** The project now has a repeatable "known good" runtime profile plus persistent session diagnostics for reviewing caption issues after a run. diff --git a/transcribe.py b/transcribe.py index 8d6da7c..d689cb0 100644 --- a/transcribe.py +++ b/transcribe.py @@ -2,6 +2,8 @@ import sys import time import re import os +import shutil +from datetime import datetime import requests import threading import json @@ -33,7 +35,7 @@ from silero_vad import load_silero_vad, get_speech_timestamps from transformers import MarianMTModel, MarianTokenizer # Parameters -WHISPER_MODEL = "mlx-community/whisper-small-mlx" +WHISPER_MODEL = "mlx-community/whisper-base-mlx" INGEST_URL = "https://emiapi.reynafamily.com/live-captions/ingest" # Translation models (English -> Target) @@ -50,6 +52,16 @@ VAD_THRESHOLD = 0.5 audio_queue = queue.Queue() ingest_queue = queue.Queue() +session_log_handle = None + +def log_session(message): + """Write a timestamped line to the session debug log if enabled.""" + global session_log_handle + if session_log_handle is None: + return + ts = datetime.now().strftime("%Y-%m-%d %H:%M:%S") + session_log_handle.write(f"{ts} {message}\n") + session_log_handle.flush() def parse_temperature_fallback(value): """Parse comma-separated temperatures into a tuple of floats.""" @@ -299,16 +311,21 @@ def call_ollama_generate(args, prompt, timeout, temperature=0.1): def post_correct_with_local_llm(text, args, llm_state, context_lines=None): """Optionally rewrite finalized English caption via a local Ollama model.""" - if not args.post_correct_llm or not llm_state.get("available", True): + if args.post_correct_debug: + print(f"[POST-LLM][PRE]: {text}", flush=True) + if not args.post_correct_llm: + if args.post_correct_debug: + print("[POST-LLM][SKIP]: --post-correct-llm not enabled; using rules-only.", flush=True) + return text + if not llm_state.get("available", True): + if args.post_correct_debug: + print("[POST-LLM][SKIP]: LLM marked unavailable after prior failure; using rules-only.", flush=True) return text context_lines = context_lines or [] prev2 = context_lines[-2] if len(context_lines) >= 2 else "" prev1 = context_lines[-1] if len(context_lines) >= 1 else "" - if args.post_correct_debug: - print(f"[POST-LLM][PRE]: {text}") - prompt = ( "You are a real-time English caption corrector for live speech.\n" "Task:\n" @@ -333,27 +350,27 @@ def post_correct_with_local_llm(text, args, llm_state, context_lines=None): raw = response.json().get("response", "").strip() cleaned = normalize_english_caption(raw) if args.post_correct_debug: - print(f"[POST-LLM][RAW]: {raw}") + print(f"[POST-LLM][RAW]: {raw}", flush=True) if cleaned: overlap = word_overlap_ratio(text, cleaned) if overlap < args.post_correct_min_overlap: if args.post_correct_debug: print( f"[POST-LLM][REJECT]: low overlap ({overlap:.2f} < {args.post_correct_min_overlap:.2f}); keeping pre text" - ) + , flush=True) return text if args.post_correct_debug: - print(f"[POST-LLM][POST]: {cleaned}") + print(f"[POST-LLM][POST]: {cleaned}", flush=True) return cleaned if args.post_correct_debug: - print("[POST-LLM][POST]: ") + print("[POST-LLM][POST]: ", flush=True) except Exception as exc: if not llm_state.get("warned", False): print(f"\n[SYSTEM]: Local post-correct LLM unavailable ({exc}). Falling back to rules-only.") llm_state["warned"] = True llm_state["available"] = False if args.post_correct_debug: - print(f"[POST-LLM][ERROR]: {exc}") + print(f"[POST-LLM][ERROR]: {exc}", flush=True) return text def maybe_merge_recent_caption(recent_en_lines, current_text, now_ts, window_sec): @@ -447,8 +464,11 @@ def format_caption_lines(lang_key, text): key = lang_key.lower() if key == "ar": cleaned = normalize_arabic_punctuation(text) - # Put label on separate line and force RTL embedding for the content line. - return ["[AR]:", f"\u202B{cleaned}\u202C"] + # Put label on separate line, right-align content, and force RTL embedding. + term_width = shutil.get_terminal_size(fallback=(100, 20)).columns + visible_len = len(cleaned) + left_pad = max(0, term_width - visible_len) + return ["[AR]:", f"{' ' * left_pad}\u202B{cleaned}\u202C"] return [f"[{lang_key.upper()}]: {text}"] def print_caption(lang_key, text, leading_newline=False): @@ -457,6 +477,7 @@ def print_caption(lang_key, text, leading_newline=False): lines[0] = "\n" + lines[0] for line in lines: print(line) + log_session(line.strip()) def is_hallucination(text): """Detect common Whisper hallucinations or high repetition.""" @@ -534,7 +555,7 @@ def warmup_ollama_model(args): print(f"[SYSTEM]: Ollama warmup failed ({exc}). Continuing; runtime fallback will apply.") def main(): - global WHISPER_MODEL + global WHISPER_MODEL, session_log_handle parser = argparse.ArgumentParser(description="Live transcription and translation with Whisper.") parser.add_argument("-es", action="store_true", help="Enable Spanish translation") parser.add_argument("-en", action="store_true", help="Enable English (detected or bridged)") @@ -587,35 +608,57 @@ def main(): parser.add_argument("--speaker-sim-threshold", type=float, default=0.72, help="Cosine similarity threshold below which a speaker change is assumed (default: 0.72)") parser.add_argument("--speaker-min-buffer", type=float, default=1.6, help="Minimum buffered speech seconds before speaker-change checks (default: 1.6)") parser.add_argument("--speaker-check-interval", type=float, default=0.6, help="Seconds between speaker-change checks while buffering (default: 0.6)") + parser.add_argument("--session-log-file", type=str, default="transcribe_session.log", help="Path to session debug log file (default: transcribe_session.log)") + parser.add_argument("--disable-session-log", action="store_true", help="Disable writing session debug logs to file") args = parser.parse_args() + if not args.disable_session_log: + session_log_handle = open(args.session_log_file, "a", encoding="utf-8") + log_session("=" * 72) + log_session("SESSION_START") + log_session(f"ARGS {json.dumps(vars(args), sort_keys=True)}") + print(f"Session logging to: {args.session_log_file}") if args.post_correct_llm and not args.post_correct: args.post_correct = True print("[SYSTEM]: Enabling --post-correct because --post-correct-llm was requested.") + log_session("[SYSTEM]: Enabling --post-correct because --post-correct-llm was requested.") file_glossary_pairs = load_glossary_file(args.glossary_file) merged_glossary_pairs = file_glossary_pairs + args.glossary_pair if file_glossary_pairs: print(f"Loaded {len(file_glossary_pairs)} glossary terms from {args.glossary_file}") + log_session(f"Loaded {len(file_glossary_pairs)} glossary terms from {args.glossary_file}") if args.post_correct: print("Post-correct mode: rules enabled.") + log_session("Post-correct mode: rules enabled.") if args.post_correct_llm: print( f"Post-correct LLM: {args.post_correct_model} via {args.post_correct_ollama_url} " f"(keep_alive={args.post_correct_keep_alive})" ) + log_session( + f"Post-correct LLM: {args.post_correct_model} via {args.post_correct_ollama_url} " + f"(keep_alive={args.post_correct_keep_alive})" + ) if args.post_correct_debug: print("Post-correct debug logging enabled.") + log_session("Post-correct debug logging enabled.") if args.llm_merge_decider and not args.post_correct_llm: print("[SYSTEM]: --llm-merge-decider requires --post-correct-llm. Falling back to heuristic merge.") args.llm_merge_decider = False + log_session("[SYSTEM]: --llm-merge-decider requires --post-correct-llm. Falling back to heuristic merge.") if args.speaker_change_detect: print( "Speaker-change detection enabled " f"(threshold={args.speaker_sim_threshold}, min_buffer={args.speaker_min_buffer}s)." ) + log_session( + "Speaker-change detection enabled " + f"(threshold={args.speaker_sim_threshold}, min_buffer={args.speaker_min_buffer}s)." + ) if args.quantize: WHISPER_MODEL = "mlx-community/whisper-small-mlx-4bit" + log_session("Using quantized Whisper model variant.") if args.list_devices: print("\nAvailable Audio Devices:") @@ -625,6 +668,7 @@ def main(): buffer_limit = SAMPLERATE * args.max_buffer device = "mps" if torch.backends.mps.is_available() else "cpu" print(f"Using device: {device}") + log_session(f"Using device: {device}") # Only start ingest thread if enabled if args.ingest: @@ -688,6 +732,7 @@ def main(): print("Using system default input device.") print(f"\nStarting live transcription{' & server ingest' if args.ingest else ''}... (Press Ctrl+C to stop)") + log_session(f"Starting live transcription (ingest={args.ingest}).") audio_buffer = [] speech_started = False @@ -696,6 +741,7 @@ def main(): rolling_context = "" rolling_context_en = "" last_draft_text = "" + draft_line_active = False recent_en_lines = deque(maxlen=2) llm_post_correct_state = {"available": True, "warned": False, "merge_warned": False} speaker_reference_signature = None @@ -781,6 +827,7 @@ def main(): if args.stream: sys.stdout.write("\r\033[K") sys.stdout.flush() + draft_line_active = False # Prepare transcription kwargs transcribe_kwargs = {"path_or_hf_repo": WHISPER_MODEL} @@ -901,6 +948,7 @@ def main(): if merge_ok: english_for_caption = merge_text print(f"[EN-REV]: {old_line} -> {english_for_caption}") + log_session(f"[EN-REV]: {old_line} -> {english_for_caption}") else: if recent_en_lines: recent_en_lines[-1]["text"] = old_line @@ -912,6 +960,7 @@ def main(): if args.en and english_for_caption: payload["en"] = english_for_caption print(f"[EN]: {english_for_caption}") + log_session(f"[EN]: {english_for_caption}") # Update rolling context for next segment if args.context: @@ -959,6 +1008,7 @@ def main(): stuck_draft_count = 0 last_draft_text = "" speaker_reference_signature = None + draft_line_active = False elif args.stream and (time.time() - last_stream_time) > 1.0: # Draft transcription @@ -981,13 +1031,17 @@ def main(): if draft_text != last_draft_text: last_change_time = time.time() last_draft_text = draft_text - - sys.stdout.write(f"\r\033[K[DRAFT]: {draft_text}") - sys.stdout.flush() + if not draft_line_active: + # Reserve one blank line before the rolling draft line. + sys.stdout.write("\n") + draft_line_active = True + sys.stdout.write(f"\r\033[K[DRAFT]: {draft_text}") + sys.stdout.flush() # Send draft to ingest if enabled if args.ingest: ingest_queue.put({"draft": draft_text}) + log_session("[DRAFT]: queued draft ingest payload") else: # If Whisper returns empty, check if we've been silent for too long # even though VAD says there is speech. @@ -1003,6 +1057,7 @@ def main(): last_draft_text = "" sys.stdout.write("\r\033[K") sys.stdout.flush() + draft_line_active = False continue last_stream_time = time.time() @@ -1013,8 +1068,15 @@ def main(): except KeyboardInterrupt: print("\nStopped by user.") + log_session("Stopped by user.") except Exception as e: print(f"\nError: {e}") + log_session(f"Error: {e}") + finally: + if session_log_handle is not None: + log_session("SESSION_END") + session_log_handle.close() + session_log_handle = None if __name__ == "__main__": import multiprocessing