From a707331cda069183017bd3197575e664e57486b1 Mon Sep 17 00:00:00 2001 From: Brad Stein Date: Tue, 5 May 2026 19:33:56 -0300 Subject: [PATCH] test(server-rc): require signal readiness before measured probe --- Cargo.lock | 6 +- client/Cargo.toml | 2 +- common/Cargo.toml | 2 +- .../manual/run_server_to_rc_mode_matrix.sh | 262 +++++++++++++++++- scripts/manual/run_upstream_av_sync.sh | 133 +++++++++ server/Cargo.toml | 2 +- .../client_manual_sync_script_contract.rs | 18 +- 7 files changed, 404 insertions(+), 21 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 2b52589..8aa1cab 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1652,7 +1652,7 @@ checksum = "09edd9e8b54e49e587e4f6295a7d29c3ea94d469cb40ab8ca70b288248a81db2" [[package]] name = "lesavka_client" -version = "0.19.24" +version = "0.19.25" dependencies = [ "anyhow", "async-stream", @@ -1686,7 +1686,7 @@ dependencies = [ [[package]] name = "lesavka_common" -version = "0.19.24" +version = "0.19.25" dependencies = [ "anyhow", "base64", @@ -1698,7 +1698,7 @@ dependencies = [ [[package]] name = "lesavka_server" -version = "0.19.24" +version = "0.19.25" dependencies = [ "anyhow", "base64", diff --git a/client/Cargo.toml b/client/Cargo.toml index ae98612..7a4aaf7 100644 --- a/client/Cargo.toml +++ b/client/Cargo.toml @@ -4,7 +4,7 @@ path = "src/main.rs" [package] name = "lesavka_client" -version = "0.19.24" +version = "0.19.25" edition = "2024" [dependencies] diff --git a/common/Cargo.toml b/common/Cargo.toml index 1bd808e..f157cff 100644 --- a/common/Cargo.toml +++ b/common/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "lesavka_common" -version = "0.19.24" +version = "0.19.25" edition = "2024" build = "build.rs" diff --git a/scripts/manual/run_server_to_rc_mode_matrix.sh b/scripts/manual/run_server_to_rc_mode_matrix.sh index 42072d8..52cbead 100755 --- a/scripts/manual/run_server_to_rc_mode_matrix.sh +++ b/scripts/manual/run_server_to_rc_mode_matrix.sh @@ -73,6 +73,13 @@ LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=${LESAVKA_SERVER_RC_FRESHNE LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS=${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS:-${LESAVKA_SERVER_RC_TUNE_MIN_PAIRS}} LESAVKA_SERVER_RC_REQUIRE_FRESHNESS_PASS=${LESAVKA_SERVER_RC_REQUIRE_FRESHNESS_PASS:-1} LESAVKA_SERVER_RC_REQUIRE_SYNC_PASS=${LESAVKA_SERVER_RC_REQUIRE_SYNC_PASS:-1} +LESAVKA_SERVER_RC_MIN_CODED_PAIRS=${LESAVKA_SERVER_RC_MIN_CODED_PAIRS:-${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}} +LESAVKA_SERVER_RC_REQUIRE_ALL_CODED_PAIRS=${LESAVKA_SERVER_RC_REQUIRE_ALL_CODED_PAIRS:-0} +LESAVKA_SERVER_RC_REQUIRE_SMOOTHNESS_PASS=${LESAVKA_SERVER_RC_REQUIRE_SMOOTHNESS_PASS:-0} +LESAVKA_SERVER_RC_SIGNAL_READY=${LESAVKA_SERVER_RC_SIGNAL_READY:-1} +LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS=${LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS:-3} +LESAVKA_SERVER_RC_SIGNAL_READY_DURATION_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_READY_DURATION_SECONDS:-8} +LESAVKA_SERVER_RC_SIGNAL_READY_WARMUP_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_READY_WARMUP_SECONDS:-1} LESAVKA_SERVER_RC_MAX_VIDEO_HICCUPS=${LESAVKA_SERVER_RC_MAX_VIDEO_HICCUPS:-0} LESAVKA_SERVER_RC_MAX_AUDIO_HICCUPS=${LESAVKA_SERVER_RC_MAX_AUDIO_HICCUPS:-0} @@ -163,6 +170,9 @@ run_mode_probe() { local video_delay_us=$5 local output_dir=$6 local log_path=$7 + local probe_duration_seconds=${8:-${PROBE_DURATION_SECONDS}} + local probe_warmup_seconds=${9:-${PROBE_WARMUP_SECONDS}} + local min_pairs=${10:-${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}} set +e TETHYS_HOST="${TETHYS_HOST}" \ @@ -191,17 +201,17 @@ run_mode_probe() { LESAVKA_OUTPUT_DELAY_APPLY=0 \ LESAVKA_OUTPUT_DELAY_SAVE=0 \ LESAVKA_OUTPUT_REQUIRE_SYNC_PASS=0 \ - LESAVKA_OUTPUT_DELAY_MIN_PAIRS="${LESAVKA_SERVER_RC_TUNE_MIN_PAIRS}" \ + LESAVKA_OUTPUT_DELAY_MIN_PAIRS="${min_pairs}" \ LESAVKA_OUTPUT_DELAY_MAX_ABS_SKEW_MS="${LESAVKA_SERVER_RC_TUNE_MAX_ABS_SKEW_MS}" \ LESAVKA_OUTPUT_DELAY_MAX_DRIFT_MS="${LESAVKA_SERVER_RC_TUNE_MAX_DRIFT_MS}" \ LESAVKA_OUTPUT_DELAY_MAX_STEP_US="${LESAVKA_SERVER_RC_TUNE_MAX_STEP_US}" \ LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS="${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS}" \ LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS="${LESAVKA_SERVER_RC_FRESHNESS_MAX_DRIFT_MS}" \ LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS="${LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS}" \ - LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS="${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}" \ + LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS="${min_pairs}" \ PROBE_EVENT_WIDTH_CODES="${PROBE_EVENT_WIDTH_CODES}" \ - PROBE_DURATION_SECONDS="${PROBE_DURATION_SECONDS}" \ - PROBE_WARMUP_SECONDS="${PROBE_WARMUP_SECONDS}" \ + PROBE_DURATION_SECONDS="${probe_duration_seconds}" \ + PROBE_WARMUP_SECONDS="${probe_warmup_seconds}" \ LOCAL_OUTPUT_DIR="${output_dir}" \ "${SCRIPT_DIR}/run_upstream_av_sync.sh" 2>&1 | tee "${log_path}" RUN_MODE_PROBE_STATUS=${PIPESTATUS[0]} @@ -321,6 +331,146 @@ with pathlib.Path(output_env_path).open("w") as handle: PY } +signal_readiness_passed() { + local artifact_dir=$1 + local min_pairs=$2 + python3 - <<'PY' "${artifact_dir}" "${min_pairs}" +import json +import pathlib +import sys + +artifact_dir = pathlib.Path(sys.argv[1]) +min_pairs = int(sys.argv[2]) + +def load_json(path): + try: + return json.loads(path.read_text()) + except Exception: + return {} + +report = load_json(artifact_dir / "report.json") +paired = int(report.get("paired_event_count") or 0) +video = int(report.get("video_event_count") or 0) +audio = int(report.get("audio_event_count") or 0) +verdict = report.get("verdict") or {} +passed = paired >= min_pairs and video >= min_pairs and audio >= min_pairs and verdict.get("passed") is True +if not passed: + reason = ( + f"signal readiness needs at least {min_pairs} paired coded events with sync pass; " + f"saw paired={paired}, video={video}, audio={audio}, sync={verdict.get('status', 'unknown')}" + ) + print(reason) +raise SystemExit(0 if passed else 1) +PY +} + +write_signal_readiness_failure() { + local mode=$1 + local width=$2 + local height=$3 + local fps=$4 + local video_delay_us=$5 + local audio_delay_us=$6 + local readiness_status=$7 + local readiness_log=$8 + local readiness_artifact_dir=$9 + local readiness_reason=${10} + local output_json=${11} + python3 - <<'PY' \ + "${mode}" \ + "${width}" \ + "${height}" \ + "${fps}" \ + "${video_delay_us}" \ + "${audio_delay_us}" \ + "${readiness_status}" \ + "${readiness_log}" \ + "${readiness_artifact_dir}" \ + "${readiness_reason}" \ + "${output_json}" +import json +import pathlib +import sys + +( + mode, + width_raw, + height_raw, + fps_raw, + video_delay_raw, + audio_delay_raw, + readiness_status_raw, + readiness_log, + readiness_artifact_dir, + readiness_reason, + output_json, +) = sys.argv[1:] + +def as_int(value, default=0): + try: + return int(str(value).strip()) + except Exception: + return default + +def load_json(path): + try: + return json.loads(pathlib.Path(path).read_text()) + except Exception: + return {} + +report = load_json(pathlib.Path(readiness_artifact_dir) / "report.json") +verdict = report.get("verdict") or {} +signature_coverage = report.get("signature_coverage") or {} +result = { + "schema": "lesavka.server-rc-mode-result.v1", + "mode": mode, + "width": as_int(width_raw), + "height": as_int(height_raw), + "fps": as_int(fps_raw), + "audio_delay_us": as_int(audio_delay_raw), + "video_delay_us": as_int(video_delay_raw), + "run_status": as_int(readiness_status_raw), + "run_log": readiness_log, + "artifact_dir": readiness_artifact_dir, + "report_json": str(pathlib.Path(readiness_artifact_dir) / "report.json"), + "passed": False, + "failure_reasons": [f"signal readiness did not pass: {readiness_reason}"], + "signal_readiness": { + "passed": False, + "reason": readiness_reason, + "artifact_dir": readiness_artifact_dir, + "run_log": readiness_log, + }, + "sync": { + "passed": verdict.get("passed") is True, + "status": verdict.get("status", "unknown"), + "reason": verdict.get("reason", ""), + "p95_abs_skew_ms": float(verdict.get("p95_abs_skew_ms") or 0.0), + "median_skew_ms": float(report.get("median_skew_ms") or 0.0), + "drift_ms": float(report.get("drift_ms") or 0.0), + "activity_start_delta_ms": float(report.get("activity_start_delta_ms") or 0.0), + "first_skew_ms": float(report.get("first_skew_ms") or 0.0), + "video_event_count": as_int(report.get("video_event_count")), + "audio_event_count": as_int(report.get("audio_event_count")), + "paired_event_count": as_int(report.get("paired_event_count")), + "signature_expected_event_count": as_int(signature_coverage.get("expected_event_count")), + "signature_paired_event_count": as_int(signature_coverage.get("paired_event_count")), + "signature_missing_event_ids": signature_coverage.get("missing_event_ids") or [], + "signature_missing_codes": signature_coverage.get("missing_codes") or [], + "signature_unknown_pair_identity_count": as_int(signature_coverage.get("unknown_pair_identity_count")), + }, + "freshness": { + "status": "unknown", + "reason": "measured probe skipped because signal readiness failed", + "worst_event_age_with_uncertainty_ms": 0.0, + }, + "smoothness": {}, + "output_delay_calibration": {}, +} +pathlib.Path(output_json).write_text(json.dumps(result, indent=2, sort_keys=True) + "\n") +PY +} + discover_local_webcam_modes() { if ! command -v python3 >/dev/null 2>&1; then printf 'LESAVKA_SERVER_RC_MODES=auto requires python3 for local webcam mode discovery.\n' >&2 @@ -855,7 +1005,10 @@ write_mode_result() { "${LESAVKA_SERVER_RC_MAX_VIDEO_MISSING_FRAMES}" \ "${LESAVKA_SERVER_RC_MAX_VIDEO_UNDECODABLE_FRAMES}" \ "${LESAVKA_SERVER_RC_MAX_VIDEO_DUPLICATE_FRAMES}" \ - "${LESAVKA_SERVER_RC_MAX_AUDIO_LOW_RMS_WINDOWS}" + "${LESAVKA_SERVER_RC_MAX_AUDIO_LOW_RMS_WINDOWS}" \ + "${LESAVKA_SERVER_RC_MIN_CODED_PAIRS}" \ + "${LESAVKA_SERVER_RC_REQUIRE_ALL_CODED_PAIRS}" \ + "${LESAVKA_SERVER_RC_REQUIRE_SMOOTHNESS_PASS}" import json import math import pathlib @@ -882,6 +1035,9 @@ import sys max_undecodable_raw, max_duplicates_raw, max_low_rms_raw, + min_coded_pairs_raw, + require_all_coded_pairs_raw, + require_smoothness_raw, ) = sys.argv[1:] @@ -928,6 +1084,7 @@ timing_map = correlation.get("timing_map") or {} freshness = correlation.get("freshness") or {} capture_timebase = freshness.get("capture_timebase") or {} smoothness = correlation.get("smoothness") or {} +event_visibility = correlation.get("event_visibility") or {} video = smoothness.get("video") or {} audio = smoothness.get("audio") or {} audio_cadence = audio.get("packet_cadence") or {} @@ -951,6 +1108,9 @@ low_rms = as_int(audio_rms.get("low_rms_window_count"), 0) signature_expected = as_int(signature_coverage.get("expected_event_count"), 0) signature_paired = as_int(signature_coverage.get("paired_event_count"), 0) signature_unknown = as_int(signature_coverage.get("unknown_pair_identity_count"), 0) +min_coded_pairs = as_int(min_coded_pairs_raw, 0) +require_all_coded_pairs = as_bool(require_all_coded_pairs_raw) +require_smoothness = as_bool(require_smoothness_raw) pair_confidences = [] for event in report.get("paired_events") or []: if not isinstance(event, dict): @@ -982,6 +1142,7 @@ activity_pair_disagreement_ms = ( ) reasons = [] +smoothness_warnings = [] if run_status != 0: reasons.append(f"probe command exited {run_status}") if as_bool(require_sync_raw) and not sync_pass: @@ -994,28 +1155,32 @@ if capture_timebase and capture_timebase.get("valid") is False: f"{capture_timebase.get('reason', capture_timebase.get('status', 'invalid'))}" ) if signature_expected > 0: - if signature_paired < signature_expected: + if require_all_coded_pairs and signature_paired < signature_expected: reasons.append(f"paired coded signatures {signature_paired} < expected {signature_expected}") + elif min_coded_pairs > 0 and signature_paired < min_coded_pairs: + reasons.append(f"paired coded signatures {signature_paired} < required {min_coded_pairs}") if signature_unknown > 0: reasons.append(f"paired signatures without coded identity {signature_unknown} > 0") elif report.get("coded_events") is True: reasons.append("coded signature coverage unavailable") if video_hiccups > as_int(max_video_hiccups_raw): - reasons.append(f"video hiccups {video_hiccups} > {max_video_hiccups_raw}") + smoothness_warnings.append(f"video hiccups {video_hiccups} > {max_video_hiccups_raw}") if audio_hiccups > as_int(max_audio_hiccups_raw): - reasons.append(f"audio hiccups {audio_hiccups} > {max_audio_hiccups_raw}") + smoothness_warnings.append(f"audio hiccups {audio_hiccups} > {max_audio_hiccups_raw}") if video_jitter > as_float(max_video_jitter_raw): - reasons.append(f"video p95 jitter {video_jitter:.1f}ms > {as_float(max_video_jitter_raw):.1f}ms") + smoothness_warnings.append(f"video p95 jitter {video_jitter:.1f}ms > {as_float(max_video_jitter_raw):.1f}ms") if audio_jitter > as_float(max_audio_jitter_raw): - reasons.append(f"audio p95 jitter {audio_jitter:.1f}ms > {as_float(max_audio_jitter_raw):.1f}ms") + smoothness_warnings.append(f"audio p95 jitter {audio_jitter:.1f}ms > {as_float(max_audio_jitter_raw):.1f}ms") if missing > as_int(max_missing_raw): - reasons.append(f"estimated missing video frames {missing} > {max_missing_raw}") + smoothness_warnings.append(f"estimated missing video frames {missing} > {max_missing_raw}") if undecodable > as_int(max_undecodable_raw): - reasons.append(f"undecodable video frames {undecodable} > {max_undecodable_raw}") + smoothness_warnings.append(f"undecodable video frames {undecodable} > {max_undecodable_raw}") if duplicates > as_int(max_duplicates_raw): - reasons.append(f"duplicate video frames {duplicates} > {max_duplicates_raw}") + smoothness_warnings.append(f"duplicate video frames {duplicates} > {max_duplicates_raw}") if low_rms > as_int(max_low_rms_raw): - reasons.append(f"low-RMS audio windows {low_rms} > {max_low_rms_raw}") + smoothness_warnings.append(f"low-RMS audio windows {low_rms} > {max_low_rms_raw}") +if require_smoothness: + reasons.extend(smoothness_warnings) artifact = { "schema": "lesavka.server-rc-mode-result.v1", @@ -1034,6 +1199,9 @@ artifact = { "timing_map": timing_map, "passed": not reasons, "failure_reasons": reasons, + "smoothness_required": require_smoothness, + "smoothness_warnings": smoothness_warnings, + "event_visibility": event_visibility, "sync": { "passed": sync_pass, "status": verdict.get("status", "unknown"), @@ -1330,6 +1498,17 @@ for result in results: f"pair_conf_median={sync.get('paired_confidence_median', 0.0):.3f} " f"raw_pair_disagreement={sync.get('activity_pair_disagreement_ms', 0.0):+.1f}ms" ) + visibility = result.get("event_visibility") or {} + visibility_summary = visibility.get("summary") or {} + if visibility_summary: + lines.append( + " coded visibility: " + f"paired={visibility_summary.get('paired', 0)} " + f"video_only={visibility_summary.get('video_only', 0)} " + f"audio_only={visibility_summary.get('audio_only', 0)} " + f"unpaired={visibility_summary.get('unpaired', 0)} " + f"missing={visibility_summary.get('missing', 0)}" + ) if freshness.get("capture_timebase_status"): lines.append( " capture timing: " @@ -1345,6 +1524,8 @@ for result in results: ) for reason in result.get("failure_reasons") or []: lines.append(f" reason: {reason}") + for warning in result.get("smoothness_warnings") or []: + lines.append(f" smoothness warning: {warning}") if video_delay_entries or audio_delay_entries: lines.append(f"- recommended video delays: {','.join(video_delay_entries)}") lines.append(f"- recommended audio delays: {','.join(audio_delay_entries)}") @@ -1367,6 +1548,8 @@ echo " ↪ audio_delays=${LESAVKA_SERVER_RC_MODE_AUDIO_DELAYS_US}" echo " ↪ capture_stack=${REMOTE_CAPTURE_STACK} audio_source=${REMOTE_AUDIO_SOURCE} pulse_tool=${REMOTE_PULSE_CAPTURE_TOOL} video_mode=${REMOTE_PULSE_VIDEO_MODE}" echo " ↪ tune_delays=${LESAVKA_SERVER_RC_TUNE_DELAYS} confirm=${LESAVKA_SERVER_RC_TUNE_CONFIRM} min_pairs=${LESAVKA_SERVER_RC_TUNE_MIN_PAIRS} max_abs_skew_ms=${LESAVKA_SERVER_RC_TUNE_MAX_ABS_SKEW_MS} max_step_us=${LESAVKA_SERVER_RC_TUNE_MAX_STEP_US} min_change_us=${LESAVKA_SERVER_RC_TUNE_MIN_CHANGE_US}" echo " ↪ freshness_limit_ms=${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS} min_pairs=${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}" +echo " ↪ coded_pairs_min=${LESAVKA_SERVER_RC_MIN_CODED_PAIRS} require_all_coded=${LESAVKA_SERVER_RC_REQUIRE_ALL_CODED_PAIRS} smoothness_gate=${LESAVKA_SERVER_RC_REQUIRE_SMOOTHNESS_PASS}" +echo " ↪ signal_ready=${LESAVKA_SERVER_RC_SIGNAL_READY} min_pairs=${LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS} duration=${LESAVKA_SERVER_RC_SIGNAL_READY_DURATION_SECONDS}s warmup=${LESAVKA_SERVER_RC_SIGNAL_READY_WARMUP_SECONDS}s" echo " ↪ reconfigure=${LESAVKA_SERVER_RC_RECONFIGURE} strategy=${LESAVKA_SERVER_RC_RECONFIGURE_STRATEGY} allow_gadget_reset=${LESAVKA_SERVER_RC_ALLOW_GADGET_RESET}" echo " ↪ tethys_ready=${LESAVKA_SERVER_RC_WAIT_TETHYS_READY} settle=${LESAVKA_SERVER_RC_TETHYS_SETTLE_SECONDS}s timeout=${LESAVKA_SERVER_RC_TETHYS_READY_TIMEOUT_SECONDS}s preroll_discard=${LESAVKA_SERVER_RC_PREROLL_DISCARD_SECONDS}s" echo " ↪ start_delay=${LESAVKA_SERVER_RC_START_DELAY_SECONDS}s" @@ -1388,6 +1571,8 @@ for mode in "${modes[@]}"; do mode_log="${mode_dir}/mode-run.log" mode_result="${mode_dir}/mode-result.json" seed_result="${mode_dir}/mode-result-seed.json" + readiness_dir="${mode_dir}/signal-readiness" + readiness_log="${readiness_dir}/signal-readiness-run.log" tuned_log="${mode_dir}/mode-tuned-run.log" tuned_result="${mode_dir}/mode-result-tuned.json" tune_env="${mode_dir}/mode-tune-candidate.env" @@ -1397,6 +1582,55 @@ for mode in "${modes[@]}"; do reconfigure_server_mode "${mode}" "${width}" "${height}" "${fps}" wait_tethys_media_ready "${mode}" "${width}" "${height}" "${fps}" + if [[ "${LESAVKA_SERVER_RC_SIGNAL_READY}" != "0" ]]; then + mkdir -p "${readiness_dir}" + echo "==> mode ${mode}: proving Tethys signal readiness before measured probe" + run_mode_probe \ + "${width}" \ + "${height}" \ + "${fps}" \ + "${audio_delay_us}" \ + "${video_delay_us}" \ + "${readiness_dir}" \ + "${readiness_log}" \ + "${LESAVKA_SERVER_RC_SIGNAL_READY_DURATION_SECONDS}" \ + "${LESAVKA_SERVER_RC_SIGNAL_READY_WARMUP_SECONDS}" \ + "${LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS}" + readiness_status=${RUN_MODE_PROBE_STATUS} + readiness_artifact_dir="$(artifact_dir_from_log "${readiness_log}" "${readiness_dir}")" + readiness_reason="probe command exited ${readiness_status}" + if [[ "${readiness_status}" -eq 0 ]]; then + set +e + readiness_reason="$(signal_readiness_passed "${readiness_artifact_dir}" "${LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS}" 2>&1)" + readiness_pass=$? + set -e + else + readiness_pass=1 + fi + if [[ "${readiness_pass}" -ne 0 ]]; then + [[ -n "${readiness_reason}" ]] || readiness_reason="signal readiness failed" + echo " ↪ signal readiness failed: ${readiness_reason}" + write_signal_readiness_failure \ + "${mode}" \ + "${width}" \ + "${height}" \ + "${fps}" \ + "${video_delay_us}" \ + "${audio_delay_us}" \ + "${readiness_status}" \ + "${readiness_log}" \ + "${readiness_artifact_dir}" \ + "${readiness_reason}" \ + "${mode_result}" + cp "${mode_result}" "${seed_result}" + if [[ "${LESAVKA_SERVER_RC_CONTINUE_ON_FAIL}" == "0" ]]; then + break + fi + continue + fi + echo " ↪ signal readiness passed: artifact_dir=${readiness_artifact_dir}" + fi + run_mode_probe "${width}" "${height}" "${fps}" "${audio_delay_us}" "${video_delay_us}" "${mode_dir}" "${mode_log}" run_status=${RUN_MODE_PROBE_STATUS} artifact_dir="$(artifact_dir_from_log "${mode_log}" "${mode_dir}")" diff --git a/scripts/manual/run_upstream_av_sync.sh b/scripts/manual/run_upstream_av_sync.sh index 45fd7c3..d830d0e 100755 --- a/scripts/manual/run_upstream_av_sync.sh +++ b/scripts/manual/run_upstream_av_sync.sh @@ -1972,6 +1972,115 @@ first_event_timing = { "audio_pipeline_freshness_ms": first_timing_row.get("audio_freshness_ms"), "video_pipeline_freshness_ms": first_timing_row.get("video_freshness_ms"), } + + +def nearest_observation(expected_s, observations_s, tolerance_s): + if expected_s is None: + return None + best = None + for observed_s in observations_s: + observed = finite(observed_s) + if observed is None: + continue + delta_s = observed - expected_s + if abs(delta_s) > tolerance_s: + continue + if best is None or abs(delta_s) < abs(best["delta_s"]): + best = { + "time_s": observed, + "delta_ms": delta_s * 1000.0, + "delta_s": delta_s, + } + return best + + +def build_event_visibility(): + video_onsets = [value for value in (finite(v) for v in report.get("video_onsets_s") or []) if value is not None] + audio_onsets = [value for value in (finite(v) for v in report.get("audio_onsets_s") or []) if value is not None] + raw_first_video = finite(report.get("raw_first_video_activity_s")) + raw_first_audio = finite(report.get("raw_first_audio_activity_s")) + pulse_period_s = max(0.001, as_float(timeline.get("pulse_period_ms"), 1000.0) / 1000.0) + tolerance_s = max(0.20, min(0.45, pulse_period_s * 0.45)) + paired_by_server_event = { + int(row["event_id"]): row for row in joined if row.get("event_id") is not None + } + events = [] + summary = { + "paired": 0, + "unpaired": 0, + "video_only": 0, + "audio_only": 0, + "missing": 0, + } + for server in server_event_list: + event_id = as_int_or_none(server.get("event_id")) + if event_id is None: + continue + code = as_int_or_none(server.get("code")) + video_pipeline_s = corrected_capture_time_s_from_unix_ns( + shifted_unix_ns(as_int_or_none(server.get("video_feed_unix_ns")), -video_delay_ms) + ) + audio_pipeline_s = corrected_capture_time_s_from_unix_ns( + shifted_unix_ns(as_int_or_none(server.get("audio_push_unix_ns")), -audio_delay_ms) + ) + video_match = nearest_observation(video_pipeline_s, video_onsets, tolerance_s) + audio_match = nearest_observation(audio_pipeline_s, audio_onsets, tolerance_s) + raw_video_match = ( + video_match is None + and raw_first_video is not None + and video_pipeline_s is not None + and abs(raw_first_video - video_pipeline_s) <= tolerance_s + ) + raw_audio_match = ( + audio_match is None + and raw_first_audio is not None + and audio_pipeline_s is not None + and abs(raw_first_audio - audio_pipeline_s) <= tolerance_s + ) + paired = paired_by_server_event.get(event_id) + video_seen = video_match is not None or raw_video_match + audio_seen = audio_match is not None or raw_audio_match + if paired is not None: + status = "paired" + elif video_seen and audio_seen: + status = "unpaired" + elif video_seen: + status = "video_only" + elif audio_seen: + status = "audio_only" + else: + status = "missing" + summary[status] += 1 + events.append({ + "event_id": event_id, + "code": code, + "status": status, + "paired": paired is not None, + "expected_video_pipeline_s": video_pipeline_s, + "expected_audio_pipeline_s": audio_pipeline_s, + "video_seen": video_seen, + "audio_seen": audio_seen, + "video_source": "coded_onset" if video_match else ("raw_activity" if raw_video_match else None), + "audio_source": "coded_onset" if audio_match else ("raw_activity" if raw_audio_match else None), + "nearest_video_time_s": (video_match or {}).get("time_s"), + "nearest_audio_time_s": (audio_match or {}).get("time_s"), + "nearest_video_delta_ms": (video_match or {}).get("delta_ms"), + "nearest_audio_delta_ms": (audio_match or {}).get("delta_ms"), + "paired_video_time_s": paired.get("tethys_video_time_s") if paired else None, + "paired_audio_time_s": paired.get("tethys_audio_time_s") if paired else None, + "paired_skew_ms": paired.get("observed_skew_ms") if paired else None, + "confidence": paired.get("confidence") if paired else None, + }) + return { + "schema": "lesavka.coded-event-visibility.v1", + "scope": "server event slots classified against Tethys coded onsets and raw first activity", + "match_tolerance_s": tolerance_s, + "summary": summary, + "events": events, + } + + +event_visibility = build_event_visibility() timing_map = { "schema": "lesavka.output-timing-map.v1", "scope": "capture-relative map of server pipeline reference, sink handoff, and Tethys observation times", @@ -2129,6 +2238,7 @@ artifact = { "audio_event_age_model": audio_event_age_model, }, "smoothness": smoothness, + "event_visibility": event_visibility, "server_observed_correlation": server_observed_correlation, "server_drift_share_of_observed": server_share, "dominant_layer": dominant_layer, @@ -2201,6 +2311,27 @@ def fmt_number(value, unit="", precision=1): return f"{value:.{precision}f}{unit}" +visibility_summary = event_visibility.get("summary") or {} +visibility_lines = [ + "Coded event visibility", + f"- paired={visibility_summary.get('paired', 0)} unpaired={visibility_summary.get('unpaired', 0)} video_only={visibility_summary.get('video_only', 0)} audio_only={visibility_summary.get('audio_only', 0)} missing={visibility_summary.get('missing', 0)}", +] +for event in event_visibility.get("events", []): + status = event.get("status", "unknown") + if status == "paired": + detail = ( + f"skew={fmt_number(event.get('paired_skew_ms'), ' ms')} " + f"conf={fmt_number(event.get('confidence'), '', 3)}" + ) + else: + video_source = event.get("video_source") or "not_seen" + audio_source = event.get("audio_source") or "not_seen" + detail = f"video={video_source} audio={audio_source}" + visibility_lines.append( + f"- code {event.get('code')} event {event.get('event_id')}: {status} ({detail})" + ) + + lines = [ f"Output-delay correlation for {report_path}", f"- joined events: {len(joined)}", @@ -2230,6 +2361,8 @@ lines = [ f"- measured event freshness: video p95 {fmt_number(video_freshness_stats.get('p95_ms'), ' ms')}, audio p95 {fmt_number(audio_freshness_stats.get('p95_ms'), ' ms')}", f"- freshness verdict: {freshness_status} ({freshness_reason})", "", + *visibility_lines, + "", f"Output freshness for {report_path}", "- scope: clock-corrected server pipeline reference to Tethys observed playback from the same paired signatures", f"- freshness status: {freshness_status} ({freshness_reason})", diff --git a/server/Cargo.toml b/server/Cargo.toml index 15ef26c..7cb57dd 100644 --- a/server/Cargo.toml +++ b/server/Cargo.toml @@ -10,7 +10,7 @@ bench = false [package] name = "lesavka_server" -version = "0.19.24" +version = "0.19.25" edition = "2024" autobins = false diff --git a/testing/tests/client_manual_sync_script_contract.rs b/testing/tests/client_manual_sync_script_contract.rs index ebaf834..3e66570 100644 --- a/testing/tests/client_manual_sync_script_contract.rs +++ b/testing/tests/client_manual_sync_script_contract.rs @@ -194,6 +194,10 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() { "fetching capture from ${TETHYS_HOST}", "warning: failed to fetch capture artifact; continuing with remote analysis JSON when available", "analysis_tmp=\"${LOCAL_ANALYSIS_JSON}.tmp\"", + "event_visibility", + "Coded event visibility", + "video_only", + "audio_only", "REMOTE_PULSE_AUDIO_ANCHOR_SILENCE=${REMOTE_PULSE_AUDIO_ANCHOR_SILENCE:-1}", "anchoring Pulse capture audio timeline with generated silence", "audiotestsrc wave=silence is-live=true do-timestamp=true", @@ -411,6 +415,18 @@ fn server_rc_mode_matrix_validates_advertised_uvc_profiles() { "timed out waiting for Tethys Lesavka media endpoints", "LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS=${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS:-350}", "LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS=${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS:-${LESAVKA_SERVER_RC_TUNE_MIN_PAIRS}}", + "LESAVKA_SERVER_RC_MIN_CODED_PAIRS=${LESAVKA_SERVER_RC_MIN_CODED_PAIRS:-${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}}", + "LESAVKA_SERVER_RC_REQUIRE_ALL_CODED_PAIRS=${LESAVKA_SERVER_RC_REQUIRE_ALL_CODED_PAIRS:-0}", + "LESAVKA_SERVER_RC_REQUIRE_SMOOTHNESS_PASS=${LESAVKA_SERVER_RC_REQUIRE_SMOOTHNESS_PASS:-0}", + "LESAVKA_SERVER_RC_SIGNAL_READY=${LESAVKA_SERVER_RC_SIGNAL_READY:-1}", + "LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS=${LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS:-3}", + "signal_readiness_passed", + "proving Tethys signal readiness before measured probe", + "signal readiness did not pass", + "smoothness_required", + "smoothness_warnings", + "smoothness warning:", + "coded visibility:", "LESAVKA_SERVER_RC_MAX_VIDEO_HICCUPS=${LESAVKA_SERVER_RC_MAX_VIDEO_HICCUPS:-0}", "LESAVKA_SERVER_RC_MAX_AUDIO_HICCUPS=${LESAVKA_SERVER_RC_MAX_AUDIO_HICCUPS:-0}", "LESAVKA_SERVER_RC_MAX_VIDEO_MISSING_FRAMES=${LESAVKA_SERVER_RC_MAX_VIDEO_MISSING_FRAMES:-12}", @@ -455,7 +471,7 @@ fn server_rc_mode_matrix_validates_advertised_uvc_profiles() { "LESAVKA_OUTPUT_DELAY_SAVE=0", "LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS=\"${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS}\"", "LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=\"${LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS}\"", - "LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS=\"${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}\"", + "LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS=\"${min_pairs}\"", "sync did not pass", "freshness did not pass", "video hiccups",