From ea9dbf87725c55a7681a7936c5b88d63e9c2283a Mon Sep 17 00:00:00 2001 From: buenosairesam Date: Fri, 10 Apr 2026 18:29:58 -0300 Subject: [PATCH] proper tests --- .gitignore | 2 + cht/app.py | 21 +- cht/stream/lifecycle.py | 9 +- cht/stream/manager.py | 14 +- cht/stream/processor.py | 20 + cht/window.py | 4 +- ctrl/bench.py | 372 ++++++++++++++++++ ctrl/bench_delay.py | 164 ++++++++ ctrl/client.sh | 25 ++ ctrl/e2e_test.sh | 116 ++++++ ctrl/gen_test_video.py | 148 +++++++ ctrl/sender.sh | 8 - ctrl/server.sh | 8 + logs/client.log | 142 +++++++ .../fixtures/test_scene_30s_ground_truth.json | 38 ++ tests/fixtures/test_speech.ogg | 1 + 16 files changed, 1077 insertions(+), 15 deletions(-) create mode 100644 ctrl/bench.py create mode 100644 ctrl/bench_delay.py create mode 100755 ctrl/client.sh create mode 100755 ctrl/e2e_test.sh create mode 100755 ctrl/gen_test_video.py delete mode 100755 ctrl/sender.sh create mode 100755 ctrl/server.sh create mode 100644 tests/fixtures/test_scene_30s_ground_truth.json create mode 100644 tests/fixtures/test_speech.ogg diff --git a/.gitignore b/.gitignore index ad1af65..34296e7 100644 --- a/.gitignore +++ b/.gitignore @@ -7,3 +7,5 @@ __pycache__/ .pytest_cache/ media/target/ media/logs/ +tests/fixtures/*.mp4 +tests/fixtures/*.wav diff --git a/cht/app.py b/cht/app.py index cee2e43..b7ce822 100644 --- a/cht/app.py +++ b/cht/app.py @@ -1,3 +1,4 @@ +import argparse import logging import os import signal @@ -55,6 +56,11 @@ class ChtApp(Adw.Application): win = ChtWindow(application=self) win.present() + # Auto-connect for E2E testing: --auto-connect + # Delay gives the GUI time to fully render before starting the stream. + if os.environ.get("_CHT_AUTO_CONNECT") == "1" and not win._lifecycle.is_streaming: + GLib.timeout_add(2000, lambda: win._on_connect_clicked(None) or False) + _STDERR_SKIP = [b"eglExportDMABUFImage"] @@ -89,6 +95,16 @@ def _filter_stderr(): def main(): + parser = argparse.ArgumentParser(description="CHT — Stream Viewer + Agent") + parser.add_argument("--auto-connect", action="store_true", help="Connect on startup") + parser.add_argument("--python", action="store_true", help="Use Python transport (default)") + parser.add_argument("--rust", action="store_true", help="Use Rust transport") + args, gtk_args = parser.parse_known_args() + + # Store parsed options so do_activate can read them + os.environ["_CHT_AUTO_CONNECT"] = "1" if args.auto_connect else "0" + os.environ["_CHT_RUST_TRANSPORT"] = "1" if args.rust else "0" + _filter_stderr() logging.basicConfig( level=logging.DEBUG, @@ -96,9 +112,10 @@ def main(): datefmt="%H:%M:%S", ) log = logging.getLogger("cht") - log.info("CHT starting") + log.info("CHT starting (transport=%s, auto_connect=%s)", + "rust" if args.rust else "python", args.auto_connect) app = ChtApp() - return app.run(sys.argv) + return app.run([sys.argv[0]] + gtk_args) if __name__ == "__main__": diff --git a/cht/stream/lifecycle.py b/cht/stream/lifecycle.py index 4571533..51e4ba5 100644 --- a/cht/stream/lifecycle.py +++ b/cht/stream/lifecycle.py @@ -1,6 +1,7 @@ """Stream lifecycle — manages recording, scene detection, audio extraction, and transcription buffering.""" import logging +import time from threading import Thread from gi.repository import GLib @@ -66,6 +67,7 @@ class StreamLifecycle: """ self._streaming = True self._gone_live = False + self._start_monotonic = time.monotonic() self._rust_transport = rust_transport if rust_transport: @@ -177,13 +179,16 @@ class StreamLifecycle: GLib.idle_add(self._go_live_once) if self._stream_mgr: self._stream_mgr.capture_now(on_new_frames=self._handle_new_scene_frames) - if self._stream_mgr: - self._stream_mgr.capture_now(on_new_frames=self._handle_new_scene_frames) def _go_live_once(self): if self._stream_mgr: + elapsed = time.monotonic() - self._start_monotonic log.info("Going LIVE (startup delay elapsed)") self._timeline.go_live() + if self._stream_mgr.telemetry: + self._stream_mgr.telemetry.metric("first_live", { + "elapsed_s": round(elapsed, 2), + }) return False def _tick_live(self): diff --git a/cht/stream/manager.py b/cht/stream/manager.py index d871a80..3daecfe 100644 --- a/cht/stream/manager.py +++ b/cht/stream/manager.py @@ -58,7 +58,7 @@ class StreamManager: self.agent_dir = self.session_dir / "agent" self.readonly = False - self.telemetry = None + self._telemetry = None self.recorder = StreamRecorder(self.session_dir) self.processor = SessionProcessor(self.session_dir) @@ -88,7 +88,7 @@ class StreamManager: mgr.audio_dir = session_dir / "audio" mgr.agent_dir = session_dir / "agent" mgr.readonly = False - mgr.telemetry = None + mgr._telemetry = None # No recorder — Rust server owns transport + recording. mgr.recorder = None @@ -121,6 +121,16 @@ class StreamManager: session_id, len(mgr.recorder.recording_segments), mgr.frame_count) return mgr + @property + def telemetry(self): + return self._telemetry + + @telemetry.setter + def telemetry(self, val): + self._telemetry = val + if self.processor: + self.processor._telemetry = val + # -- Recorder delegation -- @property diff --git a/cht/stream/processor.py b/cht/stream/processor.py index 4c49e1a..e40c8b0 100644 --- a/cht/stream/processor.py +++ b/cht/stream/processor.py @@ -51,6 +51,7 @@ class SessionProcessor: self._get_recording_path = None self._get_current_global_offset = None + self._telemetry = None def attach(self, get_recording_path, get_current_global_offset): """Wire up callbacks to query the recorder's current state.""" @@ -75,6 +76,11 @@ class SessionProcessor: self._append_frame_index(entry) log.info("Scene frame: %s at %.1fs", frame_id, global_ts) + if self._telemetry: + self._telemetry.metric("scene_frame", { + "id": frame_id, "global_ts": global_ts, + }) + if self._on_new_frames: self._on_new_frames([entry]) @@ -465,6 +471,15 @@ class SessionProcessor: if safe_duration is None or safe_duration <= 0: continue + # Raw AAC files (from Rust server) have no reliable duration metadata. + # ffprobe wildly overestimates (e.g. 1569s for a 50s session). + # Cap to wall-clock elapsed time as a sanity bound. + wall_elapsed = self._wall_clock_offset() + if wall_elapsed > 0 and safe_duration > wall_elapsed * 1.5: + log.debug("Audio: capping probed duration %.1fs to wall-clock %.1fs", + safe_duration, wall_elapsed) + safe_duration = wall_elapsed + # Fail-safe: processed_time can accumulate past the file if the # source was recreated (e.g. server restarted same session). if processed_time > safe_duration: @@ -495,6 +510,11 @@ class SessionProcessor: global_start = processed_time + offset log.info("Audio chunk: %s (%.1fs → %.1fs, global %.1fs)", wav_path.name, processed_time, process_to, global_start) + if self._telemetry: + self._telemetry.metric("audio_chunk", { + "chunk": chunk_num, "start": processed_time, + "end": process_to, "global_start": global_start, + }) if self._on_new_audio: try: self._on_new_audio( diff --git a/cht/window.py b/cht/window.py index c4aa514..2f2518b 100644 --- a/cht/window.py +++ b/cht/window.py @@ -1,6 +1,7 @@ """Main application window — wires Timeline to all components.""" import logging +import os from pathlib import Path import gi @@ -301,7 +302,8 @@ class ChtWindow(Adw.ApplicationWindow): self._connect_btn.remove_css_class("suggested-action") self._connect_btn.add_css_class("destructive-action") - mgr = self._lifecycle.start(session_id=session_id, rust_transport=True) + rust = os.environ.get("_CHT_RUST_TRANSPORT", "0") == "1" + mgr = self._lifecycle.start(session_id=session_id, rust_transport=rust) if mgr is None: log.error("Failed to start stream — no cht-server session found") self._connect_btn.set_label("Connect") diff --git a/ctrl/bench.py b/ctrl/bench.py new file mode 100644 index 0000000..aa0d4c0 --- /dev/null +++ b/ctrl/bench.py @@ -0,0 +1,372 @@ +#!/usr/bin/env python3 +"""Post-hoc session benchmark — extract timing metrics from session logs. + +Usage: + python ctrl/bench.py --session data/sessions/20260410_160441 + python ctrl/bench.py --latest # pick most recent session + python ctrl/bench.py --latest --json # machine-readable output + +Parses telemetry.jsonl, session.log, frames/index.json, and (if present) +media/logs/server.log. No live session required — works on finished sessions. + +Metrics: + M1 Full startup Connect → first transcript + M1a → first duration update + M1b → first scene frame + M1c → first audio chunk + M1d → first transcript + M5 Audio lag How far audio extraction trails real-time + M6 Transcript lag Time from audio ready to transcript done + M7 Frame throughput Scene frames per minute + M9 Recorder health Unexpected restarts / segment rotations +""" + +import argparse +import json +import logging +import re +import sys +from datetime import datetime +from pathlib import Path + +log = logging.getLogger("bench") + +PROJECT_DIR = Path(__file__).resolve().parent.parent +DATA_DIR = PROJECT_DIR / "data" +SESSIONS_DIR = DATA_DIR / "sessions" + + +def parse_log_time(line: str) -> float | None: + """Parse HH:MM:SS from session.log line → seconds since midnight.""" + m = re.match(r"(\d{2}):(\d{2}):(\d{2})", line) + if m: + return int(m[1]) * 3600 + int(m[2]) * 60 + int(m[3]) + return None + + +def load_telemetry(session_dir: Path) -> list[dict]: + path = session_dir / "telemetry.jsonl" + if not path.exists(): + return [] + entries = [] + for line in path.read_text().splitlines(): + if line.strip(): + try: + entries.append(json.loads(line)) + except json.JSONDecodeError: + pass + return entries + + +def load_session_log(session_dir: Path) -> list[str]: + path = session_dir / "session.log" + return path.read_text().splitlines() if path.exists() else [] + + +def load_frames_index(session_dir: Path) -> list[dict]: + path = session_dir / "frames" / "index.json" + if not path.exists(): + return [] + try: + return json.loads(path.read_text()) + except (json.JSONDecodeError, ValueError): + return [] + + +def find_first_line(lines: list[str], pattern: str) -> tuple[float | None, str | None]: + """Find first line matching pattern. Returns (time_seconds, full_line).""" + for line in lines: + if pattern in line: + return parse_log_time(line), line + return None, None + + +def extract_metrics(session_dir: Path) -> dict: + tel = load_telemetry(session_dir) + log_lines = load_session_log(session_dir) + frames = load_frames_index(session_dir) + + metrics = {} + + # Session start time (from telemetry t=0 wall clock, or first log line) + session_start_t = None + for entry in tel: + if entry.get("name") == "session_start": + session_start_t = parse_log_time(log_lines[0]) if log_lines else None + break + + # Session end + session_duration = None + for entry in tel: + if entry.get("name") == "session_end": + session_duration = entry.get("t") + metrics["session_duration_s"] = session_duration + + # M1a: start → first duration update + t_start = session_start_t + t_duration, _ = find_first_line(log_lines, "Duration:") + if t_start is not None and t_duration is not None: + metrics["M1a_first_duration_s"] = t_duration - t_start + + # M1b: start → first scene frame + t_frame, _ = find_first_line(log_lines, "Scene frame:") + if t_start is not None and t_frame is not None: + metrics["M1b_first_scene_frame_s"] = t_frame - t_start + + # M1c: start → first audio chunk + t_audio, _ = find_first_line(log_lines, "Audio chunk:") + if t_start is not None and t_audio is not None: + metrics["M1c_first_audio_chunk_s"] = t_audio - t_start + + # M1d: start → first transcript (whisper processing) + t_transcript, _ = find_first_line(log_lines, "faster_whisper: Processing audio") + if t_start is not None and t_transcript is not None: + metrics["M1d_first_transcript_s"] = t_transcript - t_start + + # M1: full startup = start → first transcript + if "M1d_first_transcript_s" in metrics: + metrics["M1_full_startup_s"] = metrics["M1d_first_transcript_s"] + + # Going LIVE time + t_live, _ = find_first_line(log_lines, "Going LIVE") + if t_start is not None and t_live is not None: + metrics["going_live_s"] = t_live - t_start + + # M5: Audio extraction lag + # Parse "Audio chunk: chunk_N (Xs → Ys, global Zs)" lines + audio_lags = [] + for line in log_lines: + m = re.search(r"Audio chunk: \S+ \(([\d.]+)s → ([\d.]+)s, global ([\d.]+)s\)", line) + if m: + end_time = float(m[2]) + log_t = parse_log_time(line) + if log_t is not None and t_start is not None: + wall_elapsed = log_t - t_start + lag = wall_elapsed - end_time + if lag >= 0: + audio_lags.append(lag) + if audio_lags: + metrics["M5_audio_lag_avg_s"] = round(sum(audio_lags) / len(audio_lags), 1) + metrics["M5_audio_lag_max_s"] = round(max(audio_lags), 1) + metrics["M5_audio_lag_min_s"] = round(min(audio_lags), 1) + metrics["M5_audio_chunk_count"] = len(audio_lags) + + # M6: Transcription lag + # Parse faster_whisper "Processing audio with duration MM:SS.mmm" or "HH:MM:SS.mmm" + transcript_durations = [] + for line in log_lines: + # MM:SS.mmm format (e.g., 00:06.145) + m = re.search(r"faster_whisper: Processing audio with duration (\d+):([\d.]+)$", line) + if m: + dur = int(m[1]) * 60 + float(m[2]) + transcript_durations.append(dur) + continue + # HH:MM:SS.mmm format + m = re.search(r"faster_whisper: Processing audio with duration (\d+):(\d+):([\d.]+)", line) + if m: + dur = int(m[1]) * 3600 + int(m[2]) * 60 + float(m[3]) + transcript_durations.append(dur) + if transcript_durations: + metrics["M6_whisper_processing_avg_s"] = round(sum(transcript_durations) / len(transcript_durations), 1) + metrics["M6_transcript_count"] = len(transcript_durations) + + # M7: Frame throughput + if frames and session_duration and session_duration > 0: + minutes = session_duration / 60 + metrics["M7_frame_throughput_per_min"] = round(len(frames) / minutes, 1) + metrics["M7_total_frames"] = len(frames) + + # M9: Recorder health + restarts = sum(1 for l in log_lines if "Recorder died" in l) + segments = sum(1 for l in log_lines if "Restarting recorder" in l) + metrics["M9_recorder_restarts"] = restarts + metrics["M9_segment_rotations"] = segments + + # Scene detection mode + if any("Scene detector: connecting" in l for l in log_lines): + metrics["scene_mode"] = "rust_relay" + elif any("Recorder+scene: pid=" in l for l in log_lines): + metrics["scene_mode"] = "python_single_process" + else: + metrics["scene_mode"] = "unknown" + + # Transport mode — check for Rust-specific markers + if any("Rust session dir" in l or "Attached to Rust session" in l for l in log_lines): + metrics["transport"] = "rust" + elif any("Recorder+scene: pid=" in l for l in log_lines): + metrics["transport"] = "python" + else: + # Check file signatures: Rust writes audio.aac separately, Python muxes into fMP4 + aac = session_dir / "stream" / "audio.aac" + if aac.exists(): + metrics["transport"] = "rust" + elif any("run_async:" in l for l in log_lines): + metrics["transport"] = "python" + else: + metrics["transport"] = "unknown" + + # Scene mode from log markers + if metrics.get("scene_mode") == "unknown": + if any("Recorder+scene: pid=" in l for l in log_lines): + metrics["scene_mode"] = "python_single_process" + elif any("run_async:" in l for l in log_lines): + metrics["scene_mode"] = "python_single_process" + + return metrics + + +def print_report(session_dir: Path, metrics: dict): + log.info("=" * 60) + log.info(" CHT Benchmark Report") + log.info(" Session: %s", session_dir.name) + log.info(" Transport: %s", metrics.get("transport", "?")) + log.info(" Scene mode: %s", metrics.get("scene_mode", "?")) + log.info(" Duration: %ss", metrics.get("session_duration_s", "?")) + log.info("=" * 60) + + rows = [ + ("M1", "Full startup", "M1_full_startup_s", "s"), + ("M1a", " → first duration", "M1a_first_duration_s", "s"), + ("M1b", " → first scene frame", "M1b_first_scene_frame_s", "s"), + ("M1c", " → first audio chunk", "M1c_first_audio_chunk_s", "s"), + ("M1d", " → first transcript", "M1d_first_transcript_s", "s"), + ("", " → going live", "going_live_s", "s"), + ("M5", "Audio lag (avg)", "M5_audio_lag_avg_s", "s"), + ("M5", "Audio lag (max)", "M5_audio_lag_max_s", "s"), + ("M5", "Audio chunks", "M5_audio_chunk_count", ""), + ("M6", "Whisper processing (avg)", "M6_whisper_processing_avg_s", "s"), + ("M6", "Transcripts produced", "M6_transcript_count", ""), + ("M7", "Frame throughput", "M7_frame_throughput_per_min", "/min"), + ("M7", "Total frames", "M7_total_frames", ""), + ("M9", "Recorder restarts", "M9_recorder_restarts", ""), + ("M9", "Segment rotations", "M9_segment_rotations", ""), + ] + + for code, label, key, unit in rows: + val = metrics.get(key) + if val is not None: + log.info(" %4s %28s %s%s", code, label, val, unit) + else: + log.info(" %4s %28s -", code, label) + + +def compare_ground_truth(session_dir: Path, gt: dict) -> dict: + """Compare detected scene frames against ground truth scene changes.""" + frames = load_frames_index(session_dir) + gt_scenes = gt.get("scenes", []) + + if not frames or not gt_scenes: + return {"error": "no frames or no ground truth scenes"} + + detected_ts = sorted(f["timestamp"] for f in frames) + expected_ts = sorted(s["timestamp_s"] for s in gt_scenes) + + # For each expected scene change, find the closest detected frame + matches = [] + for exp_ts in expected_ts: + best = None + best_delta = float("inf") + for det_ts in detected_ts: + delta = det_ts - exp_ts + if abs(delta) < abs(best_delta): + best_delta = delta + best = det_ts + matches.append({ + "expected_s": exp_ts, + "detected_s": best, + "delta_s": round(best_delta, 3) if best is not None else None, + }) + + deltas = [m["delta_s"] for m in matches if m["delta_s"] is not None] + + return { + "expected_scenes": len(expected_ts), + "detected_frames": len(detected_ts), + "matches": matches, + "avg_delta_s": round(sum(deltas) / len(deltas), 3) if deltas else None, + "max_delta_s": round(max(abs(d) for d in deltas), 3) if deltas else None, + "missed": sum(1 for m in matches if m["delta_s"] is None or abs(m["delta_s"]) > 10), + } + + +def print_ground_truth_report(gt: dict): + log.info("") + log.info(" Scene detection vs ground truth:") + log.info(" Expected scenes: %d", gt.get("expected_scenes", 0)) + log.info(" Detected frames: %d", gt.get("detected_frames", 0)) + if gt.get("avg_delta_s") is not None: + log.info(" Avg detection delta: %ss", gt["avg_delta_s"]) + log.info(" Max detection delta: %ss", gt["max_delta_s"]) + if gt.get("missed", 0) > 0: + log.warning(" Missed scenes: %d", gt["missed"]) + for m in gt.get("matches", []): + status = "OK" if m["delta_s"] is not None and abs(m["delta_s"]) < 5 else "MISS" + det = f"{m['detected_s']:.1f}s" if m["detected_s"] is not None else "---" + delta = f"+{m['delta_s']:.1f}s" if m["delta_s"] is not None else "" + log.info(" %4s expected=%5.1fs detected=%s %s", status, m["expected_s"], det, delta) + + +def find_latest_session() -> Path | None: + if not SESSIONS_DIR.exists(): + return None + dirs = sorted(SESSIONS_DIR.iterdir(), reverse=True) + for d in dirs: + if d.is_dir() and (d / "telemetry.jsonl").exists(): + return d + return None + + +def main(): + parser = argparse.ArgumentParser(description="CHT session benchmark") + parser.add_argument("--session", type=Path, help="Path to session directory") + parser.add_argument("--latest", action="store_true", help="Use most recent session") + parser.add_argument("--json", action="store_true", help="Output JSON instead of table") + parser.add_argument("--ground-truth", type=Path, help="Ground truth JSON for scene comparison") + args = parser.parse_args() + + logging.basicConfig( + level=logging.INFO, + format="%(asctime)s %(levelname)-7s %(name)s: %(message)s", + datefmt="%H:%M:%S", + ) + + if args.latest: + session_dir = find_latest_session() + if not session_dir: + log.error("No sessions found") + sys.exit(1) + elif args.session: + session_dir = args.session + else: + parser.print_help() + sys.exit(1) + + if not session_dir.exists(): + log.error("Session not found: %s", session_dir) + sys.exit(1) + + metrics = extract_metrics(session_dir) + metrics["session_id"] = session_dir.name + + # Ground truth comparison + if args.ground_truth and args.ground_truth.exists(): + gt = json.loads(args.ground_truth.read_text()) + comparison = compare_ground_truth(session_dir, gt) + metrics["ground_truth"] = comparison + + if args.json: + sys.stdout.write(json.dumps(metrics, indent=2) + "\n") + else: + print_report(session_dir, metrics) + if "ground_truth" in metrics: + print_ground_truth_report(metrics["ground_truth"]) + + # Save report + bench_dir = DATA_DIR / "bench" + bench_dir.mkdir(parents=True, exist_ok=True) + report_path = bench_dir / f"{session_dir.name}.json" + report_path.write_text(json.dumps(metrics, indent=2)) + + +if __name__ == "__main__": + main() diff --git a/ctrl/bench_delay.py b/ctrl/bench_delay.py new file mode 100644 index 0000000..51bbce8 --- /dev/null +++ b/ctrl/bench_delay.py @@ -0,0 +1,164 @@ +#!/usr/bin/env python3 +"""Live scene detection latency benchmark (M4). + +Measures time from a triggered visual change on the sender to a new JPEG +appearing in the receiver's frames/ directory. + +Usage (run on receiver, sender accessible via SSH): + python ctrl/bench_delay.py --session-dir data/sessions/CURRENT --sender mariano@sender + python ctrl/bench_delay.py --frames-dir data/sessions/CURRENT/frames --sender mariano@sender + +How it works: +1. Records the current frame count in frames/index.json +2. SSH to sender, triggers a visual change (xdotool workspace switch) +3. Polls frames/index.json for a new entry (or watches via mtime) +4. Measures wall-clock difference = scene detection latency + +For repeated measurements, use --repeat N with --interval S between triggers. +""" + +import argparse +import json +import logging +import os +import subprocess +import sys +import time +from pathlib import Path + +log = logging.getLogger("bench_delay") + + +def get_frame_count(frames_dir: Path) -> int: + index = frames_dir / "index.json" + if not index.exists(): + return 0 + try: + return len(json.loads(index.read_text())) + except (json.JSONDecodeError, ValueError): + return 0 + + +def get_latest_frame_mtime(frames_dir: Path) -> float: + index = frames_dir / "index.json" + if not index.exists(): + return 0.0 + return index.stat().st_mtime + + +def trigger_scene_change(sender: str, method: str = "workspace") -> float: + """Trigger a visual change on the sender. Returns wall-clock time of trigger.""" + if method == "workspace": + # xdotool switch workspace — causes a full-screen visual change + cmd = ["ssh", sender, "DISPLAY=:0 xdotool key super+Right"] + elif method == "color": + # Flash a fullscreen color using xterm (more dramatic change) + cmd = ["ssh", sender, + "DISPLAY=:0 bash -c 'xterm -fullscreen -bg red -e sleep 0.5 &'"] + else: + log.error("Unknown trigger method: %s", method) + sys.exit(1) + + t = time.monotonic() + wall = time.time() + try: + subprocess.run(cmd, timeout=5, capture_output=True) + except subprocess.TimeoutExpired: + log.warning("SSH trigger timed out") + return wall + + +def wait_for_new_frame(frames_dir: Path, initial_count: int, + timeout: float = 15.0, poll_interval: float = 0.1) -> float | None: + """Wait for a new frame to appear. Returns wall-clock time when detected, or None.""" + deadline = time.monotonic() + timeout + while time.monotonic() < deadline: + count = get_frame_count(frames_dir) + if count > initial_count: + return time.time() + time.sleep(poll_interval) + return None + + +def run_measurement(frames_dir: Path, sender: str, method: str) -> dict: + initial_count = get_frame_count(frames_dir) + trigger_wall = trigger_scene_change(sender, method) + detected_wall = wait_for_new_frame(frames_dir, initial_count) + + if detected_wall is None: + return {"trigger_wall": trigger_wall, "latency_s": None, "timed_out": True} + + latency = detected_wall - trigger_wall + return { + "trigger_wall": trigger_wall, + "detected_wall": detected_wall, + "latency_s": round(latency, 3), + "timed_out": False, + } + + +def main(): + parser = argparse.ArgumentParser(description="Scene detection latency benchmark") + parser.add_argument("--frames-dir", type=Path, help="Path to frames/ directory") + parser.add_argument("--session-dir", type=Path, help="Path to session directory") + parser.add_argument("--sender", required=True, help="SSH target for sender (user@host)") + parser.add_argument("--method", default="workspace", choices=["workspace", "color"], + help="How to trigger visual change") + parser.add_argument("--repeat", type=int, default=3, help="Number of measurements") + parser.add_argument("--interval", type=float, default=5.0, help="Seconds between triggers") + parser.add_argument("--json", action="store_true", help="Output JSON") + args = parser.parse_args() + + logging.basicConfig( + level=logging.INFO, + format="%(asctime)s %(levelname)-7s %(name)s: %(message)s", + datefmt="%H:%M:%S", + ) + + if args.session_dir: + frames_dir = args.session_dir / "frames" + elif args.frames_dir: + frames_dir = args.frames_dir + else: + parser.error("Provide --frames-dir or --session-dir") + return + + if not frames_dir.exists(): + log.error("Frames dir not found: %s", frames_dir) + sys.exit(1) + + results = [] + for i in range(args.repeat): + if i > 0: + time.sleep(args.interval) + log.info("Trigger %d/%d...", i + 1, args.repeat) + r = run_measurement(frames_dir, args.sender, args.method) + if r["timed_out"]: + log.warning("TIMEOUT (no frame in 15s)") + else: + log.info(" latency: %ss", r["latency_s"]) + results.append(r) + + latencies = [r["latency_s"] for r in results if r["latency_s"] is not None] + + if args.json: + print(json.dumps({"measurements": results, "summary": { + "count": len(latencies), + "avg_s": round(sum(latencies) / len(latencies), 3) if latencies else None, + "min_s": round(min(latencies), 3) if latencies else None, + "max_s": round(max(latencies), 3) if latencies else None, + "timeouts": sum(1 for r in results if r["timed_out"]), + }}, indent=2)) + else: + log.info("M4 Scene detection latency:") + if latencies: + log.info(" avg: %.1fs", sum(latencies) / len(latencies)) + log.info(" min: %.1fs", min(latencies)) + log.info(" max: %.1fs", max(latencies)) + timeouts = sum(1 for r in results if r["timed_out"]) + if timeouts: + log.warning(" timeouts: %d/%d", timeouts, len(results)) + + +if __name__ == "__main__": + main() diff --git a/ctrl/client.sh b/ctrl/client.sh new file mode 100755 index 0000000..721bba9 --- /dev/null +++ b/ctrl/client.sh @@ -0,0 +1,25 @@ +#!/bin/bash +# Start the client (sender) — Python or Rust mode. +# +# Usage: +# ctrl/client.sh --python [RECEIVER_IP] [PORT] # kmsgrab + mpegts (default port 4444) +# ctrl/client.sh --rust [server_addr] # Rust framed protocol (default mcrndeb:4447) +# +# Default: --python +set -euo pipefail + +PROJECT_DIR="$(cd "$(dirname "$0")/.." && pwd)" +MODE="python" + +# Parse mode flag +if [[ "${1:-}" == "--python" ]]; then + MODE="python"; shift +elif [[ "${1:-}" == "--rust" ]]; then + MODE="rust"; shift +fi + +if [ "$MODE" = "rust" ]; then + exec "$PROJECT_DIR/media/ctrl/client.sh" "$@" +else + exec sudo python3 "$PROJECT_DIR/sender/stream_av.py" "$@" +fi diff --git a/ctrl/e2e_test.sh b/ctrl/e2e_test.sh new file mode 100755 index 0000000..c3a0993 --- /dev/null +++ b/ctrl/e2e_test.sh @@ -0,0 +1,116 @@ +#!/bin/bash +# E2E benchmark test — fully automated, run from the SENDER machine. +# +# Starts everything via SSH, captures test video, collects results. +# +# Usage: +# ctrl/e2e_test.sh --python [--duration 30] +# ctrl/e2e_test.sh --rust [--duration 30] +set -euo pipefail + +PROJECT_DIR="$(cd "$(dirname "$0")/.." && pwd)" +cd "$PROJECT_DIR" + +DURATION=30 +INTERVAL=5 +RECEIVER="mcrndeb" +RDIR="wdir/cht" +MODE="python" +PLAY_DELAY=3 + +while [[ $# -gt 0 ]]; do + case $1 in + --python) MODE="python"; shift ;; + --rust) MODE="rust"; shift ;; + --duration) DURATION="$2"; shift 2 ;; + --interval) INTERVAL="$2"; shift 2 ;; + --receiver) RECEIVER="$2"; shift 2 ;; + --play-delay) PLAY_DELAY="$2"; shift 2 ;; + *) echo "Unknown arg: $1"; exit 1 ;; + esac +done + +VIDEO="tests/fixtures/test_scene_${DURATION}s.mp4" +GROUND_TRUTH="tests/fixtures/test_scene_${DURATION}s_ground_truth.json" + +# Generate test video if needed +if [ ! -f "$VIDEO" ]; then + echo "=== Generating test video ===" + python3 ctrl/gen_test_video.py --duration "$DURATION" --interval "$INTERVAL" +fi + +# PIDs to clean up +PIDS=() +cleanup() { + echo "=== Cleaning up ===" + for pid in "${PIDS[@]}"; do + kill "$pid" 2>/dev/null || true + done + # Kill sudo'd client + sudo pkill -f "stream_av\|cht-client" 2>/dev/null || true + # Stop remote processes + ssh "$RECEIVER" "pkill -f 'cht-server|cht.app' 2>/dev/null" || true + wait 2>/dev/null +} +trap cleanup EXIT INT TERM + +echo "=== E2E test: $MODE mode, ${DURATION}s ===" + +# Step 1: Start receiver side (on mcrndeb via SSH) +if [ "$MODE" = "rust" ]; then + echo "--- Starting Rust server on $RECEIVER ---" + ssh -tt "$RECEIVER" "cd $RDIR && ctrl/server.sh" & + PIDS+=($!) + sleep 2 + + echo "--- Starting app on $RECEIVER (rust transport, auto-connect) ---" + ssh -tt "$RECEIVER" "cd $RDIR && CHT_AUTO_CONNECT=1 CHT_RUST_TRANSPORT=1 ctrl/app.sh" & + PIDS+=($!) + sleep 3 +else + echo "--- Starting app on $RECEIVER (python transport, auto-connect) ---" + ssh -tt "$RECEIVER" "cd $RDIR && CHT_AUTO_CONNECT=1 CHT_RUST_TRANSPORT=0 ctrl/app.sh" & + PIDS+=($!) + sleep 3 +fi + +# Step 2: Play test video fullscreen on sender +echo "--- Playing test video fullscreen ---" +mpv --fullscreen --loop-file=inf --no-terminal "$VIDEO" & +PIDS+=($!) +sleep "$PLAY_DELAY" + +# Step 3: Start client (sender) +echo "--- Starting $MODE client → $RECEIVER ---" +if [ "$MODE" = "rust" ]; then + ctrl/client.sh --rust "${RECEIVER}:4447" & +else + ctrl/client.sh --python "$RECEIVER" & +fi +PIDS+=($!) + +# Step 4: Wait for capture + processing +WAIT=$(( DURATION + 15 )) +echo "--- Waiting ${WAIT}s for capture + processing ---" +sleep "$WAIT" + +# Step 5: Stop sender side +echo "--- Stopping sender ---" +sudo pkill -f "stream_av\|cht-client" 2>/dev/null || true +kill "${PIDS[-1]}" 2>/dev/null || true # mpv +sleep 2 + +# Step 6: Stop receiver side +echo "--- Stopping receiver ---" +ssh "$RECEIVER" "pkill -f 'cht.app' 2>/dev/null" || true +sleep 2 +ssh "$RECEIVER" "pkill -f 'cht-server' 2>/dev/null" || true +sleep 1 + +# Step 7: Benchmark +echo "" +echo "=== Benchmark results ($MODE) ===" +ssh "$RECEIVER" "cd $RDIR && python3 ctrl/bench.py --latest --ground-truth $GROUND_TRUTH" + +echo "" +echo "JSON: ssh $RECEIVER 'cd $RDIR && python3 ctrl/bench.py --latest --json --ground-truth $GROUND_TRUTH'" diff --git a/ctrl/gen_test_video.py b/ctrl/gen_test_video.py new file mode 100755 index 0000000..1f2bde9 --- /dev/null +++ b/ctrl/gen_test_video.py @@ -0,0 +1,148 @@ +#!/usr/bin/env python3 +"""Generate a test video with known scene changes and audio markers. + +The video is played fullscreen on the sender while kmsgrab captures it — +simulating a meeting with deterministic, reproducible content. + +- Scene changes: solid color blocks every INTERVAL seconds +- Overlay: large elapsed-seconds counter for visual sync measurement +- Audio: sine tone (changes frequency each scene for transcription ground truth) + +Outputs: + tests/fixtures/test_scene_30s.mp4 + tests/fixtures/test_scene_30s_ground_truth.json + +Usage: + python ctrl/gen_test_video.py [--duration 30] [--interval 5] +""" + +import argparse +import json +import logging +import subprocess +import sys +from pathlib import Path + +log = logging.getLogger("gen_test_video") + +PROJECT_DIR = Path(__file__).resolve().parent.parent +FIXTURES_DIR = PROJECT_DIR / "tests" / "fixtures" + +# Scene colors (RGB hex) +COLORS = ["FF0000", "0000FF", "00FF00", "FFFF00", "FF00FF", "00FFFF"] + +# Speech sample (Harvard sentences, public domain, Open Speech Repository) +SPEECH_SAMPLE = FIXTURES_DIR / "test_speech_harvard.wav" +SPEECH_URL = "http://www.voiptroubleshooter.com/open_speech/american/OSR_us_000_0010_8k.wav" + + +def ensure_speech_sample(): + """Download speech sample if not present.""" + FIXTURES_DIR.mkdir(parents=True, exist_ok=True) + if SPEECH_SAMPLE.exists(): + return + log.info("Downloading speech sample from Open Speech Repository...") + import urllib.request + urllib.request.urlretrieve(SPEECH_URL, SPEECH_SAMPLE) + log.info("Saved: %s", SPEECH_SAMPLE) + + +def generate(duration: int, interval: int): + FIXTURES_DIR.mkdir(parents=True, exist_ok=True) + ensure_speech_sample() + + video_path = FIXTURES_DIR / f"test_scene_{duration}s.mp4" + truth_path = FIXTURES_DIR / f"test_scene_{duration}s_ground_truth.json" + + num_scenes = duration // interval + nc = len(COLORS) + + # Video: colored segments with timer overlay, concatenated. + # Audio: speech sample looped to fill duration (real speech for whisper testing). + filter_parts = [] + for i in range(num_scenes): + color = COLORS[i % nc] + seg_dur = interval if (i + 1) * interval <= duration else duration - i * interval + offset = i * interval + filter_parts.append( + f"color=c=0x{color}:s=1920x1080:d={seg_dur}:r=30," + f"drawtext=text='%{{eif\\:t+{offset}\\:d}}s':" + f"fontsize=200:fontcolor=white:x=(w-text_w)/2:y=(h-text_h)/2:" + f"borderw=6:bordercolor=black" + f"[v{i}]" + ) + + v_inputs = "".join(f"[v{i}]" for i in range(num_scenes)) + filter_parts.append(f"{v_inputs}concat=n={num_scenes}:v=1:a=0[vout]") + # Audio: speech sample is input 1 (input 0 is the lavfi dummy) + filter_parts.append( + f"[1:a]aresample=48000,aloop=loop=-1:size=48000*{duration}," + f"atrim=0:{duration},volume=0.8[aout]" + ) + + filter_complex = ";\n".join(filter_parts) + + cmd = [ + "ffmpeg", "-y", + "-f", "lavfi", "-i", "anullsrc", # dummy (video segments come from filter) + *[arg for i in range(num_scenes) for arg in []], # no extra inputs needed for video + "-i", str(SPEECH_SAMPLE), # speech audio input + "-filter_complex", filter_complex, + "-map", "[vout]", "-map", "[aout]", + "-c:v", "libx264", "-preset", "ultrafast", "-crf", "18", + "-g", "30", "-keyint_min", "30", + "-c:a", "aac", "-b:a", "128k", + "-t", str(duration), + str(video_path), + "-hide_banner", "-loglevel", "warning", + ] + + log.info("Generating %ds test video (%d scenes, %ds interval, speech audio)", duration, num_scenes, interval) + log.info("Output: %s", video_path) + + result = subprocess.run(cmd, capture_output=True, text=True) + if result.returncode != 0: + log.error("ffmpeg failed:\n%s", result.stderr) + sys.exit(1) + + log.info("Video generated: %s", video_path) + + # Write ground truth + scenes = [] + for i in range(num_scenes): + scenes.append({ + "scene_index": i, + "timestamp_s": i * interval, + "color_hex": COLORS[i % nc], + }) + + truth = { + "duration_s": duration, + "interval_s": interval, + "num_scenes": num_scenes, + "video_path": str(video_path), + "scenes": scenes, + } + truth_path.write_text(json.dumps(truth, indent=2)) + log.info("Ground truth: %s", truth_path) + + return video_path, truth_path + + +def main(): + logging.basicConfig( + level=logging.INFO, + format="%(asctime)s %(levelname)-7s %(name)s: %(message)s", + datefmt="%H:%M:%S", + ) + + parser = argparse.ArgumentParser(description="Generate CHT test video") + parser.add_argument("--duration", type=int, default=30, help="Video duration in seconds") + parser.add_argument("--interval", type=int, default=5, help="Seconds between scene changes") + args = parser.parse_args() + + generate(args.duration, args.interval) + + +if __name__ == "__main__": + main() diff --git a/ctrl/sender.sh b/ctrl/sender.sh deleted file mode 100755 index 639d528..0000000 --- a/ctrl/sender.sh +++ /dev/null @@ -1,8 +0,0 @@ -#!/bin/bash -# Start the sender on this machine -# Usage: ./sender.sh RECEIVER_IP [PORT] -set -euo pipefail - -PROJECT_DIR="$(cd "$(dirname "$0")/.." && pwd)" - -exec sudo "$PROJECT_DIR/sender/stream_av.sh" "$@" diff --git a/ctrl/server.sh b/ctrl/server.sh new file mode 100755 index 0000000..c86dcd4 --- /dev/null +++ b/ctrl/server.sh @@ -0,0 +1,8 @@ +#!/bin/bash +# Start the Rust media server (receiver). +# Thin wrapper around media/ctrl/server.sh. +# Usage: ctrl/server.sh [port] +set -euo pipefail + +PROJECT_DIR="$(cd "$(dirname "$0")/.." && pwd)" +exec "$PROJECT_DIR/media/ctrl/server.sh" "$@" diff --git a/logs/client.log b/logs/client.log index 14eef89..d7ee325 100644 --- a/logs/client.log +++ b/logs/client.log @@ -222,3 +222,145 @@ 2026-04-10T19:11:10.098551Z INFO cht_client::backends::subprocess: Subprocess pipeline stopped (11607 video, 18137 audio packets) 2026-04-10T19:11:10.099048Z INFO cht_client::backends::subprocess: [ffmpeg] stderr closed 2026-04-10T19:11:10.099238Z INFO cht_client: Done — 11607 video + 18137 audio packets +2026-04-10T21:05:21.524598Z INFO cht_common::logging: Logging to /home/mariano/wdir/cht/logs/client.log +2026-04-10T21:05:21.524640Z INFO cht_client: Backend: Subprocess (default) +2026-04-10T21:05:21.524656Z INFO cht_client: Waiting for server at mcrndeb:4447... +2026-04-10T21:05:21.526428Z INFO cht_client: Connected to mcrndeb:4447 +2026-04-10T21:05:21.526579Z INFO cht_client: Sent session_start +2026-04-10T21:05:21.526736Z INFO cht_client::pipeline: Backend: Subprocess (ffmpeg CLI) +2026-04-10T21:05:21.539960Z INFO cht_client::backends::subprocess: Audio sources — monitor: Some("alsa_output.usb-TASCAM_US-122_MKII_no_serial_number-00.analog-stereo.monitor"), mic: Some("alsa_input.usb-046d_C922_Pro_Stream_Webcam_B4B595AF-02.analog-stereo") +2026-04-10T21:05:21.540031Z INFO cht_client::backends::subprocess: ffmpeg args: ["-init_hw_device", "drm=drm:/dev/dri/card0", "-init_hw_device", "vaapi=va@drm", "-thread_queue_size", "512", "-device", "/dev/dri/card0", "-f", "kmsgrab", "-framerate", "30", "-i", "-", "-f", "pulse", "-thread_queue_size", "1024", "-i", "alsa_output.usb-TASCAM_US-122_MKII_no_serial_number-00.analog-stereo.monitor", "-f", "pulse", "-thread_queue_size", "1024", "-i", "alsa_input.usb-046d_C922_Pro_Stream_Webcam_B4B595AF-02.analog-stereo", "-filter_complex", "[1:a][2:a]amix=inputs=2:duration=longest[aout]", "-map", "0:v", "-map", "[aout]", "-vf", "hwmap=derive_device=vaapi,scale_vaapi=w=1920:h=1080:format=nv12,fps=30", "-c:v", "h264_vaapi", "-qp", "20", "-g", "30", "-bf", "0", "-c:a", "aac", "-b:a", "128k", "-flush_packets", "1", "-fflags", "nobuffer", "-f", "nut", "pipe:1", "-hide_banner"] +2026-04-10T21:05:21.540335Z INFO cht_client::backends::subprocess: ffmpeg subprocess pid=285348 +2026-04-10T21:05:21.614965Z INFO cht_client::backends::subprocess: [ffmpeg] There are 2 hardware devices. device va of type vaapi is picked for filters by default. Set hardware device explicitly with the filter_hw_device option if device va is not usable for filters. +2026-04-10T21:05:21.615160Z INFO cht_client::backends::subprocess: [ffmpeg] [in#0 @ 0x5558236e7380] Using plane 57 to locate framebuffers. +2026-04-10T21:05:21.615189Z INFO cht_client::backends::subprocess: [ffmpeg] [in#0 @ 0x5558236e7380] Template framebuffer is 127: 1920x1080 format 30335258 modifier 0 flags 0. +2026-04-10T21:05:22.283496Z INFO cht_client::backends::subprocess: [ffmpeg] Input #0, kmsgrab, from 'fd:': +2026-04-10T21:05:22.283555Z INFO cht_client::backends::subprocess: [ffmpeg] Duration: N/A, start: 1775855121.615205, bitrate: N/A +2026-04-10T21:05:22.283583Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:0: Video: wrapped_avframe, drm_prime, 1920x1080, 29.92 tbr, 1000k tbn, start 1775855121.615205 +2026-04-10T21:05:22.445978Z INFO cht_client::backends::subprocess: [ffmpeg] [aist#1:0/pcm_s16le @ 0x5558236fc000] Guessed Channel Layout: stereo +2026-04-10T21:05:22.446054Z INFO cht_client::backends::subprocess: [ffmpeg] Input #1, pulse, from 'alsa_output.usb-TASCAM_US-122_MKII_no_serial_number-00.analog-stereo.monitor': +2026-04-10T21:05:22.446091Z INFO cht_client::backends::subprocess: [ffmpeg] Duration: N/A, start: 1775855122.367547, bitrate: 1536 kb/s +2026-04-10T21:05:22.446117Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #1:0: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s, start 1775855122.367547 +2026-04-10T21:05:22.725022Z INFO cht_client::backends::subprocess: [ffmpeg] [aist#2:0/pcm_s16le @ 0x555823705e40] Guessed Channel Layout: stereo +2026-04-10T21:05:22.725079Z INFO cht_client::backends::subprocess: [ffmpeg] Input #2, pulse, from 'alsa_input.usb-046d_C922_Pro_Stream_Webcam_B4B595AF-02.analog-stereo': +2026-04-10T21:05:22.725111Z INFO cht_client::backends::subprocess: [ffmpeg] Duration: N/A, start: 1775855122.611843, bitrate: 1536 kb/s +2026-04-10T21:05:22.725181Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #2:0: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s, start 1775855122.611843 +2026-04-10T21:05:22.725217Z INFO cht_client::backends::subprocess: [ffmpeg] There are 2 hardware devices. device va of type vaapi is picked for filters by default. Set hardware device explicitly with the filter_hw_device option if device va is not usable for filters. +2026-04-10T21:05:22.725705Z INFO cht_client::backends::subprocess: [ffmpeg] Stream mapping: +2026-04-10T21:05:22.725727Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #1:0 (pcm_s16le) -> amix +2026-04-10T21:05:22.725761Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #2:0 (pcm_s16le) -> amix +2026-04-10T21:05:22.725783Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:0 -> #0:0 (wrapped_avframe (native) -> h264 (h264_vaapi)) +2026-04-10T21:05:22.725806Z INFO cht_client::backends::subprocess: [ffmpeg] amix:default -> Stream #0:1 (aac) +2026-04-10T21:05:22.726159Z INFO cht_client::backends::subprocess: [ffmpeg] There are 2 hardware devices. device va of type vaapi is picked for filters by default. Set hardware device explicitly with the filter_hw_device option if device va is not usable for filters. +2026-04-10T21:05:22.758184Z INFO cht_client::backends::subprocess: [ffmpeg] Last message repeated 1 times +2026-04-10T21:05:22.758257Z INFO cht_client::backends::subprocess: [ffmpeg] Output #0, nut, to 'pipe:1': +2026-04-10T21:05:22.758283Z INFO cht_client::backends::subprocess: [ffmpeg] Metadata: +2026-04-10T21:05:22.758339Z INFO cht_client::backends::subprocess: [ffmpeg] encoder : Lavf62.12.100 +2026-04-10T21:05:22.758375Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:0: Video: h264 (High) (H264 / 0x34363248), vaapi(tv, progressive), 1920x1080, q=2-31, 30 fps, 61440 tbn +2026-04-10T21:05:22.758401Z INFO cht_client::backends::subprocess: [ffmpeg] Metadata: +2026-04-10T21:05:22.758417Z INFO cht_client::backends::subprocess: [ffmpeg] encoder : Lavc62.28.100 h264_vaapi +2026-04-10T21:05:22.758446Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:1: Audio: aac (LC) ([255][0][0][0] / 0x00FF), 48000 Hz, stereo, fltp, 128 kb/s +2026-04-10T21:05:22.758476Z INFO cht_client::backends::subprocess: [ffmpeg] Metadata: +2026-04-10T21:05:22.758500Z INFO cht_client::backends::subprocess: [ffmpeg] encoder : Lavc62.28.100 aac +2026-04-10T21:05:23.678684Z INFO cht_client::backends::subprocess: Demux: video_idx=0 tb=1/61440, audio_idx=1 tb=1/48000 +2026-04-10T21:05:23.678837Z INFO cht_client::backends::subprocess: Subprocess: 1 video, 1 audio packets +2026-04-10T21:05:23.679774Z INFO cht_client: Sent 1 video, 1 audio packets +2026-04-10T21:05:32.725968Z INFO cht_client::backends::subprocess: Subprocess: 301 video, 469 audio packets +2026-04-10T21:05:32.726155Z INFO cht_client: Sent 301 video, 469 audio packets +2026-04-10T21:05:42.713337Z INFO cht_client::backends::subprocess: Subprocess: 601 video, 937 audio packets +2026-04-10T21:05:42.713494Z INFO cht_client: Sent 601 video, 937 audio packets +2026-04-10T21:05:52.737096Z INFO cht_client::backends::subprocess: Subprocess: 901 video, 1406 audio packets +2026-04-10T21:05:52.737234Z INFO cht_client: Sent 901 video, 1406 audio packets +2026-04-10T21:06:02.721370Z INFO cht_client::backends::subprocess: Subprocess: 1201 video, 1874 audio packets +2026-04-10T21:06:02.721613Z INFO cht_client: Sent 1201 video, 1874 audio packets +2026-04-10T21:06:12.751216Z INFO cht_client::backends::subprocess: Subprocess: 1501 video, 2343 audio packets +2026-04-10T21:06:12.751377Z INFO cht_client: Sent 1501 video, 2343 audio packets +2026-04-10T21:06:22.732968Z INFO cht_client::backends::subprocess: Subprocess: 1801 video, 2811 audio packets +2026-04-10T21:06:22.733240Z INFO cht_client: Sent 1801 video, 2811 audio packets +2026-04-10T21:06:32.086693Z INFO cht_client::backends::subprocess: Stop watcher: sent SIGINT to ffmpeg pid=285348 +2026-04-10T21:06:32.130083Z INFO cht_client::backends::subprocess: Subprocess pipeline stopped (2082 video, 3252 audio packets) +2026-04-10T21:06:32.163774Z INFO cht_client::backends::subprocess: [ffmpeg] frame= 19 fps=0.0 q=-0.0 size= 1708KiB time=00:00:00.48 bitrate=28602.5kbits/s speed=0.978x elapsed=0:00:00.50 frame= 41 fps= 41 q=-0.0 size= 1716KiB time=00:00:01.02 bitrate=13681.1kbits/s speed=1.03x elapsed=0:00:01.00 frame= 63 fps= 42 q=-0.0 size= 2097KiB time=00:00:01.48 bitrate=11575.9kbits/s speed=0.989x elapsed=0:00:01.50 frame= 70 fps= 35 q=-0.0 size= 2310KiB time=00:00:01.97 bitrate=9598.3kbits/s speed=0.986x elapsed=0:00:02.00 frame= 93 fps= 37 q=-0.0 size= 2830KiB time=00:00:02.51 bitrate=9212.2kbits/s speed=1.01x elapsed=0:00:02.50 frame= 99 fps= 33 q=-0.0 size= 2838KiB time=00:00:02.96 bitrate=7846.8kbits/s speed=0.987x elapsed=0:00:03.00 frame= 123 fps= 35 q=-0.0 size= 2990KiB time=00:00:03.46 bitrate=7064.0kbits/s speed=0.991x elapsed=0:00:03.50 frame= 129 fps= 32 q=-0.0 size= 2999KiB time=00:00:03.99 bitrate=6147.9kbits/s speed=0.999x elapsed=0:00:04.00 frame= 156 fps= 35 q=-0.0 size= 3169KiB time=00:00:04.50 bitrate=5763.8kbits/s speed= 1x elapsed=0:00:04.50 frame= 158 fps= 32 q=-0.0 size= 3177KiB time=00:00:04.95 bitrate=5257.9kbits/s speed=0.99x elapsed=0:00:05.00 frame= 182 fps= 33 q=-0.0 size= 3213KiB time=00:00:05.43 bitrate=4842.5kbits/s speed=0.988x elapsed=0:00:05.50 frame= 189 fps= 31 q=-0.0 size= 3224KiB time=00:00:05.98 bitrate=4410.6kbits/s speed=0.998x elapsed=0:00:06.00 frame= 212 fps= 33 q=-0.0 size= 3266KiB time=00:00:06.49 bitrate=4117.7kbits/s speed= 1x elapsed=0:00:06.50 frame= 220 fps= 31 q=-0.0 size= 3276KiB time=00:00:06.94 bitrate=3862.2kbits/s speed=0.992x elapsed=0:00:07.00 frame= 240 fps= 32 q=-0.0 size= 3307KiB time=00:00:07.43 bitrate=3642.1kbits/s speed=0.992x elapsed=0:00:07.50 frame= 250 fps= 31 q=-0.0 size= 3327KiB time=00:00:07.99 bitrate=3408.3kbits/s speed=0.999x elapsed=0:00:08.00 frame= 271 fps= 32 q=-0.0 size= 3369KiB time=00:00:08.45 bitrate=3263.1kbits/s speed=0.995x elapsed=0:00:08.50 frame= 280 fps= 31 q=-0.0 size= 3386KiB time=00:00:08.95 bitrate=3096.4kbits/s speed=0.995x elapsed=0:00:09.00 frame= 302 fps= 32 q=-0.0 size= 3436KiB time=00:00:09.52 bitrate=2956.4kbits/s speed= 1x elapsed=0:00:09.50 frame= 309 fps= 31 q=-0.0 size= 3456KiB time=00:00:10.03 bitrate=2819.9kbits/s speed= 1x elapsed=0:00:10.00 frame= 333 fps= 32 q=-0.0 size= 3500KiB time=00:00:10.48 bitrate=2734.1kbits/s speed=0.999x elapsed=0:00:10.50 frame= 339 fps= 31 q=-0.0 size= 3520KiB time=00:00:11.02 bitrate=2615.5kbits/s speed= 1x elapsed=0:00:11.00 frame= 365 fps= 32 q=-0.0 size= 3565KiB time=00:00:11.53 bitrate=2531.5kbits/s speed= 1x elapsed=0:00:11.50 frame= 368 fps= 31 q=-0.0 size= 3584KiB time=00:00:11.98 bitrate=2449.4kbits/s speed=0.999x elapsed=0:00:12.00 frame= 396 fps= 32 q=-0.0 size= 3631KiB time=00:00:12.47 bitrate=2384.1kbits/s speed=0.998x elapsed=0:00:12.50 frame= 396 fps= 30 q=-0.0 size= 3652KiB time=00:00:13.03 bitrate=2295.8kbits/s speed= 1x elapsed=0:00:13.00 frame= 426 fps= 32 q=-0.0 size= 3699KiB time=00:00:13.54 bitrate=2237.6kbits/s speed= 1x elapsed=0:00:13.50 frame= 426 fps= 30 q=-0.0 size= 3715KiB time=00:00:13.99 bitrate=2175.0kbits/s speed=0.999x elapsed=0:00:14.00 frame= 455 fps= 31 q=-0.0 size= 3758KiB time=00:00:14.48 bitrate=2126.0kbits/s speed=0.998x elapsed=0:00:14.50 frame= 455 fps= 30 q=-0.0 size= 3776KiB time=00:00:15.03 bitrate=2057.4kbits/s speed= 1x elapsed=0:00:15.00 frame= 483 fps= 31 q=-0.0 size= 3818KiB time=00:00:15.48 bitrate=2020.1kbits/s speed=0.999x elapsed=0:00:15.50 frame= 483 fps= 30 q=-0.0 size= 3835KiB time=00:00:15.99 bitrate=1964.5kbits/s speed=0.999x elapsed=0:00:16.00 frame= 513 fps= 31 q=-0.0 size= 3880KiB time=00:00:16.52 bitrate=1923.2kbits/s speed= 1x elapsed=0:00:16.50 frame= 514 fps= 30 q=-0.0 size= 3920KiB time=00:00:17.03 bitrate=1884.8kbits/s speed= 1x elapsed=0:00:17.00 frame= 542 fps= 31 q=-0.0 size= 3939KiB time=00:00:17.48 bitrate=1845.1kbits/s speed=0.999x elapsed=0:00:17.50 frame= 548 fps= 30 q=-0.0 size= 3956KiB time=00:00:17.97 bitrate=1802.7kbits/s speed=0.999x elapsed=0:00:18.00 frame= 570 fps= 31 q=-0.0 size= 4008KiB time=00:00:18.53 bitrate=1771.9kbits/s speed= 1x elapsed=0:00:18.50 frame= 577 fps= 30 q=-0.0 size= 4025KiB time=00:00:18.97 bitrate=1737.4kbits/s speed=0.999x elapsed=0:00:19.00 frame= 600 fps= 31 q=-0.0 size= 4072KiB time=00:00:19.49 bitrate=1711.5kbits/s speed=0.999x elapsed=0:00:19.50 frame= 609 fps= 30 q=-0.0 size= 4114KiB time=00:00:20.02 bitrate=1683.0kbits/s speed= 1x elapsed=0:00:20.00 frame= 629 fps= 31 q=-0.0 size= 4137KiB time=00:00:20.53 bitrate=1650.4kbits/s speed= 1x elapsed=0:00:20.50 frame= 643 fps= 31 q=-0.0 size= 4154KiB time=00:00:20.98 bitrate=1621.6kbits/s speed=0.999x elapsed=0:00:21.00 frame= 657 fps= 31 q=-0.0 size= 4198KiB time=00:00:21.47 bitrate=1601.6kbits/s speed=0.999x elapsed=0:00:21.50 frame= 673 fps= 31 q=-0.0 size= 4217KiB time=00:00:21.98 bitrate=1571.4kbits/s speed=0.999x elapsed=0:00:22.00 frame= 687 fps= 31 q=-0.0 size= 4265KiB time=00:00:22.53 bitrate=1550.0kbits/s speed= 1x elapsed=0:00:22.50 frame= 704 fps= 31 q=-0.0 size= 4281KiB time=00:00:22.98 bitrate=1525.5kbits/s speed=0.999x elapsed=0:00:23.00 frame= 716 fps= 30 q=-0.0 size= 4331KiB time=00:00:23.52 bitrate=1508.6kbits/s speed= 1x elapsed=0:00:23.50 frame= 738 fps= 31 q=-0.0 size= 4345KiB time=00:00:23.88 bitrate=1490.3kbits/s speed=0.995x elapsed=0:00:24.00 frame= 744 fps= 30 q=-0.0 size= 4398KiB time=00:00:24.48 bitrate=1471.5kbits/s speed=0.999x elapsed=0:00:24.50 frame= 768 fps= 31 q=-0.0 size= 4421KiB time=00:00:24.97 bitrate=1450.3kbits/s speed=0.999x elapsed=0:00:25.00 frame= 774 fps= 30 q=-0.0 size= 4463KiB time=00:00:25.52 bitrate=1432.4kbits/s speed= 1x elapsed=0:00:25.50 frame= 799 fps= 31 q=-0.0 size= 4487KiB time=00:00:25.97 bitrate=1415.0kbits/s speed=0.999x elapsed=0:00:26.00 frame= 803 fps= 30 q=-0.0 size= 4530KiB time=00:00:26.48 bitrate=1401.1kbits/s speed=0.999x elapsed=0:00:26.50 frame= 832 fps= 31 q=-0.0 size= 4553KiB time=00:00:27.02 bitrate=1380.3kbits/s speed= 1x elapsed=0:00:27.00 frame= 832 fps= 30 q=-0.0 size= 4597KiB time=00:00:27.53 bitrate=1367.7kbits/s speed= 1x elapsed=0:00:27.50 frame= 861 fps= 31 q=-0.0 size= 4625KiB time=00:00:27.97 bitrate=1354.2kbits/s speed=0.999x elapsed=0:00:28.00 frame= 861 fps= 30 q=-0.0 size= 4670KiB time=00:00:28.46 bitrate=1343.9kbits/s speed=0.999x elapsed=0:00:28.50 frame= 890 fps= 31 q=-0.0 size= 4694KiB time=00:00:29.02 bitrate=1324.9kbits/s speed= 1x elapsed=0:00:29.00 frame= 890 fps= 30 q=-0.0 size= 4737KiB time=00:00:29.53 bitrate=1313.8kbits/s speed= 1x elapsed=0:00:29.50 frame= 919 fps= 31 q=-0.0 size= 4758KiB time=00:00:29.98 bitrate=1299.8kbits/s speed=0.999x elapsed=0:00:30.00 frame= 919 fps= 30 q=-0.0 size= 4804KiB time=00:00:30.47 bitrate=1291.3kbits/s speed=0.999x elapsed=0:00:30.50 frame= 948 fps= 31 q=-0.0 size= 4828KiB time=00:00:31.03 bitrate=1274.6kbits/s speed= 1x elapsed=0:00:31.00 frame= 949 fps= 30 q=-0.0 size= 4875KiB time=00:00:31.52 bitrate=1266.9kbits/s speed= 1x elapsed=0:00:31.50 frame= 977 fps= 31 q=-0.0 size= 4894KiB time=00:00:31.99 bitrate=1253.3kbits/s speed= 1x elapsed=0:00:32.00 frame= 983 fps= 30 q=-0.0 size= 4942KiB time=00:00:32.52 bitrate=1244.7kbits/s speed= 1x elapsed=0:00:32.50 frame= 1006 fps= 30 q=-0.0 size= 4969KiB time=00:00:33.03 bitrate=1232.2kbits/s speed= 1x elapsed=0:00:33.00 frame= 1009 fps= 30 q=-0.0 size= 5011KiB time=00:00:33.48 bitrate=1226.0kbits/s speed=0.999x elapsed=0:00:33.50 frame= 1036 fps= 30 q=-0.0 size= 5031KiB time=00:00:33.97 bitrate=1213.1kbits/s speed=0.999x elapsed=0:00:34.00 frame= 1041 fps= 30 q=-0.0 size= 5077KiB time=00:00:34.52 bitrate=1204.6kbits/s speed= 1x elapsed=0:00:34.50 frame= 1066 fps= 30 q=-0.0 size= 5097KiB time=00:00:35.01 bitrate=1192.3kbits/s speed= 1x elapsed=0:00:35.00 frame= 1069 fps= 30 q=-0.0 size= 5139KiB time=00:00:35.48 bitrate=1186.2kbits/s speed= 1x elapsed=0:00:35.50 frame= 1097 fps= 30 q=-0.0 size= 5161KiB time=00:00:36.02 bitrate=1173.6kbits/s speed= 1x elapsed=0:00:36.00 frame= 1102 fps= 30 q=-0.0 size= 5206KiB time=00:00:36.53 bitrate=1167.3kbits/s speed= 1x elapsed=0:00:36.50 frame= 1126 fps= 30 q=-0.0 size= 5225KiB time=00:00:36.98 bitrate=1157.3kbits/s speed=0.999x elapsed=0:00:37.00 frame= 1127 fps= 30 q=-0.0 size= 5270KiB time=00:00:37.47 bitrate=1152.0kbits/s speed=0.999x elapsed=0:00:37.50 frame= 1158 fps= 30 q=-0.0 size= 5286KiB time=00:00:38.02 bitrate=1138.8kbits/s speed= 1x elapsed=0:00:38.00 frame= 1159 fps= 30 q=-0.0 size= 5331KiB time=00:00:38.54 bitrate=1132.9kbits/s speed= 1x elapsed=0:00:38.50 frame= 1187 fps= 30 q=-0.0 size= 5369KiB time=00:00:39.00 bitrate=1127.8kbits/s speed= 1x elapsed=0:00:39.00 frame= 1193 fps= 30 q=-0.0 size= 5425KiB time=00:00:39.49 bitrate=1125.1kbits/s speed= 1x elapsed=0:00:39.50 frame= 1216 fps= 30 q=-0.0 size= 5479KiB time=00:00:40.05 bitrate=1120.5kbits/s speed= 1x elapsed=0:00:40.00 frame= 1223 fps= 30 q=-0.0 size= 5499KiB time=00:00:40.50 bitrate=1112.1kbits/s speed= 1x elapsed=0:00:40.50 frame= 1245 fps= 30 q=-0.0 size= 5522KiB time=00:00:40.99 bitrate=1103.4kbits/s speed= 1x elapsed=0:00:41.00 frame= 1257 fps= 30 q=-0.0 size= 5578KiB time=00:00:41.50 bitrate=1100.8kbits/s speed= 1x elapsed=0:00:41.50 frame= 1273 fps= 30 q=-0.0 size= 5638KiB time=00:00:42.06 bitrate=1097.9kbits/s speed= 1x elapsed=0:00:42.00 frame= 1290 fps= 30 q=-0.0 size= 5655KiB time=00:00:42.44 bitrate=1091.5kbits/s speed=0.999x elapsed=0:00:42.50 frame= 1301 fps= 30 q=-0.0 size= 5710KiB time=00:00:43.04 bitrate=1086.7kbits/s speed= 1x elapsed=0:00:43.00 frame= 1324 fps= 30 q=-0.0 size= 5728KiB time=00:00:43.45 bitrate=1079.9kbits/s speed=0.999x elapsed=0:00:43.50 frame= 1329 fps= 30 q=-0.0 size= 5775KiB time=00:00:44.04 bitrate=1074.0kbits/s speed= 1x elapsed=0:00:44.00 frame= 1353 fps= 30 q=-0.0 size= 5796KiB time=00:00:44.49 bitrate=1067.1kbits/s speed= 1x elapsed=0:00:44.50 frame= 1359 fps= 30 q=-0.0 size= 5835KiB time=00:00:45.04 bitrate=1061.1kbits/s speed= 1x elapsed=0:00:45.00 frame= 1384 fps= 30 q=-0.0 size= 5856KiB time=00:00:45.49 bitrate=1054.4kbits/s speed= 1x elapsed=0:00:45.50 frame= 1388 fps= 30 q=-0.0 size= 5873KiB time=00:00:46.00 bitrate=1045.7kbits/s speed= 1x elapsed=0:00:46.00 frame= 1417 fps= 30 q=-0.0 size= 5917KiB time=00:00:46.49 bitrate=1042.4kbits/s speed= 1x elapsed=0:00:46.50 frame= 1417 fps= 30 q=-0.0 size= 5957KiB time=00:00:47.05 bitrate=1037.1kbits/s speed= 1x elapsed=0:00:47.00 frame= 1446 fps= 30 q=-0.0 size= 5978KiB time=00:00:47.54 bitrate=1029.9kbits/s speed= 1x elapsed=0:00:47.50 frame= 1446 fps= 30 q=-0.0 size= 5994KiB time=00:00:48.01 bitrate=1022.6kbits/s speed= 1x elapsed=0:00:48.00 frame= 1474 fps= 30 q=-0.0 size= 6046KiB time=00:00:48.54 bitrate=1020.2kbits/s speed= 1x elapsed=0:00:48.50 frame= 1475 fps= 30 q=-0.0 size= 6091KiB time=00:00:49.06 bitrate=1017.0kbits/s speed= 1x elapsed=0:00:49.00 frame= 1502 fps= 30 q=-0.0 size= 6109KiB time=00:00:49.50 bitrate=1010.8kbits/s speed= 1x elapsed=0:00:49.50 frame= 1508 fps= 30 q=-0.0 size= 6127KiB time=00:00:49.99 bitrate=1003.9kbits/s speed= 1x elapsed=0:00:50.00 frame= 1530 fps= 30 q=-0.0 size= 6175KiB time=00:00:50.55 bitrate=1000.6kbits/s speed= 1x elapsed=0:00:50.50 frame= 1538 fps= 30 q=-0.0 size= 6191KiB time=00:00:51.00 bitrate= 994.4kbits/s speed= 1x elapsed=0:00:51.00 frame= 1560 fps= 30 q=-0.0 size= 6237KiB time=00:00:51.51 bitrate= 991.9kbits/s speed= 1x elapsed=0:00:51.50 frame= 1569 fps= 30 q=-0.0 size= 6282KiB time=00:00:52.04 bitrate= 988.7kbits/s speed= 1x elapsed=0:00:52.00 frame= 1589 fps= 30 q=-0.0 size= 6305KiB time=00:00:52.55 bitrate= 982.8kbits/s speed= 1x elapsed=0:00:52.50 frame= 1604 fps= 30 q=-0.0 size= 6321KiB time=00:00:53.00 bitrate= 977.0kbits/s speed= 1x elapsed=0:00:53.00 frame= 1617 fps= 30 q=-0.0 size= 6370KiB time=00:00:53.49 bitrate= 975.5kbits/s speed= 1x elapsed=0:00:53.50 frame= 1634 fps= 30 q=-0.0 size= 6421KiB time=00:00:54.04 bitrate= 973.2kbits/s speed= 1x elapsed=0:00:54.00 frame= 1647 fps= 30 q=-0.0 size= 6440KiB time=00:00:54.56 bitrate= 966.9kbits/s speed= 1x elapsed=0:00:54.50 frame= 1665 fps= 30 q=-0.0 size= 6462KiB time=00:00:55.00 bitrate= 962.2kbits/s speed= 1x elapsed=0:00:55.00 frame= 1676 fps= 30 q=-0.0 size= 6503KiB time=00:00:55.54 bitrate= 959.2kbits/s speed= 1x elapsed=0:00:55.50 frame= 1699 fps= 30 q=-0.0 size= 6553KiB time=00:00:56.05 bitrate= 957.7kbits/s speed= 1x elapsed=0:00:56.00 frame= 1705 fps= 30 q=-0.0 size= 6572KiB time=00:00:56.54 bitrate= 952.1kbits/s speed= 1x elapsed=0:00:56.50 frame= 1729 fps= 30 q=-0.0 size= 6592KiB time=00:00:56.99 bitrate= 947.5kbits/s speed= 1x elapsed=0:00:57.01 frame= 1734 fps= 30 q=-0.0 size= 6637KiB time=00:00:57.54 bitrate= 944.7kbits/s speed= 1x elapsed=0:00:57.51 frame= 1760 fps= 30 q=-0.0 size= 6692KiB time=00:00:58.06 bitrate= 944.2kbits/s speed= 1x elapsed=0:00:58.01 frame= 1763 fps= 30 q=-0.0 size= 6711KiB time=00:00:58.51 bitrate= 939.7kbits/s speed= 1x elapsed=0:00:58.51 frame= 1792 fps= 30 q=-0.0 size= 6757KiB time=00:00:59.04 bitrate= 937.5kbits/s speed= 1x elapsed=0:00:59.01 frame= 1792 fps= 30 q=-0.0 size= 6777KiB time=00:00:59.55 bitrate= 932.2kbits/s speed= 1x elapsed=0:00:59.51 frame= 1821 fps= 30 q=-0.0 size= 6823KiB time=00:01:00.04 bitrate= 930.9kbits/s speed= 1x elapsed=0:01:00.01 frame= 1821 fps= 30 q=-0.0 size= 6842KiB time=00:01:00.49 bitrate= 926.5kbits/s speed= 1x elapsed=0:01:00.51 frame= 1850 fps= 30 q=-0.0 size= 6893KiB time=00:01:01.04 bitrate= 924.9kbits/s speed= 1x elapsed=0:01:01.01 frame= 1850 fps= 30 q=-0.0 size= 6913KiB time=00:01:01.56 bitrate= 919.9kbits/s speed= 1x elapsed=0:01:01.51 frame= 1879 fps= 30 q=-0.0 size= 6932KiB time=00:01:02.00 bitrate= 915.8kbits/s speed= 1x elapsed=0:01:02.01 frame= 1879 fps= 30 q=-0.0 size= 6977KiB time=00:01:02.49 bitrate= 914.5kbits/s speed= 1x elapsed=0:01:02.51 frame= 1908 fps= 30 q=-0.0 size= 7024KiB time=00:01:03.05 bitrate= 912.6kbits/s speed= 1x elapsed=0:01:03.01 frame= 1913 fps= 30 q=-0.0 size= 7043KiB time=00:01:03.50 bitrate= 908.6kbits/s speed= 1x elapsed=0:01:03.51 frame= 1936 fps= 30 q=-0.0 size= 7072KiB time=00:01:04.01 bitrate= 905.0kbits/s speed= 1x elapsed=0:01:04.01 frame= 1945 fps= 30 q=-0.0 size= 7116KiB time=00:01:04.54 bitrate= 903.2kbits/s speed= 1x elapsed=0:01:04.51 frame= 1964 fps= 30 q=-0.0 size= 7164KiB time=00:01:05.05 bitrate= 902.0kbits/s speed= 1x elapsed=0:01:05.01 frame= 1978 fps= 30 q=-0.0 size= 7178KiB time=00:01:05.44 bitrate= 898.5kbits/s speed=0.999x elapsed=0:01:05.51 frame= 1993 fps= 30 q=-0.0 size= 7201KiB time=00:01:05.99 bitrate= 893.8kbits/s speed= 1x elapsed=0:01:06.01 frame= 2009 fps= 30 q=-0.0 size= 7252KiB time=00:01:06.55 bitrate= 892.7kbits/s speed= 1x elapsed=0:01:06.51 frame= 2022 fps= 30 q=-0.0 size= 7268KiB time=00:01:07.04 bitrate= 888.1kbits/s speed= 1x elapsed=0:01:07.01 frame= 2041 fps= 30 q=-0.0 size= 7316KiB time=00:01:07.51 bitrate= 887.8kbits/s speed= 1x elapsed=0:01:07.51 frame= 2051 fps= 30 q=-0.0 size= 7360KiB time=00:01:08.04 bitrate= 886.1kbits/s speed= 1x elapsed=0:01:08.01 frame= 2075 fps= 30 q=-0.0 size= 7367KiB time=00:01:08.34 bitrate= 883.0kbits/s speed=0.998x elapsed=0:01:08.51 frame= 2080 fps= 30 q=-0.0 size= 7408KiB time=00:01:09.04 bitrate= 878.9kbits/s speed= 1x elapsed=0:01:09.01 [aost#0:1/aac @ 0x55582370dcc0] Error submitting a packet to the muxer: Immediate exit requested +2026-04-10T21:06:32.164474Z INFO cht_client::backends::subprocess: [ffmpeg] Last message repeated 1 times +2026-04-10T21:06:32.164491Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x555823706100] Error muxing a packet +2026-04-10T21:06:32.164509Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x555823706100] Task finished with error code: -1414092869 (Immediate exit requested) +2026-04-10T21:06:32.164526Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x555823706100] Terminating thread with return code -1414092869 (Immediate exit requested) +2026-04-10T21:06:32.344303Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x555823706100] Error writing trailer: Immediate exit requested +2026-04-10T21:06:32.344355Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x555823706100] Error closing file: Immediate exit requested +2026-04-10T21:06:32.344379Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x555823706100] video:6464KiB audio:939KiB subtitle:0KiB other streams:0KiB global headers:0KiB muxing overhead: 0.199193% +2026-04-10T21:06:32.344406Z INFO cht_client::backends::subprocess: [ffmpeg] frame= 2098 fps= 30 q=-0.0 Lsize= 7417KiB time=00:01:09.47 bitrate= 874.6kbits/s speed=0.998x elapsed=0:01:09.61 +2026-04-10T21:06:32.346422Z INFO cht_client::backends::subprocess: [ffmpeg] [aac @ 0x55582370e440] Qavg: 11396.375 +2026-04-10T21:06:32.351170Z INFO cht_client::backends::subprocess: [ffmpeg] Exiting normally, received signal 2. +2026-04-10T21:06:32.357939Z INFO cht_client::backends::subprocess: [ffmpeg] stderr closed +2026-04-10T21:06:32.430521Z INFO cht_client::backends::subprocess: ffmpeg exited cleanly +2026-04-10T21:10:12.157580Z INFO cht_common::logging: Logging to /home/mariano/wdir/cht/logs/client.log +2026-04-10T21:10:12.157626Z INFO cht_client: Backend: Subprocess (default) +2026-04-10T21:10:12.157645Z INFO cht_client: Waiting for server at mcrndeb:4447... +2026-04-10T21:10:12.159320Z INFO cht_client: Connected to mcrndeb:4447 +2026-04-10T21:10:12.159434Z INFO cht_client: Sent session_start +2026-04-10T21:10:12.159567Z INFO cht_client::pipeline: Backend: Subprocess (ffmpeg CLI) +2026-04-10T21:10:12.170295Z INFO cht_client::backends::subprocess: Audio sources — monitor: Some("alsa_output.usb-TASCAM_US-122_MKII_no_serial_number-00.analog-stereo.monitor"), mic: Some("alsa_input.usb-046d_C922_Pro_Stream_Webcam_B4B595AF-02.analog-stereo") +2026-04-10T21:10:12.170374Z INFO cht_client::backends::subprocess: ffmpeg args: ["-init_hw_device", "drm=drm:/dev/dri/card0", "-init_hw_device", "vaapi=va@drm", "-thread_queue_size", "512", "-device", "/dev/dri/card0", "-f", "kmsgrab", "-framerate", "30", "-i", "-", "-f", "pulse", "-thread_queue_size", "1024", "-i", "alsa_output.usb-TASCAM_US-122_MKII_no_serial_number-00.analog-stereo.monitor", "-f", "pulse", "-thread_queue_size", "1024", "-i", "alsa_input.usb-046d_C922_Pro_Stream_Webcam_B4B595AF-02.analog-stereo", "-filter_complex", "[1:a][2:a]amix=inputs=2:duration=longest[aout]", "-map", "0:v", "-map", "[aout]", "-vf", "hwmap=derive_device=vaapi,scale_vaapi=w=1920:h=1080:format=nv12,fps=30", "-c:v", "h264_vaapi", "-qp", "20", "-g", "30", "-bf", "0", "-c:a", "aac", "-b:a", "128k", "-flush_packets", "1", "-fflags", "nobuffer", "-f", "nut", "pipe:1", "-hide_banner"] +2026-04-10T21:10:12.170626Z INFO cht_client::backends::subprocess: ffmpeg subprocess pid=297473 +2026-04-10T21:10:12.240299Z INFO cht_client::backends::subprocess: [ffmpeg] There are 2 hardware devices. device va of type vaapi is picked for filters by default. Set hardware device explicitly with the filter_hw_device option if device va is not usable for filters. +2026-04-10T21:10:12.240482Z INFO cht_client::backends::subprocess: [ffmpeg] [in#0 @ 0x55f31c7da440] Using plane 57 to locate framebuffers. +2026-04-10T21:10:12.240503Z INFO cht_client::backends::subprocess: [ffmpeg] [in#0 @ 0x55f31c7da440] Template framebuffer is 127: 1920x1080 format 30335258 modifier 0 flags 0. +2026-04-10T21:10:12.909527Z INFO cht_client::backends::subprocess: [ffmpeg] Input #0, kmsgrab, from 'fd:': +2026-04-10T21:10:12.909573Z INFO cht_client::backends::subprocess: [ffmpeg] Duration: N/A, start: 1775855412.240530, bitrate: N/A +2026-04-10T21:10:12.909595Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:0: Video: wrapped_avframe, drm_prime, 1920x1080, 29.92 tbr, 1000k tbn, start 1775855412.240530 +2026-04-10T21:10:13.069800Z INFO cht_client::backends::subprocess: [ffmpeg] [aist#1:0/pcm_s16le @ 0x55f31c7eef00] Guessed Channel Layout: stereo +2026-04-10T21:10:13.069850Z INFO cht_client::backends::subprocess: [ffmpeg] Input #1, pulse, from 'alsa_output.usb-TASCAM_US-122_MKII_no_serial_number-00.analog-stereo.monitor': +2026-04-10T21:10:13.069874Z INFO cht_client::backends::subprocess: [ffmpeg] Duration: N/A, start: 1775855412.994212, bitrate: 1536 kb/s +2026-04-10T21:10:13.069893Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #1:0: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s, start 1775855412.994212 +2026-04-10T21:10:13.361726Z INFO cht_client::backends::subprocess: [ffmpeg] [aist#2:0/pcm_s16le @ 0x55f31c7f8d00] Guessed Channel Layout: stereo +2026-04-10T21:10:13.361768Z INFO cht_client::backends::subprocess: [ffmpeg] Input #2, pulse, from 'alsa_input.usb-046d_C922_Pro_Stream_Webcam_B4B595AF-02.analog-stereo': +2026-04-10T21:10:13.361788Z INFO cht_client::backends::subprocess: [ffmpeg] Duration: N/A, start: 1775855413.234339, bitrate: 1536 kb/s +2026-04-10T21:10:13.361804Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #2:0: Audio: pcm_s16le, 48000 Hz, stereo, s16, 1536 kb/s, start 1775855413.234339 +2026-04-10T21:10:13.361823Z INFO cht_client::backends::subprocess: [ffmpeg] There are 2 hardware devices. device va of type vaapi is picked for filters by default. Set hardware device explicitly with the filter_hw_device option if device va is not usable for filters. +2026-04-10T21:10:13.362286Z INFO cht_client::backends::subprocess: [ffmpeg] Stream mapping: +2026-04-10T21:10:13.362322Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #1:0 (pcm_s16le) -> amix +2026-04-10T21:10:13.362346Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #2:0 (pcm_s16le) -> amix +2026-04-10T21:10:13.362363Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:0 -> #0:0 (wrapped_avframe (native) -> h264 (h264_vaapi)) +2026-04-10T21:10:13.362381Z INFO cht_client::backends::subprocess: [ffmpeg] amix:default -> Stream #0:1 (aac) +2026-04-10T21:10:13.362742Z INFO cht_client::backends::subprocess: [ffmpeg] There are 2 hardware devices. device va of type vaapi is picked for filters by default. Set hardware device explicitly with the filter_hw_device option if device va is not usable for filters. +2026-04-10T21:10:13.378251Z INFO cht_client::backends::subprocess: [ffmpeg] Last message repeated 1 times +2026-04-10T21:10:13.378288Z INFO cht_client::backends::subprocess: [ffmpeg] Output #0, nut, to 'pipe:1': +2026-04-10T21:10:13.378312Z INFO cht_client::backends::subprocess: [ffmpeg] Metadata: +2026-04-10T21:10:13.378330Z INFO cht_client::backends::subprocess: [ffmpeg] encoder : Lavf62.12.100 +2026-04-10T21:10:13.378346Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:0: Video: h264 (High) (H264 / 0x34363248), vaapi(tv, progressive), 1920x1080, q=2-31, 30 fps, 61440 tbn +2026-04-10T21:10:13.378363Z INFO cht_client::backends::subprocess: [ffmpeg] Metadata: +2026-04-10T21:10:13.378376Z INFO cht_client::backends::subprocess: [ffmpeg] encoder : Lavc62.28.100 h264_vaapi +2026-04-10T21:10:13.378391Z INFO cht_client::backends::subprocess: [ffmpeg] Stream #0:1: Audio: aac (LC) ([255][0][0][0] / 0x00FF), 48000 Hz, stereo, fltp, 128 kb/s +2026-04-10T21:10:13.378406Z INFO cht_client::backends::subprocess: [ffmpeg] Metadata: +2026-04-10T21:10:13.378418Z INFO cht_client::backends::subprocess: [ffmpeg] encoder : Lavc62.28.100 aac +2026-04-10T21:10:14.315563Z INFO cht_client::backends::subprocess: Demux: video_idx=0 tb=1/61440, audio_idx=1 tb=1/48000 +2026-04-10T21:10:14.315707Z INFO cht_client::backends::subprocess: Subprocess: 1 video, 1 audio packets +2026-04-10T21:10:14.316453Z INFO cht_client: Sent 1 video, 1 audio packets +2026-04-10T21:10:23.362551Z INFO cht_client::backends::subprocess: Subprocess: 301 video, 469 audio packets +2026-04-10T21:10:23.362703Z INFO cht_client: Sent 301 video, 469 audio packets +2026-04-10T21:10:33.431669Z INFO cht_client::backends::subprocess: Subprocess: 601 video, 938 audio packets +2026-04-10T21:10:33.431892Z INFO cht_client: Sent 601 video, 938 audio packets +2026-04-10T21:10:43.415910Z INFO cht_client::backends::subprocess: Subprocess: 901 video, 1407 audio packets +2026-04-10T21:10:43.416170Z INFO cht_client: Sent 901 video, 1407 audio packets +2026-04-10T21:10:53.364802Z INFO cht_client::backends::subprocess: Subprocess: 1201 video, 1874 audio packets +2026-04-10T21:10:53.365097Z INFO cht_client: Sent 1201 video, 1874 audio packets +2026-04-10T21:11:03.385341Z INFO cht_client::backends::subprocess: Subprocess: 1501 video, 2343 audio packets +2026-04-10T21:11:03.385463Z INFO cht_client: Sent 1501 video, 2343 audio packets +2026-04-10T21:11:13.369961Z INFO cht_client::backends::subprocess: Subprocess: 1801 video, 2812 audio packets +2026-04-10T21:11:13.370082Z INFO cht_client: Sent 1801 video, 2812 audio packets +2026-04-10T21:11:23.353784Z INFO cht_client::backends::subprocess: Subprocess: 2101 video, 3280 audio packets +2026-04-10T21:11:23.354019Z INFO cht_client: Sent 2101 video, 3280 audio packets +2026-04-10T21:11:28.165705Z INFO cht_client::backends::subprocess: Subprocess pipeline stopped (2243 video, 3502 audio packets) +2026-04-10T21:11:28.221593Z INFO cht_client::backends::subprocess: Stop watcher: sent SIGINT to ffmpeg pid=297473 +2026-04-10T21:11:28.261249Z INFO cht_client::backends::subprocess: [ffmpeg] frame= 25 fps=0.0 q=-0.0 size= 950KiB time=00:00:00.49 bitrate=15747.3kbits/s speed=0.989x elapsed=0:00:00.50 frame= 40 fps= 40 q=-0.0 size= 958KiB time=00:00:01.01 bitrate=7699.7kbits/s speed=1.02x elapsed=0:00:01.00 frame= 62 fps= 41 q=-0.0 size= 1245KiB time=00:00:01.41 bitrate=7222.4kbits/s speed=0.941x elapsed=0:00:01.50 frame= 70 fps= 35 q=-0.0 size= 1418KiB time=00:00:01.96 bitrate=5897.8kbits/s speed=0.985x elapsed=0:00:02.00 frame= 92 fps= 37 q=-0.0 size= 1709KiB time=00:00:02.47 bitrate=5649.3kbits/s speed=0.991x elapsed=0:00:02.50 frame= 100 fps= 33 q=-0.0 size= 1718KiB time=00:00:02.96 bitrate=4741.6kbits/s speed=0.989x elapsed=0:00:03.00 frame= 120 fps= 34 q=-0.0 size= 1757KiB time=00:00:03.33 bitrate=4321.0kbits/s speed=0.951x elapsed=0:00:03.50 frame= 130 fps= 32 q=-0.0 size= 1800KiB time=00:00:04.01 bitrate=3672.0kbits/s speed= 1x elapsed=0:00:04.00 frame= 152 fps= 34 q=-0.0 size= 1857KiB time=00:00:04.53 bitrate=3356.9kbits/s speed=1.01x elapsed=0:00:04.50 frame= 160 fps= 32 q=-0.0 size= 1874KiB time=00:00:04.98 bitrate=3081.8kbits/s speed=0.996x elapsed=0:00:05.00 frame= 183 fps= 33 q=-0.0 size= 1933KiB time=00:00:05.47 bitrate=2893.7kbits/s speed=0.995x elapsed=0:00:05.50 frame= 189 fps= 31 q=-0.0 size= 1955KiB time=00:00:06.02 bitrate=2656.9kbits/s speed= 1x elapsed=0:00:06.00 frame= 214 fps= 33 q=-0.0 size= 2009KiB time=00:00:06.43 bitrate=2559.3kbits/s speed=0.989x elapsed=0:00:06.50 frame= 219 fps= 31 q=-0.0 size= 2031KiB time=00:00:06.98 bitrate=2381.9kbits/s speed=0.998x elapsed=0:00:07.00 frame= 245 fps= 33 q=-0.0 size= 2099KiB time=00:00:07.51 bitrate=2286.6kbits/s speed= 1x elapsed=0:00:07.50 frame= 248 fps= 31 q=-0.0 size= 2119KiB time=00:00:08.03 bitrate=2161.6kbits/s speed= 1x elapsed=0:00:08.00 frame= 276 fps= 32 q=-0.0 size= 2174KiB time=00:00:08.47 bitrate=2101.2kbits/s speed=0.997x elapsed=0:00:08.50 frame= 278 fps= 31 q=-0.0 size= 2191KiB time=00:00:08.96 bitrate=2001.2kbits/s speed=0.996x elapsed=0:00:09.00 frame= 307 fps= 32 q=-0.0 size= 2238KiB time=00:00:09.52 bitrate=1925.4kbits/s speed= 1x elapsed=0:00:09.50 frame= 307 fps= 31 q=-0.0 size= 2254KiB time=00:00:10.03 bitrate=1840.3kbits/s speed= 1x elapsed=0:00:10.00 frame= 335 fps= 32 q=-0.0 size= 2295KiB time=00:00:10.48 bitrate=1794.3kbits/s speed=0.998x elapsed=0:00:10.50 frame= 338 fps= 31 q=-0.0 size= 2314KiB time=00:00:11.01 bitrate=1721.2kbits/s speed= 1x elapsed=0:00:11.00 frame= 367 fps= 32 q=-0.0 size= 2359KiB time=00:00:11.52 bitrate=1676.5kbits/s speed= 1x elapsed=0:00:11.50 frame= 367 fps= 31 q=-0.0 size= 2373KiB time=00:00:11.97 bitrate=1623.2kbits/s speed=0.998x elapsed=0:00:12.00 frame= 397 fps= 32 q=-0.0 size= 2416KiB time=00:00:12.46 bitrate=1588.0kbits/s speed=0.997x elapsed=0:00:12.50 frame= 397 fps= 31 q=-0.0 size= 2434KiB time=00:00:13.01 bitrate=1531.8kbits/s speed= 1x elapsed=0:00:13.00 frame= 425 fps= 31 q=-0.0 size= 2485KiB time=00:00:13.53 bitrate=1504.8kbits/s speed= 1x elapsed=0:00:13.50 frame= 427 fps= 30 q=-0.0 size= 2502KiB time=00:00:13.97 bitrate=1466.2kbits/s speed=0.998x elapsed=0:00:14.00 frame= 457 fps= 32 q=-0.0 size= 2550KiB time=00:00:14.46 bitrate=1444.1kbits/s speed=0.998x elapsed=0:00:14.50 frame= 457 fps= 30 q=-0.0 size= 2569KiB time=00:00:15.02 bitrate=1401.2kbits/s speed= 1x elapsed=0:00:15.00 frame= 486 fps= 31 q=-0.0 size= 2615KiB time=00:00:15.46 bitrate=1384.8kbits/s speed=0.998x elapsed=0:00:15.50 frame= 488 fps= 30 q=-0.0 size= 2633KiB time=00:00:15.98 bitrate=1349.5kbits/s speed=0.999x elapsed=0:00:16.00 frame= 517 fps= 31 q=-0.0 size= 2681KiB time=00:00:16.51 bitrate=1330.1kbits/s speed= 1x elapsed=0:00:16.50 frame= 517 fps= 30 q=-0.0 size= 2699KiB time=00:00:17.02 bitrate=1298.6kbits/s speed= 1x elapsed=0:00:17.00 frame= 545 fps= 31 q=-0.0 size= 2747KiB time=00:00:17.47 bitrate=1287.9kbits/s speed=0.998x elapsed=0:00:17.50 frame= 548 fps= 30 q=-0.0 size= 2764KiB time=00:00:17.96 bitrate=1260.4kbits/s speed=0.998x elapsed=0:00:18.00 frame= 577 fps= 31 q=-0.0 size= 2817KiB time=00:00:18.51 bitrate=1246.1kbits/s speed= 1x elapsed=0:00:18.50 frame= 577 fps= 30 q=-0.0 size= 2835KiB time=00:00:19.00 bitrate=1221.6kbits/s speed= 1x elapsed=0:00:19.00 frame= 607 fps= 31 q=-0.0 size= 2883KiB time=00:00:19.47 bitrate=1212.3kbits/s speed=0.999x elapsed=0:00:19.50 frame= 607 fps= 30 q=-0.0 size= 2901KiB time=00:00:20.01 bitrate=1187.3kbits/s speed= 1x elapsed=0:00:20.00 frame= 636 fps= 31 q=-0.0 size= 2950KiB time=00:00:20.52 bitrate=1177.5kbits/s speed= 1x elapsed=0:00:20.50 frame= 637 fps= 30 q=-0.0 size= 2965KiB time=00:00:20.97 bitrate=1158.0kbits/s speed=0.999x elapsed=0:00:21.00 frame= 667 fps= 31 q=-0.0 size= 3013KiB time=00:00:21.46 bitrate=1150.2kbits/s speed=0.998x elapsed=0:00:21.50 frame= 667 fps= 30 q=-0.0 size= 3031KiB time=00:00:22.01 bitrate=1127.6kbits/s speed= 1x elapsed=0:00:22.00 frame= 696 fps= 31 q=-0.0 size= 3079KiB time=00:00:22.53 bitrate=1119.6kbits/s speed= 1x elapsed=0:00:22.50 frame= 697 fps= 30 q=-0.0 size= 3094KiB time=00:00:22.97 bitrate=1103.1kbits/s speed=0.999x elapsed=0:00:23.00 frame= 727 fps= 31 q=-0.0 size= 3152KiB time=00:00:23.51 bitrate=1098.1kbits/s speed= 1x elapsed=0:00:23.50 frame= 727 fps= 30 q=-0.0 size= 3172KiB time=00:00:24.02 bitrate=1081.8kbits/s speed= 1x elapsed=0:00:24.00 frame= 755 fps= 31 q=-0.0 size= 3219KiB time=00:00:24.47 bitrate=1077.6kbits/s speed=0.999x elapsed=0:00:24.50 frame= 758 fps= 30 q=-0.0 size= 3239KiB time=00:00:24.96 bitrate=1062.8kbits/s speed=0.998x elapsed=0:00:25.00 frame= 787 fps= 31 q=-0.0 size= 3288KiB time=00:00:25.51 bitrate=1055.5kbits/s speed= 1x elapsed=0:00:25.50 frame= 787 fps= 30 q=-0.0 size= 3307KiB time=00:00:26.02 bitrate=1040.7kbits/s speed= 1x elapsed=0:00:26.00 frame= 815 fps= 31 q=-0.0 size= 3355KiB time=00:00:26.47 bitrate=1038.0kbits/s speed=0.999x elapsed=0:00:26.50 frame= 818 fps= 30 q=-0.0 size= 3375KiB time=00:00:27.01 bitrate=1023.6kbits/s speed= 1x elapsed=0:00:27.00 frame= 847 fps= 31 q=-0.0 size= 3425KiB time=00:00:27.52 bitrate=1019.4kbits/s speed= 1x elapsed=0:00:27.50 frame= 847 fps= 30 q=-0.0 size= 3441KiB time=00:00:27.96 bitrate=1007.8kbits/s speed=0.999x elapsed=0:00:28.00 frame= 877 fps= 31 q=-0.0 size= 3497KiB time=00:00:28.45 bitrate=1006.6kbits/s speed=0.998x elapsed=0:00:28.50 frame= 877 fps= 30 q=-0.0 size= 3516KiB time=00:00:29.01 bitrate= 992.8kbits/s speed= 1x elapsed=0:00:29.00 frame= 906 fps= 31 q=-0.0 size= 3565KiB time=00:00:29.52 bitrate= 989.2kbits/s speed= 1x elapsed=0:00:29.50 frame= 907 fps= 30 q=-0.0 size= 3579KiB time=00:00:29.97 bitrate= 978.0kbits/s speed=0.999x elapsed=0:00:30.00 frame= 937 fps= 31 q=-0.0 size= 3626KiB time=00:00:30.46 bitrate= 975.1kbits/s speed=0.999x elapsed=0:00:30.50 frame= 937 fps= 30 q=-0.0 size= 3644KiB time=00:00:31.02 bitrate= 962.2kbits/s speed= 1x elapsed=0:00:31.00 frame= 966 fps= 31 q=-0.0 size= 3691KiB time=00:00:31.51 bitrate= 959.6kbits/s speed= 1x elapsed=0:00:31.50 frame= 968 fps= 30 q=-0.0 size= 3707KiB time=00:00:31.98 bitrate= 949.5kbits/s speed=0.999x elapsed=0:00:32.00 frame= 997 fps= 31 q=-0.0 size= 3757KiB time=00:00:32.51 bitrate= 946.5kbits/s speed= 1x elapsed=0:00:32.50 frame= 997 fps= 30 q=-0.0 size= 3774KiB time=00:00:33.02 bitrate= 936.1kbits/s speed= 1x elapsed=0:00:33.00 frame= 1025 fps= 31 q=-0.0 size= 3835KiB time=00:00:33.47 bitrate= 938.5kbits/s speed=0.999x elapsed=0:00:33.50 frame= 1028 fps= 30 q=-0.0 size= 3851KiB time=00:00:33.97 bitrate= 928.6kbits/s speed=0.999x elapsed=0:00:34.00 frame= 1057 fps= 31 q=-0.0 size= 3910KiB time=00:00:34.53 bitrate= 927.6kbits/s speed= 1x elapsed=0:00:34.50 frame= 1057 fps= 30 q=-0.0 size= 3929KiB time=00:00:35.03 bitrate= 918.8kbits/s speed= 1x elapsed=0:00:35.00 frame= 1085 fps= 31 q=-0.0 size= 3983KiB time=00:00:35.50 bitrate= 919.0kbits/s speed= 1x elapsed=0:00:35.50 frame= 1085 fps= 30 q=-0.0 size= 4004KiB time=00:00:36.03 bitrate= 910.1kbits/s speed= 1x elapsed=0:00:36.00 frame= 1115 fps= 31 q=-0.0 size= 4062KiB time=00:00:36.54 bitrate= 910.4kbits/s speed= 1x elapsed=0:00:36.50 frame= 1115 fps= 30 q=-0.0 size= 4080KiB time=00:00:36.99 bitrate= 903.3kbits/s speed= 1x elapsed=0:00:37.00 frame= 1144 fps= 31 q=-0.0 size= 4145KiB time=00:00:37.48 bitrate= 905.8kbits/s speed= 1x elapsed=0:00:37.50 frame= 1146 fps= 30 q=-0.0 size= 4198KiB time=00:00:38.04 bitrate= 904.1kbits/s speed= 1x elapsed=0:00:38.00 frame= 1172 fps= 30 q=-0.0 size= 4225KiB time=00:00:38.55 bitrate= 897.7kbits/s speed= 1x elapsed=0:00:38.50 frame= 1175 fps= 30 q=-0.0 size= 4242KiB time=00:00:39.00 bitrate= 890.9kbits/s speed= 1x elapsed=0:00:39.00 frame= 1202 fps= 30 q=-0.0 size= 4285KiB time=00:00:39.53 bitrate= 888.0kbits/s speed= 1x elapsed=0:00:39.50 frame= 1207 fps= 30 q=-0.0 size= 4325KiB time=00:00:40.04 bitrate= 884.6kbits/s speed= 1x elapsed=0:00:40.00 frame= 1231 fps= 30 q=-0.0 size= 4343KiB time=00:00:40.53 bitrate= 877.6kbits/s speed= 1x elapsed=0:00:40.50 frame= 1240 fps= 30 q=-0.0 size= 4358KiB time=00:00:40.98 bitrate= 871.1kbits/s speed=0.999x elapsed=0:00:41.00 frame= 1259 fps= 30 q=-0.0 size= 4403KiB time=00:00:41.53 bitrate= 868.3kbits/s speed= 1x elapsed=0:00:41.50 frame= 1271 fps= 30 q=-0.0 size= 4419KiB time=00:00:41.98 bitrate= 862.2kbits/s speed= 1x elapsed=0:00:42.00 frame= 1289 fps= 30 q=-0.0 size= 4462KiB time=00:00:42.49 bitrate= 860.1kbits/s speed= 1x elapsed=0:00:42.50 frame= 1302 fps= 30 q=-0.0 size= 4480KiB time=00:00:42.99 bitrate= 853.6kbits/s speed= 1x elapsed=0:00:43.00 frame= 1318 fps= 30 q=-0.0 size= 4524KiB time=00:00:43.54 bitrate= 851.0kbits/s speed= 1x elapsed=0:00:43.50 frame= 1336 fps= 30 q=-0.0 size= 4540KiB time=00:00:43.99 bitrate= 845.4kbits/s speed= 1x elapsed=0:00:44.00 frame= 1346 fps= 30 q=-0.0 size= 4583KiB time=00:00:44.48 bitrate= 844.0kbits/s speed=0.999x elapsed=0:00:44.50 frame= 1369 fps= 30 q=-0.0 size= 4607KiB time=00:00:44.99 bitrate= 838.7kbits/s speed= 1x elapsed=0:00:45.00 frame= 1375 fps= 30 q=-0.0 size= 4648KiB time=00:00:45.55 bitrate= 836.0kbits/s speed= 1x elapsed=0:00:45.50 frame= 1399 fps= 30 q=-0.0 size= 4670KiB time=00:00:45.99 bitrate= 831.8kbits/s speed= 1x elapsed=0:00:46.00 frame= 1404 fps= 30 q=-0.0 size= 4712KiB time=00:00:46.48 bitrate= 830.4kbits/s speed= 1x elapsed=0:00:46.50 frame= 1432 fps= 30 q=-0.0 size= 4761KiB time=00:00:47.04 bitrate= 829.1kbits/s speed= 1x elapsed=0:00:47.00 frame= 1432 fps= 30 q=-0.0 size= 4779KiB time=00:00:47.53 bitrate= 823.7kbits/s speed= 1x elapsed=0:00:47.50 frame= 1460 fps= 30 q=-0.0 size= 4802KiB time=00:00:48.00 bitrate= 819.5kbits/s speed= 1x elapsed=0:00:48.00 frame= 1460 fps= 30 q=-0.0 size= 4845KiB time=00:00:48.53 bitrate= 817.8kbits/s speed= 1x elapsed=0:00:48.50 frame= 1490 fps= 30 q=-0.0 size= 4896KiB time=00:00:49.04 bitrate= 817.6kbits/s speed= 1x elapsed=0:00:49.00 frame= 1490 fps= 30 q=-0.0 size= 4912KiB time=00:00:49.49 bitrate= 813.0kbits/s speed= 1x elapsed=0:00:49.50 frame= 1519 fps= 30 q=-0.0 size= 4936KiB time=00:00:49.98 bitrate= 808.9kbits/s speed= 1x elapsed=0:00:50.00 frame= 1521 fps= 30 q=-0.0 size= 4982KiB time=00:00:50.54 bitrate= 807.4kbits/s speed= 1x elapsed=0:00:50.50 frame= 1547 fps= 30 q=-0.0 size= 5003KiB time=00:00:51.03 bitrate= 803.0kbits/s speed= 1x elapsed=0:00:51.00 frame= 1550 fps= 30 q=-0.0 size= 5043KiB time=00:00:51.50 bitrate= 802.2kbits/s speed= 1x elapsed=0:00:51.50 frame= 1577 fps= 30 q=-0.0 size= 5067KiB time=00:00:52.03 bitrate= 797.7kbits/s speed= 1x elapsed=0:00:52.00 frame= 1582 fps= 30 q=-0.0 size= 5112KiB time=00:00:52.54 bitrate= 796.9kbits/s speed= 1x elapsed=0:00:52.50 frame= 1606 fps= 30 q=-0.0 size= 5132KiB time=00:00:53.03 bitrate= 792.6kbits/s speed= 1x elapsed=0:00:53.00 frame= 1616 fps= 30 q=-0.0 size= 5174KiB time=00:00:53.48 bitrate= 792.5kbits/s speed= 1x elapsed=0:00:53.50 frame= 1634 fps= 30 q=-0.0 size= 5207KiB time=00:00:54.04 bitrate= 789.2kbits/s speed= 1x elapsed=0:00:54.00 frame= 1648 fps= 30 q=-0.0 size= 5253KiB time=00:00:54.48 bitrate= 789.7kbits/s speed= 1x elapsed=0:00:54.50 frame= 1663 fps= 30 q=-0.0 size= 5274KiB time=00:00:55.00 bitrate= 785.5kbits/s speed= 1x elapsed=0:00:55.00 frame= 1679 fps= 30 q=-0.0 size= 5323KiB time=00:00:55.53 bitrate= 785.2kbits/s speed= 1x elapsed=0:00:55.51 frame= 1692 fps= 30 q=-0.0 size= 5367KiB time=00:00:56.04 bitrate= 784.4kbits/s speed= 1x elapsed=0:00:56.01 frame= 1713 fps= 30 q=-0.0 size= 5390KiB time=00:00:56.49 bitrate= 781.5kbits/s speed= 1x elapsed=0:00:56.51 frame= 1720 fps= 30 q=-0.0 size= 5409KiB time=00:00:56.98 bitrate= 777.5kbits/s speed= 1x elapsed=0:00:57.01 frame= 1746 fps= 30 q=-0.0 size= 5461KiB time=00:00:57.54 bitrate= 777.6kbits/s speed= 1x elapsed=0:00:57.51 frame= 1748 fps= 30 q=-0.0 size= 5506KiB time=00:00:58.05 bitrate= 777.0kbits/s speed= 1x elapsed=0:00:58.01 frame= 1776 fps= 30 q=-0.0 size= 5536KiB time=00:00:58.50 bitrate= 775.2kbits/s speed= 1x elapsed=0:00:58.51 frame= 1778 fps= 30 q=-0.0 size= 5554KiB time=00:00:59.03 bitrate= 770.7kbits/s speed= 1x elapsed=0:00:59.01 frame= 1807 fps= 30 q=-0.0 size= 5602KiB time=00:00:59.54 bitrate= 770.7kbits/s speed= 1x elapsed=0:00:59.51 frame= 1807 fps= 30 q=-0.0 size= 5618KiB time=00:01:00.03 bitrate= 766.5kbits/s speed= 1x elapsed=0:01:00.01 frame= 1835 fps= 30 q=-0.0 size= 5664KiB time=00:01:00.48 bitrate= 767.1kbits/s speed= 1x elapsed=0:01:00.51 frame= 1835 fps= 30 q=-0.0 size= 5682KiB time=00:01:01.04 bitrate= 762.5kbits/s speed= 1x elapsed=0:01:01.01 frame= 1865 fps= 30 q=-0.0 size= 5730KiB time=00:01:01.55 bitrate= 762.7kbits/s speed= 1x elapsed=0:01:01.51 frame= 1865 fps= 30 q=-0.0 size= 5745KiB time=00:01:01.99 bitrate= 759.1kbits/s speed= 1x elapsed=0:01:02.01 frame= 1894 fps= 30 q=-0.0 size= 5793KiB time=00:01:02.48 bitrate= 759.5kbits/s speed= 1x elapsed=0:01:02.51 frame= 1896 fps= 30 q=-0.0 size= 5838KiB time=00:01:03.04 bitrate= 758.6kbits/s speed= 1x elapsed=0:01:03.01 frame= 1922 fps= 30 q=-0.0 size= 5853KiB time=00:01:03.53 bitrate= 754.7kbits/s speed= 1x elapsed=0:01:03.51 frame= 1929 fps= 30 q=-0.0 size= 5871KiB time=00:01:04.01 bitrate= 751.3kbits/s speed= 1x elapsed=0:01:04.01 frame= 1951 fps= 30 q=-0.0 size= 5938KiB time=00:01:04.55 bitrate= 753.5kbits/s speed= 1x elapsed=0:01:04.51 frame= 1959 fps= 30 q=-0.0 size= 5990KiB time=00:01:05.06 bitrate= 754.2kbits/s speed= 1x elapsed=0:01:05.01 frame= 1980 fps= 30 q=-0.0 size= 6013KiB time=00:01:05.56 bitrate= 751.3kbits/s speed= 1x elapsed=0:01:05.51 frame= 1994 fps= 30 q=-0.0 size= 6030KiB time=00:01:06.01 bitrate= 748.3kbits/s speed= 1x elapsed=0:01:06.01 frame= 2008 fps= 30 q=-0.0 size= 6088KiB time=00:01:06.56 bitrate= 749.2kbits/s speed= 1x elapsed=0:01:06.51 frame= 2027 fps= 30 q=-0.0 size= 6141KiB time=00:01:07.05 bitrate= 750.2kbits/s speed= 1x elapsed=0:01:07.01 frame= 2036 fps= 30 q=-0.0 size= 6162KiB time=00:01:07.52 bitrate= 747.5kbits/s speed= 1x elapsed=0:01:07.51 frame= 2056 fps= 30 q=-0.0 size= 6221KiB time=00:01:08.06 bitrate= 748.8kbits/s speed= 1x elapsed=0:01:08.01 frame= 2066 fps= 30 q=-0.0 size= 6239KiB time=00:01:08.57 bitrate= 745.4kbits/s speed= 1x elapsed=0:01:08.51 frame= 2088 fps= 30 q=-0.0 size= 6265KiB time=00:01:09.01 bitrate= 743.5kbits/s speed= 1x elapsed=0:01:09.01 frame= 2095 fps= 30 q=-0.0 size= 6303KiB time=00:01:09.51 bitrate= 742.8kbits/s speed= 1x elapsed=0:01:09.51 frame= 2123 fps= 30 q=-0.0 size= 6343KiB time=00:01:10.06 bitrate= 741.7kbits/s speed= 1x elapsed=0:01:10.01 frame= 2123 fps= 30 q=-0.0 size= 6352KiB time=00:01:10.57 bitrate= 737.3kbits/s speed= 1x elapsed=0:01:10.51 frame= 2153 fps= 30 q=-0.0 size= 6386KiB time=00:01:11.02 bitrate= 736.6kbits/s speed= 1x elapsed=0:01:11.01 frame= 2153 fps= 30 q=-0.0 size= 6396KiB time=00:01:11.55 bitrate= 732.3kbits/s speed= 1x elapsed=0:01:11.51 frame= 2182 fps= 30 q=-0.0 size= 6427KiB time=00:01:12.06 bitrate= 730.6kbits/s speed= 1x elapsed=0:01:12.01 frame= 2182 fps= 30 q=-0.0 size= 6437KiB time=00:01:12.55 bitrate= 726.8kbits/s speed= 1x elapsed=0:01:12.51 frame= 2210 fps= 30 q=-0.0 size= 6446KiB time=00:01:13.00 bitrate= 723.3kbits/s speed= 1x elapsed=0:01:13.01 frame= 2210 fps= 30 q=-0.0 size= 6479KiB time=00:01:13.56 bitrate= 721.5kbits/s speed= 1x elapsed=0:01:13.51 frame= 2239 fps= 30 q=-0.0 size= 6510KiB time=00:01:14.07 bitrate= 719.9kbits/s speed= 1x elapsed=0:01:14.01 frame= 2239 fps= 30 q=-0.0 size= 6520KiB time=00:01:14.52 bitrate= 716.7kbits/s speed= 1x elapsed=0:01:14.51 [aost#0:1/aac @ 0x55f31c800d00] Error submitting a packet to the muxer: Immediate exit requested +2026-04-10T21:11:28.262111Z INFO cht_client::backends::subprocess: [ffmpeg] Last message repeated 1 times +2026-04-10T21:11:28.262130Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x55f31c7f8fc0] Error muxing a packet +2026-04-10T21:11:28.262146Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x55f31c7f8fc0] Task finished with error code: -1414092869 (Immediate exit requested) +2026-04-10T21:11:28.262162Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x55f31c7f8fc0] Terminating thread with return code -1414092869 (Immediate exit requested) +2026-04-10T21:11:28.324512Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x55f31c7f8fc0] Error writing trailer: Immediate exit requested +2026-04-10T21:11:28.324578Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x55f31c7f8fc0] Error closing file: Immediate exit requested +2026-04-10T21:11:28.324600Z INFO cht_client::backends::subprocess: [ffmpeg] [out#0/nut @ 0x55f31c7f8fc0] video:5498KiB audio:1039KiB subtitle:0KiB other streams:0KiB global headers:0KiB muxing overhead: unknown +2026-04-10T21:11:28.324624Z INFO cht_client::backends::subprocess: [ffmpeg] frame= 2268 fps= 30 q=-0.0 Lsize= 6527KiB time=00:01:14.94 bitrate= 713.5kbits/s speed= 1x elapsed=0:01:14.96 +2026-04-10T21:11:28.326276Z INFO cht_client::backends::subprocess: [ffmpeg] [aac @ 0x55f31c801480] Qavg: 10464.688 +2026-04-10T21:11:28.331294Z INFO cht_client::backends::subprocess: [ffmpeg] Exiting normally, received signal 2. +2026-04-10T21:11:28.337814Z INFO cht_client::backends::subprocess: [ffmpeg] stderr closed +2026-04-10T21:11:28.366056Z INFO cht_client::backends::subprocess: ffmpeg exited cleanly diff --git a/tests/fixtures/test_scene_30s_ground_truth.json b/tests/fixtures/test_scene_30s_ground_truth.json new file mode 100644 index 0000000..ec332d1 --- /dev/null +++ b/tests/fixtures/test_scene_30s_ground_truth.json @@ -0,0 +1,38 @@ +{ + "duration_s": 30, + "interval_s": 5, + "num_scenes": 6, + "video_path": "/home/mariano/wdir/cht/tests/fixtures/test_scene_30s.mp4", + "scenes": [ + { + "scene_index": 0, + "timestamp_s": 0, + "color_hex": "FF0000" + }, + { + "scene_index": 1, + "timestamp_s": 5, + "color_hex": "0000FF" + }, + { + "scene_index": 2, + "timestamp_s": 10, + "color_hex": "00FF00" + }, + { + "scene_index": 3, + "timestamp_s": 15, + "color_hex": "FFFF00" + }, + { + "scene_index": 4, + "timestamp_s": 20, + "color_hex": "FF00FF" + }, + { + "scene_index": 5, + "timestamp_s": 25, + "color_hex": "00FFFF" + } + ] +} \ No newline at end of file diff --git a/tests/fixtures/test_speech.ogg b/tests/fixtures/test_speech.ogg new file mode 100644 index 0000000..e5a55fe --- /dev/null +++ b/tests/fixtures/test_speech.ogg @@ -0,0 +1 @@ +File not found: /v1/AUTH_mw/wikipedia-commons-local-public.22/2/22/En-us-United_States_Constitution-Article_1-Section_1.ogg \ No newline at end of file