test(server-rc): make freshness event based

This commit is contained in:
Brad Stein 2026-05-04 20:22:57 -03:00
parent b4587970b4
commit 61228a6c9b
3 changed files with 197 additions and 13 deletions

View File

@ -69,6 +69,7 @@ LESAVKA_SERVER_RC_TUNE_MIN_CHANGE_US=${LESAVKA_SERVER_RC_TUNE_MIN_CHANGE_US:-500
LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS=${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS:-350} LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS=${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS:-350}
LESAVKA_SERVER_RC_FRESHNESS_MAX_DRIFT_MS=${LESAVKA_SERVER_RC_FRESHNESS_MAX_DRIFT_MS:-100} LESAVKA_SERVER_RC_FRESHNESS_MAX_DRIFT_MS=${LESAVKA_SERVER_RC_FRESHNESS_MAX_DRIFT_MS:-100}
LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=${LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS:-250} LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=${LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS:-250}
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_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_REQUIRE_SYNC_PASS=${LESAVKA_SERVER_RC_REQUIRE_SYNC_PASS:-1}
@ -196,6 +197,7 @@ run_mode_probe() {
LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS="${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS}" \ 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_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_MAX_CLOCK_UNCERTAINTY_MS="${LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS}" \
LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS="${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}" \
PROBE_EVENT_WIDTH_CODES="${PROBE_EVENT_WIDTH_CODES}" \ PROBE_EVENT_WIDTH_CODES="${PROBE_EVENT_WIDTH_CODES}" \
PROBE_DURATION_SECONDS="${PROBE_DURATION_SECONDS}" \ PROBE_DURATION_SECONDS="${PROBE_DURATION_SECONDS}" \
PROBE_WARMUP_SECONDS="${PROBE_WARMUP_SECONDS}" \ PROBE_WARMUP_SECONDS="${PROBE_WARMUP_SECONDS}" \
@ -1352,7 +1354,7 @@ echo " ↪ video_delays=${LESAVKA_SERVER_RC_MODE_DELAYS_US}"
echo " ↪ audio_delays=${LESAVKA_SERVER_RC_MODE_AUDIO_DELAYS_US}" 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 " ↪ 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 " ↪ 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}" echo " ↪ freshness_limit_ms=${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS} min_pairs=${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}"
echo " ↪ reconfigure=${LESAVKA_SERVER_RC_RECONFIGURE} strategy=${LESAVKA_SERVER_RC_RECONFIGURE_STRATEGY} allow_gadget_reset=${LESAVKA_SERVER_RC_ALLOW_GADGET_RESET}" 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 " ↪ 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 " ↪ artifact_dir=${MATRIX_REPORT_DIR}" echo " ↪ artifact_dir=${MATRIX_REPORT_DIR}"

View File

@ -31,7 +31,8 @@ LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US=${LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DEL
# VIDIOC_STREAMON if the camera is starved during pre-roll. # VIDIOC_STREAMON if the camera is starved during pre-roll.
LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-0} LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-0}
TAIL_SECONDS=${TAIL_SECONDS:-2} TAIL_SECONDS=${TAIL_SECONDS:-2}
CAPTURE_SECONDS=${CAPTURE_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + PROBE_START_GRACE_SECONDS + LEAD_IN_SECONDS + TAIL_SECONDS))} CAPTURE_START_GRACE_SECONDS=${CAPTURE_START_GRACE_SECONDS:-12}
CAPTURE_SECONDS=${CAPTURE_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + CAPTURE_START_GRACE_SECONDS + LEAD_IN_SECONDS + TAIL_SECONDS))}
LOCAL_OUTPUT_DIR=${LOCAL_OUTPUT_DIR:-/tmp} LOCAL_OUTPUT_DIR=${LOCAL_OUTPUT_DIR:-/tmp}
REMOTE_VIDEO_DEVICE=${REMOTE_VIDEO_DEVICE:-auto} REMOTE_VIDEO_DEVICE=${REMOTE_VIDEO_DEVICE:-auto}
VIDEO_SIZE=${VIDEO_SIZE:-auto} VIDEO_SIZE=${VIDEO_SIZE:-auto}
@ -78,6 +79,7 @@ LESAVKA_OUTPUT_DELAY_MAX_STEP_US=${LESAVKA_OUTPUT_DELAY_MAX_STEP_US:-1500000}
LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS:-1000} LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS:-1000}
LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS:-100} LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS:-100}
LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS:-250} LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS:-250}
LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS=${LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS:-${LESAVKA_OUTPUT_DELAY_MIN_PAIRS}}
LESAVKA_CLOCK_ALIGNMENT_SAMPLES=${LESAVKA_CLOCK_ALIGNMENT_SAMPLES:-5} LESAVKA_CLOCK_ALIGNMENT_SAMPLES=${LESAVKA_CLOCK_ALIGNMENT_SAMPLES:-5}
CAPTURE_READY_MARKER="__LESAVKA_CAPTURE_READY__" CAPTURE_READY_MARKER="__LESAVKA_CAPTURE_READY__"
@ -988,7 +990,10 @@ write_output_delay_correlation() {
"${LOCAL_CLOCK_ALIGNMENT_JSON}" \ "${LOCAL_CLOCK_ALIGNMENT_JSON}" \
"${LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS}" \ "${LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS}" \
"${LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS}" \ "${LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS}" \
"${LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS}" "${LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS}" \
"${LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS}" \
"${CAPTURE_SECONDS}" \
"${CAPTURE_START_GRACE_SECONDS}"
import csv import csv
import json import json
import math import math
@ -1010,6 +1015,9 @@ import sys
max_freshness_age_raw, max_freshness_age_raw,
max_freshness_drift_raw, max_freshness_drift_raw,
max_clock_uncertainty_raw, max_clock_uncertainty_raw,
min_freshness_pairs_raw,
capture_seconds_raw,
capture_start_grace_seconds_raw,
) = sys.argv[1:] ) = sys.argv[1:]
report = json.loads(pathlib.Path(report_path).read_text()) report = json.loads(pathlib.Path(report_path).read_text())
timeline = json.loads(pathlib.Path(timeline_path).read_text()) timeline = json.loads(pathlib.Path(timeline_path).read_text())
@ -1777,6 +1785,9 @@ correction_mode = (
max_freshness_age_ms = max(1.0, as_float(max_freshness_age_raw, 1000.0)) max_freshness_age_ms = max(1.0, as_float(max_freshness_age_raw, 1000.0))
max_freshness_drift_ms = max(0.0, as_float(max_freshness_drift_raw, 100.0)) max_freshness_drift_ms = max(0.0, as_float(max_freshness_drift_raw, 100.0))
max_clock_uncertainty_ms = max(0.0, as_float(max_clock_uncertainty_raw, 100.0)) max_clock_uncertainty_ms = max(0.0, as_float(max_clock_uncertainty_raw, 100.0))
min_freshness_pairs = max(1, as_int_or_none(min_freshness_pairs_raw) or 1)
configured_capture_duration_s = as_float(capture_seconds_raw, 0.0)
capture_start_grace_s = as_float(capture_start_grace_seconds_raw, 0.0)
freshness_p95_values = [ freshness_p95_values = [
value value
for value in [ for value in [
@ -1820,6 +1831,17 @@ event_age_min_values = [
freshness_min_event_age_ms = min(event_age_min_values) if event_age_min_values else None freshness_min_event_age_ms = min(event_age_min_values) if event_age_min_values else None
smoothness = analyze_smoothness(capture_path, report, timeline) smoothness = analyze_smoothness(capture_path, report, timeline)
media_timeline = smoothness.get("media_timeline") or {} media_timeline = smoothness.get("media_timeline") or {}
observed_capture_duration_values = [
value
for value in [
finite(media_timeline.get("video_last_s")),
finite(media_timeline.get("audio_last_s")),
]
if value is not None
]
observed_capture_duration_s = (
max(observed_capture_duration_values) if observed_capture_duration_values else None
)
def negative_rows(rows, key, limit_ms): def negative_rows(rows, key, limit_ms):
@ -1832,11 +1854,36 @@ def negative_rows(rows, key, limit_ms):
] ]
def non_monotonic_rows(rows, key):
bad = []
previous = None
for row in rows:
value = finite(row.get(key))
if value is None:
continue
if previous is not None and value + 1e-9 < previous:
bad.append(row)
previous = value
return bad
video_negative_rows = negative_rows(joined, "video_freshness_ms", clock_uncertainty_ms) video_negative_rows = negative_rows(joined, "video_freshness_ms", clock_uncertainty_ms)
audio_negative_rows = negative_rows(joined, "audio_freshness_ms", clock_uncertainty_ms) audio_negative_rows = negative_rows(joined, "audio_freshness_ms", clock_uncertainty_ms)
monotonic_checks = {
"server video pipeline": non_monotonic_rows(joined, "server_video_pipeline_unix_ns"),
"server audio pipeline": non_monotonic_rows(joined, "server_audio_pipeline_unix_ns"),
"Tethys video observation": non_monotonic_rows(joined, "tethys_video_time_s"),
"Tethys audio observation": non_monotonic_rows(joined, "tethys_audio_time_s"),
}
non_monotonic_labels = [
f"{label} ({len(rows)} reversal{'s' if len(rows) != 1 else ''})"
for label, rows in monotonic_checks.items()
if rows
]
capture_timebase_status = "valid" capture_timebase_status = "valid"
capture_timebase_reason = "Tethys observation timestamps are monotonic against server pipeline references" capture_timebase_reason = "Tethys observation timestamps are monotonic against server pipeline references"
capture_timebase_reasons = [] capture_timebase_reasons = []
capture_timebase_warnings = []
if not joined: if not joined:
capture_timebase_status = "unknown" capture_timebase_status = "unknown"
capture_timebase_reason = "no joined coded events are available" capture_timebase_reason = "no joined coded events are available"
@ -1853,14 +1900,18 @@ elif video_negative_rows or audio_negative_rows:
capture_timebase_reasons.append( capture_timebase_reasons.append(
f"audio observed before server pipeline injection {len(audio_negative_rows)} time(s)" f"audio observed before server pipeline injection {len(audio_negative_rows)} time(s)"
) )
if non_monotonic_labels:
capture_timebase_status = "invalid"
capture_timebase_reasons.append(
"non-monotonic event timestamps: " + ", ".join(non_monotonic_labels)
)
span_gap_s = finite(media_timeline.get("audio_video_span_gap_s")) span_gap_s = finite(media_timeline.get("audio_video_span_gap_s"))
if span_gap_s is not None and abs(span_gap_s) > 1.0: if span_gap_s is not None and abs(span_gap_s) > 1.0:
relation = "shorter" if span_gap_s > 0 else "longer" relation = "shorter" if span_gap_s > 0 else "longer"
capture_timebase_status = "invalid" capture_timebase_warnings.append(
capture_timebase_reasons.append(
f"captured audio stream is {abs(span_gap_s):.3f}s {relation} than video; " f"captured audio stream is {abs(span_gap_s):.3f}s {relation} than video; "
"the recording cannot place audio events on the video capture timeline" "treating whole-file media span as recorder coverage, not event freshness"
) )
if capture_timebase_reasons: if capture_timebase_reasons:
capture_timebase_reason = "; ".join(capture_timebase_reasons) capture_timebase_reason = "; ".join(capture_timebase_reasons)
@ -1911,18 +1962,30 @@ timing_map = {
), ),
"probe_warmup_ms": as_float(timeline.get("warmup_us"), 0.0) / 1000.0, "probe_warmup_ms": as_float(timeline.get("warmup_us"), 0.0) / 1000.0,
"probe_duration_ms": as_float(timeline.get("duration_us"), 0.0) / 1000.0, "probe_duration_ms": as_float(timeline.get("duration_us"), 0.0) / 1000.0,
"active_probe_media_ms": (
as_float(timeline.get("warmup_us"), 0.0) + as_float(timeline.get("duration_us"), 0.0)
) / 1000.0,
"configured_capture_duration_s": configured_capture_duration_s,
"observed_capture_duration_s": observed_capture_duration_s,
"capture_start_grace_s": capture_start_grace_s,
"intentional_audio_delay_ms": audio_delay_ms, "intentional_audio_delay_ms": audio_delay_ms,
"intentional_video_delay_ms": video_delay_ms, "intentional_video_delay_ms": video_delay_ms,
"first_event": first_event_timing, "first_event": first_event_timing,
} }
if not event_age_p95_values: if not event_age_p95_values:
freshness_status = "unknown" freshness_status = "invalid"
freshness_reason = "clock-aligned server feed and Tethys capture timestamps were not available" freshness_reason = "clock-aligned server pipeline references and Tethys observations were not available"
elif not clock_alignment_available or clock_uncertainty_ms > max_clock_uncertainty_ms: elif len(joined) < min_freshness_pairs:
freshness_status = "unknown" freshness_status = "invalid"
freshness_reason = ( freshness_reason = (
f"clock uncertainty {clock_uncertainty_ms:.1f} ms exceeds " f"paired coded events {len(joined)} < {min_freshness_pairs}; "
f"{max_clock_uncertainty_ms:.1f} ms freshness measurement limit" "freshness requires enough matched injected/observed events"
)
elif not clock_alignment_available or clock_uncertainty_ms > max_clock_uncertainty_ms:
freshness_status = "invalid"
freshness_reason = (
"server/capture clock alignment unavailable or too uncertain: "
f"{clock_uncertainty_ms:.1f} ms exceeds {max_clock_uncertainty_ms:.1f} ms limit"
) )
elif capture_timebase_status == "invalid": elif capture_timebase_status == "invalid":
freshness_status = "invalid" freshness_status = "invalid"
@ -1987,14 +2050,18 @@ artifact = {
"status": capture_timebase_status, "status": capture_timebase_status,
"reason": capture_timebase_reason, "reason": capture_timebase_reason,
"valid": capture_timebase_status == "valid", "valid": capture_timebase_status == "valid",
"warnings": capture_timebase_warnings,
"video_observed_before_injection_count": len(video_negative_rows), "video_observed_before_injection_count": len(video_negative_rows),
"audio_observed_before_injection_count": len(audio_negative_rows), "audio_observed_before_injection_count": len(audio_negative_rows),
"non_monotonic_event_timestamps": non_monotonic_labels,
}, },
"clock_alignment": clock_alignment, "clock_alignment": clock_alignment,
"clock_uncertainty_ms": clock_uncertainty_ms, "clock_uncertainty_ms": clock_uncertainty_ms,
"max_age_limit_ms": max_freshness_age_ms, "max_age_limit_ms": max_freshness_age_ms,
"max_drift_limit_ms": max_freshness_drift_ms, "max_drift_limit_ms": max_freshness_drift_ms,
"max_clock_uncertainty_ms": max_clock_uncertainty_ms, "max_clock_uncertainty_ms": max_clock_uncertainty_ms,
"min_paired_events": min_freshness_pairs,
"paired_event_count": len(joined),
"intentional_audio_delay_ms": audio_delay_ms, "intentional_audio_delay_ms": audio_delay_ms,
"intentional_video_delay_ms": video_delay_ms, "intentional_video_delay_ms": video_delay_ms,
"worst_p95_sink_handoff_overhead_ms": max( "worst_p95_sink_handoff_overhead_ms": max(
@ -2124,10 +2191,18 @@ lines = [
f"- first event Tethys observation: audio {fmt_number(first_event_timing.get('tethys_audio_observed_s'), 's', 3)}, video {fmt_number(first_event_timing.get('tethys_video_observed_s'), 's', 3)}", f"- first event Tethys observation: audio {fmt_number(first_event_timing.get('tethys_audio_observed_s'), 's', 3)}, video {fmt_number(first_event_timing.get('tethys_video_observed_s'), 's', 3)}",
f"- first event pipeline freshness: audio {fmt_number(first_event_timing.get('audio_pipeline_freshness_ms'), ' ms')}, video {fmt_number(first_event_timing.get('video_pipeline_freshness_ms'), ' ms')}", f"- first event pipeline freshness: audio {fmt_number(first_event_timing.get('audio_pipeline_freshness_ms'), ' ms')}, video {fmt_number(first_event_timing.get('video_pipeline_freshness_ms'), ' ms')}",
"", "",
"Freshness timeline",
f"- capture duration: {fmt_number(observed_capture_duration_s if observed_capture_duration_s is not None else configured_capture_duration_s, 's', 3)} (recorder coverage, not media latency; configured {fmt_number(configured_capture_duration_s, 's', 3)})",
f"- active probe media: {fmt_number(timing_map.get('active_probe_media_ms'), ' ms')} (warmup + coded events)",
f"- setup before probe: {fmt_number(timing_map.get('capture_to_server_start_ms'), ' ms')} (capture readiness/tunnel/probe startup, not media latency)",
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})",
"",
f"Output freshness for {report_path}", f"Output freshness for {report_path}",
"- scope: clock-corrected server pipeline reference to Tethys observed playback from the same paired signatures", "- scope: clock-corrected server pipeline reference to Tethys observed playback from the same paired signatures",
f"- freshness status: {freshness_status} ({freshness_reason})", f"- freshness status: {freshness_status} ({freshness_reason})",
f"- capture timebase: {capture_timebase_status} ({capture_timebase_reason})", f"- capture timebase: {capture_timebase_status} ({capture_timebase_reason})",
*[f"- capture timebase warning: {warning}" for warning in capture_timebase_warnings],
f"- clock uncertainty: +/-{clock_uncertainty_ms:.1f} ms", f"- clock uncertainty: +/-{clock_uncertainty_ms:.1f} ms",
f"- intentional sync delays: audio {audio_delay_ms:+.1f} ms, video {video_delay_ms:+.1f} ms", f"- intentional sync delays: audio {audio_delay_ms:+.1f} ms, video {video_delay_ms:+.1f} ms",
f"- sink handoff overhead: video median {fmt_number(video_sink_handoff_stats.get('median_ms'), ' ms')} / p95 {fmt_number(video_sink_handoff_stats.get('p95_ms'), ' ms')} / max {fmt_number(video_sink_handoff_stats.get('max_ms'), ' ms')}; audio median {fmt_number(audio_sink_handoff_stats.get('median_ms'), ' ms')} / p95 {fmt_number(audio_sink_handoff_stats.get('p95_ms'), ' ms')} / max {fmt_number(audio_sink_handoff_stats.get('max_ms'), ' ms')}", f"- sink handoff overhead: video median {fmt_number(video_sink_handoff_stats.get('median_ms'), ' ms')} / p95 {fmt_number(video_sink_handoff_stats.get('p95_ms'), ' ms')} / max {fmt_number(video_sink_handoff_stats.get('max_ms'), ' ms')}; audio median {fmt_number(audio_sink_handoff_stats.get('median_ms'), ' ms')} / p95 {fmt_number(audio_sink_handoff_stats.get('p95_ms'), ' ms')} / max {fmt_number(audio_sink_handoff_stats.get('max_ms'), ' ms')}",

View File

@ -56,6 +56,7 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() {
"LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS:-1000}", "LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS:-1000}",
"LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS:-100}", "LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_DRIFT_MS:-100}",
"LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS:-250}", "LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS=${LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS:-250}",
"LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS=${LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS:-${LESAVKA_OUTPUT_DELAY_MIN_PAIRS}}",
"REMOTE_CAPTURE_PREROLL_DISCARD_SECONDS=${REMOTE_CAPTURE_PREROLL_DISCARD_SECONDS:-0}", "REMOTE_CAPTURE_PREROLL_DISCARD_SECONDS=${REMOTE_CAPTURE_PREROLL_DISCARD_SECONDS:-0}",
"REMOTE_CAPTURE_READY_SETTLE_SECONDS=${REMOTE_CAPTURE_READY_SETTLE_SECONDS:-1}", "REMOTE_CAPTURE_READY_SETTLE_SECONDS=${REMOTE_CAPTURE_READY_SETTLE_SECONDS:-1}",
"remote_capture_ready_settle_seconds=${15}", "remote_capture_ready_settle_seconds=${15}",
@ -111,9 +112,21 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() {
"clock-corrected server pipeline reference to Tethys observed playback", "clock-corrected server pipeline reference to Tethys observed playback",
"capture timebase", "capture timebase",
"capture timebase invalid", "capture timebase invalid",
"capture_timebase_warnings = []",
"capture timebase warning",
"treating whole-file media span as recorder coverage, not event freshness",
"intentional sync delays", "intentional sync delays",
"sink handoff overhead", "sink handoff overhead",
"pipeline freshness", "pipeline freshness",
"Freshness timeline",
"capture duration",
"observed_capture_duration_s",
"configured_capture_duration_s",
"recorder coverage, not media latency",
"active probe media",
"setup before probe",
"measured event freshness",
"freshness verdict",
"freshness budget", "freshness budget",
"Output smoothness", "Output smoothness",
"capture media timeline", "capture media timeline",
@ -131,6 +144,9 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() {
"minimum_pipeline_freshness_ms", "minimum_pipeline_freshness_ms",
"worst_event_age_with_uncertainty_ms", "worst_event_age_with_uncertainty_ms",
"minimum_event_age_ms", "minimum_event_age_ms",
"min_paired_events",
"paired_event_count",
"non_monotonic_event_timestamps",
"sync_passed", "sync_passed",
"sync did not pass, so freshness from paired signatures is not trustworthy", "sync did not pass, so freshness from paired signatures is not trustworthy",
"impossible negative pipeline freshness", "impossible negative pipeline freshness",
@ -178,7 +194,8 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() {
"LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-0}", "LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-0}",
"PROBE_START_GRACE_SECONDS=${PROBE_START_GRACE_SECONDS:-20}", "PROBE_START_GRACE_SECONDS=${PROBE_START_GRACE_SECONDS:-20}",
"PROBE_TIMEOUT_SECONDS=${PROBE_TIMEOUT_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + PROBE_START_GRACE_SECONDS))}", "PROBE_TIMEOUT_SECONDS=${PROBE_TIMEOUT_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + PROBE_START_GRACE_SECONDS))}",
"CAPTURE_SECONDS=${CAPTURE_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + PROBE_START_GRACE_SECONDS + LEAD_IN_SECONDS + TAIL_SECONDS))}", "CAPTURE_START_GRACE_SECONDS=${CAPTURE_START_GRACE_SECONDS:-12}",
"CAPTURE_SECONDS=${CAPTURE_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + CAPTURE_START_GRACE_SECONDS + LEAD_IN_SECONDS + TAIL_SECONDS))}",
"ANALYSIS_TIMELINE_WINDOW=${ANALYSIS_TIMELINE_WINDOW:-0}", "ANALYSIS_TIMELINE_WINDOW=${ANALYSIS_TIMELINE_WINDOW:-0}",
"compute_analysis_window_arg", "compute_analysis_window_arg",
"analyzer timeline window:", "analyzer timeline window:",
@ -237,6 +254,94 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() {
} }
} }
#[test]
fn output_freshness_is_event_level_not_capture_container_duration() {
for expected in [
"\"freshness_clock_starts_at\": \"server pipeline reference before intentional sync delay\"",
"video_freshness_ms = (",
"audio_freshness_ms = (",
"\"video_freshness_stats\": video_freshness_stats",
"\"audio_freshness_stats\": audio_freshness_stats",
"\"worst_p95_pipeline_freshness_ms\": freshness_worst_p95_ms",
"\"worst_event_age_with_uncertainty_ms\": freshness_worst_event_with_uncertainty_ms",
"\"configured_capture_duration_s\": configured_capture_duration_s",
"\"observed_capture_duration_s\": observed_capture_duration_s",
"\"min_paired_events\": min_freshness_pairs",
"\"paired_event_count\": len(joined)",
"\"warnings\": capture_timebase_warnings",
"treating whole-file media span as recorder coverage, not event freshness",
"Freshness timeline",
"measured event freshness",
] {
assert!(
SYNC_SCRIPT.contains(expected),
"freshness contract should contain event-level timing marker {expected}"
);
}
let span_gap_start = SYNC_SCRIPT
.find("span_gap_s = finite(media_timeline.get(\"audio_video_span_gap_s\"))")
.expect("manual sync script should compute media span gap diagnostics");
let span_gap_end = SYNC_SCRIPT[span_gap_start..]
.find("if capture_timebase_reasons:")
.map(|offset| span_gap_start + offset)
.expect("span gap diagnostic block should end before reason folding");
let span_gap_block = &SYNC_SCRIPT[span_gap_start..span_gap_end];
assert!(
span_gap_block.contains("capture_timebase_warnings.append("),
"whole-file media span mismatch should be recorded as a warning"
);
assert!(
!span_gap_block.contains("capture_timebase_status = \"invalid\""),
"whole-file media span mismatch must not invalidate freshness; freshness is event-level"
);
assert!(
!span_gap_block.contains("capture_timebase_reasons.append("),
"whole-file media span mismatch must not become a hard invalidation reason"
);
}
#[test]
fn output_freshness_still_invalidates_real_event_timing_contradictions() {
let negative_rows_start = SYNC_SCRIPT
.find("elif video_negative_rows or audio_negative_rows:")
.expect("manual sync script should detect observed-before-injection rows");
let negative_rows_end = SYNC_SCRIPT[negative_rows_start..]
.find("span_gap_s = finite")
.map(|offset| negative_rows_start + offset)
.expect("negative-row invalidation should precede span diagnostics");
let negative_rows_block = &SYNC_SCRIPT[negative_rows_start..negative_rows_end];
for expected in [
"capture_timebase_status = \"invalid\"",
"video observed before server pipeline injection",
"audio observed before server pipeline injection",
"capture_timebase_reasons.append(",
] {
assert!(
negative_rows_block.contains(expected),
"real event timing contradictions must remain hard failures: {expected}"
);
}
for expected in [
"elif capture_timebase_status == \"invalid\":",
"freshness_reason = f\"capture timebase invalid: {capture_timebase_reason}\"",
"paired coded events {len(joined)} < {min_freshness_pairs}",
"freshness requires enough matched injected/observed events",
"server/capture clock alignment unavailable or too uncertain",
"non-monotonic event timestamps",
"minimum freshness",
"freshness was negative beyond clock uncertainty",
] {
assert!(
SYNC_SCRIPT.contains(expected),
"freshness should still fail on impossible event timing: {expected}"
);
}
}
#[test] #[test]
fn server_rc_mode_matrix_validates_advertised_uvc_profiles() { fn server_rc_mode_matrix_validates_advertised_uvc_profiles() {
for expected in [ for expected in [
@ -289,6 +394,7 @@ fn server_rc_mode_matrix_validates_advertised_uvc_profiles() {
"Tethys media ready: video=%s mode=%s audio_stack=%s", "Tethys media ready: video=%s mode=%s audio_stack=%s",
"timed out waiting for Tethys Lesavka media endpoints", "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_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_MAX_VIDEO_HICCUPS=${LESAVKA_SERVER_RC_MAX_VIDEO_HICCUPS:-0}", "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_AUDIO_HICCUPS=${LESAVKA_SERVER_RC_MAX_AUDIO_HICCUPS:-0}",
"LESAVKA_SERVER_RC_MAX_VIDEO_MISSING_FRAMES=${LESAVKA_SERVER_RC_MAX_VIDEO_MISSING_FRAMES:-12}", "LESAVKA_SERVER_RC_MAX_VIDEO_MISSING_FRAMES=${LESAVKA_SERVER_RC_MAX_VIDEO_MISSING_FRAMES:-12}",
@ -333,6 +439,7 @@ fn server_rc_mode_matrix_validates_advertised_uvc_profiles() {
"LESAVKA_OUTPUT_DELAY_SAVE=0", "LESAVKA_OUTPUT_DELAY_SAVE=0",
"LESAVKA_OUTPUT_FRESHNESS_MAX_AGE_MS=\"${LESAVKA_SERVER_RC_FRESHNESS_MAX_AGE_MS}\"", "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_MAX_CLOCK_UNCERTAINTY_MS=\"${LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS}\"",
"LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS=\"${LESAVKA_SERVER_RC_FRESHNESS_MIN_PAIRS}\"",
"sync did not pass", "sync did not pass",
"freshness did not pass", "freshness did not pass",
"video hiccups", "video hiccups",