From 9c81ab51d3fe36c962673b22231319d99695ba11 Mon Sep 17 00:00:00 2001 From: Brad Stein Date: Tue, 5 May 2026 21:01:05 -0300 Subject: [PATCH] test(server-rc): condition signals before measured capture --- Cargo.lock | 6 +- client/Cargo.toml | 2 +- common/Cargo.toml | 2 +- .../manual/run_server_to_rc_mode_matrix.sh | 54 ++++++- scripts/manual/run_upstream_av_sync.sh | 134 +++++++++++++----- server/Cargo.toml | 2 +- .../client_manual_sync_script_contract.rs | 20 ++- 7 files changed, 178 insertions(+), 42 deletions(-) diff --git a/Cargo.lock b/Cargo.lock index 4de1d2a..f69ceb2 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1652,7 +1652,7 @@ checksum = "09edd9e8b54e49e587e4f6295a7d29c3ea94d469cb40ab8ca70b288248a81db2" [[package]] name = "lesavka_client" -version = "0.19.26" +version = "0.19.27" dependencies = [ "anyhow", "async-stream", @@ -1686,7 +1686,7 @@ dependencies = [ [[package]] name = "lesavka_common" -version = "0.19.26" +version = "0.19.27" dependencies = [ "anyhow", "base64", @@ -1698,7 +1698,7 @@ dependencies = [ [[package]] name = "lesavka_server" -version = "0.19.26" +version = "0.19.27" dependencies = [ "anyhow", "base64", diff --git a/client/Cargo.toml b/client/Cargo.toml index 422bce1..56e1944 100644 --- a/client/Cargo.toml +++ b/client/Cargo.toml @@ -4,7 +4,7 @@ path = "src/main.rs" [package] name = "lesavka_client" -version = "0.19.26" +version = "0.19.27" edition = "2024" [dependencies] diff --git a/common/Cargo.toml b/common/Cargo.toml index a2186ff..6228cf6 100644 --- a/common/Cargo.toml +++ b/common/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "lesavka_common" -version = "0.19.26" +version = "0.19.27" 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 77daf95..fa3c31c 100755 --- a/scripts/manual/run_server_to_rc_mode_matrix.sh +++ b/scripts/manual/run_server_to_rc_mode_matrix.sh @@ -77,11 +77,17 @@ LESAVKA_SERVER_RC_MIN_CODED_PAIRS=${LESAVKA_SERVER_RC_MIN_CODED_PAIRS:-${LESAVKA 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_MODE=${LESAVKA_SERVER_RC_SIGNAL_READY_MODE:-conditioned_capture} 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:-12} LESAVKA_SERVER_RC_SIGNAL_READY_WARMUP_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_READY_WARMUP_SECONDS:-1} LESAVKA_SERVER_RC_SIGNAL_READY_ATTEMPTS=${LESAVKA_SERVER_RC_SIGNAL_READY_ATTEMPTS:-4} LESAVKA_SERVER_RC_SIGNAL_READY_RETRY_DELAY_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_READY_RETRY_DELAY_SECONDS:-5} +LESAVKA_SERVER_RC_SIGNAL_CONDITION_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_SECONDS:-12} +LESAVKA_SERVER_RC_SIGNAL_CONDITION_WARMUP_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_WARMUP_SECONDS:-1} +LESAVKA_SERVER_RC_SIGNAL_CONDITION_GAP_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_GAP_SECONDS:-1} +LESAVKA_SERVER_RC_SIGNAL_CONDITION_EVENT_WIDTH_CODES=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_EVENT_WIDTH_CODES:-${PROBE_EVENT_WIDTH_CODES:-1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16}} +LESAVKA_SERVER_RC_ANALYSIS_TIMELINE_WINDOW=${LESAVKA_SERVER_RC_ANALYSIS_TIMELINE_WINDOW:-auto} 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} @@ -175,6 +181,18 @@ run_mode_probe() { 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}} + local conditioning_seconds=${11:-${LESAVKA_SERVER_RC_SIGNAL_CONDITION_SECONDS}} + local analysis_timeline_window=${LESAVKA_SERVER_RC_ANALYSIS_TIMELINE_WINDOW} + if [[ "${LESAVKA_SERVER_RC_SIGNAL_READY}" == "0" ]]; then + conditioning_seconds=0 + fi + if [[ "${analysis_timeline_window}" == "auto" ]]; then + if [[ "${conditioning_seconds}" =~ ^[0-9]+$ && "${conditioning_seconds}" -gt 0 ]]; then + analysis_timeline_window=1 + else + analysis_timeline_window=0 + fi + fi set +e TETHYS_HOST="${TETHYS_HOST}" \ @@ -212,8 +230,13 @@ run_mode_probe() { LESAVKA_OUTPUT_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS="${LESAVKA_SERVER_RC_FRESHNESS_MAX_CLOCK_UNCERTAINTY_MS}" \ LESAVKA_OUTPUT_FRESHNESS_MIN_PAIRS="${min_pairs}" \ PROBE_EVENT_WIDTH_CODES="${PROBE_EVENT_WIDTH_CODES}" \ + PROBE_CONDITIONING_SECONDS="${conditioning_seconds}" \ + PROBE_CONDITIONING_WARMUP_SECONDS="${LESAVKA_SERVER_RC_SIGNAL_CONDITION_WARMUP_SECONDS}" \ + PROBE_CONDITIONING_GAP_SECONDS="${LESAVKA_SERVER_RC_SIGNAL_CONDITION_GAP_SECONDS}" \ + PROBE_CONDITIONING_EVENT_WIDTH_CODES="${LESAVKA_SERVER_RC_SIGNAL_CONDITION_EVENT_WIDTH_CODES}" \ PROBE_DURATION_SECONDS="${probe_duration_seconds}" \ PROBE_WARMUP_SECONDS="${probe_warmup_seconds}" \ + ANALYSIS_TIMELINE_WINDOW="${analysis_timeline_window}" \ LOCAL_OUTPUT_DIR="${output_dir}" \ "${SCRIPT_DIR}/run_upstream_av_sync.sh" 2>&1 | tee "${log_path}" RUN_MODE_PROBE_STATUS=${PIPESTATUS[0]} @@ -434,6 +457,9 @@ report = load_json(artifact_dir / "report.json") timeline = load_json(artifact_dir / "server-output-timeline.json") error_log = artifact_dir / "analysis-error.log" error_text = read_text(error_log) +if not error_text: + error_log = artifact_dir / "analysis-error.log.tmp" + error_text = read_text(error_log) if not error_text: error_text = read_text(run_log) @@ -474,6 +500,22 @@ if failure_match: raw_activity_delta_ms = as_float(failure_match.group("delta")) analyzer_failure = failure_match.group(0) +pairs_match = re.search( + r"need at least\s+(?P\d+)\s+matching coded pulse pairs;\s+" + r"saw\s+(?P\d+);\s+raw activity delta was\s+" + r"(?P[+-]?\d+(?:\.\d+)?)\s+ms\s+" + r"\(video=(?P\d+(?:\.\d+)?)s\s+audio=(?P\d+(?:\.\d+)?)s\)", + error_text, +) +if pairs_match: + paired_from_error = as_int(pairs_match.group("paired")) + paired_events = max(paired_events, paired_from_error) + coded_pairs = max(coded_pairs, paired_from_error) + video_events = max(video_events, paired_from_error) + audio_events = max(audio_events, paired_from_error) + raw_activity_delta_ms = as_float(pairs_match.group("delta")) + analyzer_failure = pairs_match.group(0) + sync_passed = verdict.get("passed") is True paired_ready = paired_events >= min_pairs or coded_pairs >= min_pairs video_ready = video_events >= min_pairs @@ -1802,7 +1844,8 @@ echo " ↪ capture_stack=${REMOTE_CAPTURE_STACK} audio_source=${REMOTE_AUDIO_S 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} attempts=${LESAVKA_SERVER_RC_SIGNAL_READY_ATTEMPTS} 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 retry_delay=${LESAVKA_SERVER_RC_SIGNAL_READY_RETRY_DELAY_SECONDS}s" +echo " ↪ signal_ready=${LESAVKA_SERVER_RC_SIGNAL_READY} mode=${LESAVKA_SERVER_RC_SIGNAL_READY_MODE} attempts=${LESAVKA_SERVER_RC_SIGNAL_READY_ATTEMPTS} 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 retry_delay=${LESAVKA_SERVER_RC_SIGNAL_READY_RETRY_DELAY_SECONDS}s" +echo " ↪ signal_conditioning=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_SECONDS}s warmup=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_WARMUP_SECONDS}s gap=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_GAP_SECONDS}s analysis_window=${LESAVKA_SERVER_RC_ANALYSIS_TIMELINE_WINDOW}" 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" @@ -1836,7 +1879,11 @@ 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 + if [[ "${LESAVKA_SERVER_RC_SIGNAL_READY}" != "0" && "${LESAVKA_SERVER_RC_SIGNAL_READY_MODE}" != "separate" ]]; then + echo "==> mode ${mode}: using same-capture signal conditioning before measured probe" + fi + + if [[ "${LESAVKA_SERVER_RC_SIGNAL_READY}" != "0" && "${LESAVKA_SERVER_RC_SIGNAL_READY_MODE}" == "separate" ]]; then mkdir -p "${readiness_dir}" echo "==> mode ${mode}: proving Tethys signal readiness before measured probe" readiness_pass=1 @@ -1860,7 +1907,8 @@ for mode in "${modes[@]}"; do "${readiness_log}" \ "${LESAVKA_SERVER_RC_SIGNAL_READY_DURATION_SECONDS}" \ "${LESAVKA_SERVER_RC_SIGNAL_READY_WARMUP_SECONDS}" \ - "${LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS}" + "${LESAVKA_SERVER_RC_SIGNAL_READY_MIN_PAIRS}" \ + 0 readiness_status=${RUN_MODE_PROBE_STATUS} readiness_artifact_dir="$(artifact_dir_from_log "${readiness_log}" "${attempt_dir}")" set +e diff --git a/scripts/manual/run_upstream_av_sync.sh b/scripts/manual/run_upstream_av_sync.sh index 12cea82..4c28054 100755 --- a/scripts/manual/run_upstream_av_sync.sh +++ b/scripts/manual/run_upstream_av_sync.sh @@ -24,6 +24,11 @@ PROBE_TIMEOUT_SECONDS=${PROBE_TIMEOUT_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE PROBE_PULSE_PERIOD_MS=${PROBE_PULSE_PERIOD_MS:-1000} PROBE_PULSE_WIDTH_MS=${PROBE_PULSE_WIDTH_MS:-120} PROBE_EVENT_WIDTH_CODES=${PROBE_EVENT_WIDTH_CODES:-1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16} +PROBE_CONDITIONING_SECONDS=${PROBE_CONDITIONING_SECONDS:-0} +PROBE_CONDITIONING_WARMUP_SECONDS=${PROBE_CONDITIONING_WARMUP_SECONDS:-1} +PROBE_CONDITIONING_GAP_SECONDS=${PROBE_CONDITIONING_GAP_SECONDS:-1} +PROBE_CONDITIONING_EVENT_WIDTH_CODES=${PROBE_CONDITIONING_EVENT_WIDTH_CODES:-${PROBE_EVENT_WIDTH_CODES}} +PROBE_CONDITIONING_TIMEOUT_SECONDS=${PROBE_CONDITIONING_TIMEOUT_SECONDS:-$((PROBE_CONDITIONING_SECONDS + PROBE_CONDITIONING_WARMUP_SECONDS + PROBE_START_GRACE_SECONDS))} LESAVKA_OUTPUT_DELAY_PROBE_AUDIO_DELAY_US=${LESAVKA_OUTPUT_DELAY_PROBE_AUDIO_DELAY_US:-0} LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US=${LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US:-0} # Do not open the UVC host capture far ahead of the probe. The gadget side only @@ -32,7 +37,8 @@ LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US=${LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DEL LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-0} TAIL_SECONDS=${TAIL_SECONDS:-2} 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))} +CONDITIONING_CAPTURE_SECONDS=$((PROBE_CONDITIONING_SECONDS > 0 ? PROBE_CONDITIONING_SECONDS + PROBE_CONDITIONING_WARMUP_SECONDS + PROBE_CONDITIONING_GAP_SECONDS : 0)) +CAPTURE_SECONDS=${CAPTURE_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + CONDITIONING_CAPTURE_SECONDS + CAPTURE_START_GRACE_SECONDS + LEAD_IN_SECONDS + TAIL_SECONDS))} LOCAL_OUTPUT_DIR=${LOCAL_OUTPUT_DIR:-/tmp} REMOTE_VIDEO_DEVICE=${REMOTE_VIDEO_DEVICE:-auto} VIDEO_SIZE=${VIDEO_SIZE:-auto} @@ -95,6 +101,8 @@ LOCAL_REPORT_TXT="${LOCAL_REPORT_DIR}/report.txt" LOCAL_EVENTS_CSV="${LOCAL_REPORT_DIR}/events.csv" LOCAL_SERVER_PROBE_REPLY="${LOCAL_REPORT_DIR}/server-output-probe-reply.txt" LOCAL_SERVER_TIMELINE_JSON="${LOCAL_REPORT_DIR}/server-output-timeline.json" +LOCAL_SIGNAL_CONDITIONING_REPLY="${LOCAL_REPORT_DIR}/signal-conditioning-probe-reply.txt" +LOCAL_SIGNAL_CONDITIONING_TIMELINE_JSON="${LOCAL_REPORT_DIR}/signal-conditioning-timeline.json" LOCAL_OUTPUT_DELAY_CORRELATION_JSON="${LOCAL_REPORT_DIR}/output-delay-correlation.json" LOCAL_OUTPUT_DELAY_CORRELATION_CSV="${LOCAL_REPORT_DIR}/output-delay-correlation.csv" LOCAL_OUTPUT_DELAY_CORRELATION_TXT="${LOCAL_REPORT_DIR}/output-delay-correlation.txt" @@ -911,10 +919,12 @@ with pathlib.Path(output_env_path).open("w") as handle: PY } -extract_server_timeline() { - [[ -f "${LOCAL_SERVER_PROBE_REPLY}" ]] || return 0 +extract_timeline_from_reply() { + local reply_path=$1 + local timeline_path=$2 + [[ -f "${reply_path}" ]] || return 0 - python3 - <<'PY' "${LOCAL_SERVER_PROBE_REPLY}" "${LOCAL_SERVER_TIMELINE_JSON}" + python3 - <<'PY' "${reply_path}" "${timeline_path}" import json import pathlib import sys @@ -933,6 +943,14 @@ timeline_path.write_text(json.dumps(timeline, indent=2, sort_keys=True) + "\n") PY } +extract_server_timeline() { + extract_timeline_from_reply "${LOCAL_SERVER_PROBE_REPLY}" "${LOCAL_SERVER_TIMELINE_JSON}" +} + +extract_signal_conditioning_timeline() { + extract_timeline_from_reply "${LOCAL_SIGNAL_CONDITIONING_REPLY}" "${LOCAL_SIGNAL_CONDITIONING_TIMELINE_JSON}" +} + compute_analysis_window_arg() { [[ "${ANALYSIS_TIMELINE_WINDOW}" != "0" ]] || return 0 [[ -f "${LOCAL_SERVER_TIMELINE_JSON}" ]] || return 0 @@ -3268,27 +3286,77 @@ wait_for_capture_ready sleep "${LEAD_IN_SECONDS}" +run_output_delay_probe() { + local label=$1 + local duration_seconds=$2 + local warmup_seconds=$3 + local event_width_codes=$4 + local audio_delay_us=$5 + local video_delay_us=$6 + local timeout_seconds=$7 + local reply_path=$8 + + set +e + ( + cd "${REPO_ROOT}" + LESAVKA_TLS_DOMAIN="${LESAVKA_TLS_DOMAIN}" \ + timeout --signal=INT "${timeout_seconds}" \ + "${REPO_ROOT}/target/debug/lesavka-relayctl" \ + --server "${RESOLVED_LESAVKA_SERVER_ADDR}" \ + output-delay-probe \ + "${duration_seconds}" \ + "${warmup_seconds}" \ + "${PROBE_PULSE_PERIOD_MS}" \ + "${PROBE_PULSE_WIDTH_MS}" \ + "${event_width_codes}" \ + "${audio_delay_us}" \ + "${video_delay_us}" + ) 2>&1 | tee "${reply_path}" + local status=${PIPESTATUS[0]} + set -e + if [[ "${status}" -eq 124 ]]; then + printf '%s output-delay probe timed out after %ss\n' "${label}" "${timeout_seconds}" >&2 + fi + return "${status}" +} + +conditioning_status=0 +conditioning_timed_out=0 +if [[ "${PROBE_CONDITIONING_SECONDS}" =~ ^[0-9]+$ && "${PROBE_CONDITIONING_SECONDS}" -gt 0 ]]; then + echo "==> conditioning Tethys UVC/UAC signal path before measured probe" + echo " ↪ conditioning duration=${PROBE_CONDITIONING_SECONDS}s warmup=${PROBE_CONDITIONING_WARMUP_SECONDS}s gap=${PROBE_CONDITIONING_GAP_SECONDS}s" + run_output_delay_probe \ + "signal-conditioning" \ + "${PROBE_CONDITIONING_SECONDS}" \ + "${PROBE_CONDITIONING_WARMUP_SECONDS}" \ + "${PROBE_CONDITIONING_EVENT_WIDTH_CODES}" \ + "${LESAVKA_OUTPUT_DELAY_PROBE_AUDIO_DELAY_US}" \ + "${LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US}" \ + "${PROBE_CONDITIONING_TIMEOUT_SECONDS}" \ + "${LOCAL_SIGNAL_CONDITIONING_REPLY}" || conditioning_status=$? + if [[ "${conditioning_status}" -eq 124 ]]; then + conditioning_timed_out=1 + fi + extract_signal_conditioning_timeline + if [[ "${conditioning_status}" -ne 0 ]]; then + echo "signal-conditioning output-delay probe failed with status ${conditioning_status}" >&2 + exit "${conditioning_status}" + fi + sleep "${PROBE_CONDITIONING_GAP_SECONDS}" +fi + echo "==> running server-generated UVC/UAC output-delay probe against ${RESOLVED_LESAVKA_SERVER_ADDR}" probe_status=0 probe_timed_out=0 -set +e -( - cd "${REPO_ROOT}" - LESAVKA_TLS_DOMAIN="${LESAVKA_TLS_DOMAIN}" \ - timeout --signal=INT "${PROBE_TIMEOUT_SECONDS}" \ - "${REPO_ROOT}/target/debug/lesavka-relayctl" \ - --server "${RESOLVED_LESAVKA_SERVER_ADDR}" \ - output-delay-probe \ - "${PROBE_DURATION_SECONDS}" \ - "${PROBE_WARMUP_SECONDS}" \ - "${PROBE_PULSE_PERIOD_MS}" \ - "${PROBE_PULSE_WIDTH_MS}" \ - "${PROBE_EVENT_WIDTH_CODES}" \ - "${LESAVKA_OUTPUT_DELAY_PROBE_AUDIO_DELAY_US}" \ - "${LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US}" -) 2>&1 | tee "${LOCAL_SERVER_PROBE_REPLY}" -probe_status=${PIPESTATUS[0]} -set -e +run_output_delay_probe \ + "server" \ + "${PROBE_DURATION_SECONDS}" \ + "${PROBE_WARMUP_SECONDS}" \ + "${PROBE_EVENT_WIDTH_CODES}" \ + "${LESAVKA_OUTPUT_DELAY_PROBE_AUDIO_DELAY_US}" \ + "${LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US}" \ + "${PROBE_TIMEOUT_SECONDS}" \ + "${LOCAL_SERVER_PROBE_REPLY}" || probe_status=$? if [[ "${probe_status}" -eq 124 ]]; then probe_timed_out=1 fi @@ -3360,20 +3428,16 @@ REMOTE_NORMALIZE_SCRIPT run_remote_sync_analysis_once "${analysis_tmp}" "${analysis_error_tmp}" analysis_status=$? set -e + if [[ -s "${analysis_error_tmp}" ]]; then + cp "${analysis_error_tmp}" "${LOCAL_ANALYSIS_ERROR_LOG}" + fi if [[ "${analysis_status}" -eq 0 ]]; then mv "${analysis_tmp}" "${LOCAL_ANALYSIS_JSON}" - if [[ -s "${analysis_error_tmp}" ]]; then - mv "${analysis_error_tmp}" "${LOCAL_ANALYSIS_ERROR_LOG}" - else - rm -f "${analysis_error_tmp}" - fi + rm -f "${analysis_error_tmp}" else rm -f "${analysis_tmp}" - if [[ -s "${analysis_error_tmp}" ]]; then - mv "${analysis_error_tmp}" "${LOCAL_ANALYSIS_ERROR_LOG}" - else - rm -f "${analysis_error_tmp}" - fi + # Keep the .tmp copy too. If this script exits on analysis failure, the + # readiness summarizer can still parse whichever error artifact survived. fi fi @@ -3531,6 +3595,12 @@ fi if [[ -f "${LOCAL_SERVER_TIMELINE_JSON}" ]]; then echo "server_timeline_json: ${LOCAL_SERVER_TIMELINE_JSON}" fi +if [[ -f "${LOCAL_SIGNAL_CONDITIONING_REPLY}" ]]; then + echo "signal_conditioning_reply: ${LOCAL_SIGNAL_CONDITIONING_REPLY}" +fi +if [[ -f "${LOCAL_SIGNAL_CONDITIONING_TIMELINE_JSON}" ]]; then + echo "signal_conditioning_timeline_json: ${LOCAL_SIGNAL_CONDITIONING_TIMELINE_JSON}" +fi if [[ -f "${LOCAL_CLOCK_ALIGNMENT_JSON}" ]]; then echo "clock_alignment_json: ${LOCAL_CLOCK_ALIGNMENT_JSON}" fi diff --git a/server/Cargo.toml b/server/Cargo.toml index 323c6d8..196ecf5 100644 --- a/server/Cargo.toml +++ b/server/Cargo.toml @@ -10,7 +10,7 @@ bench = false [package] name = "lesavka_server" -version = "0.19.26" +version = "0.19.27" 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 7a2cc18..807b054 100644 --- a/testing/tests/client_manual_sync_script_contract.rs +++ b/testing/tests/client_manual_sync_script_contract.rs @@ -37,6 +37,8 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() { "LOCAL_EVENTS_CSV=\"${LOCAL_REPORT_DIR}/events.csv\"", "LOCAL_SERVER_PROBE_REPLY=\"${LOCAL_REPORT_DIR}/server-output-probe-reply.txt\"", "LOCAL_SERVER_TIMELINE_JSON=\"${LOCAL_REPORT_DIR}/server-output-timeline.json\"", + "LOCAL_SIGNAL_CONDITIONING_REPLY=\"${LOCAL_REPORT_DIR}/signal-conditioning-probe-reply.txt\"", + "LOCAL_SIGNAL_CONDITIONING_TIMELINE_JSON=\"${LOCAL_REPORT_DIR}/signal-conditioning-timeline.json\"", "LOCAL_OUTPUT_DELAY_CORRELATION_JSON=\"${LOCAL_REPORT_DIR}/output-delay-correlation.json\"", "LOCAL_OUTPUT_DELAY_CORRELATION_CSV=\"${LOCAL_REPORT_DIR}/output-delay-correlation.csv\"", "LOCAL_OUTPUT_DELAY_CORRELATION_TXT=\"${LOCAL_REPORT_DIR}/output-delay-correlation.txt\"", @@ -85,10 +87,15 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() { "server-to-capture-persistent-ssh-python", "LESAVKA_OUTPUT_DELAY_PROBE_AUDIO_DELAY_US=${LESAVKA_OUTPUT_DELAY_PROBE_AUDIO_DELAY_US:-0}", "LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US=${LESAVKA_OUTPUT_DELAY_PROBE_VIDEO_DELAY_US:-0}", + "PROBE_CONDITIONING_SECONDS=${PROBE_CONDITIONING_SECONDS:-0}", + "PROBE_CONDITIONING_WARMUP_SECONDS=${PROBE_CONDITIONING_WARMUP_SECONDS:-1}", + "PROBE_CONDITIONING_GAP_SECONDS=${PROBE_CONDITIONING_GAP_SECONDS:-1}", "write_clock_alignment", "capture_start_unix_ns=", "write_output_delay_calibration", + "extract_timeline_from_reply", "extract_server_timeline", + "extract_signal_conditioning_timeline", "write_output_delay_correlation", "maybe_apply_output_delay_calibration", "maybe_run_output_delay_confirmation", @@ -212,10 +219,15 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() { "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))}", "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))}", + "CONDITIONING_CAPTURE_SECONDS=$((PROBE_CONDITIONING_SECONDS > 0 ? PROBE_CONDITIONING_SECONDS + PROBE_CONDITIONING_WARMUP_SECONDS + PROBE_CONDITIONING_GAP_SECONDS : 0))", + "CAPTURE_SECONDS=${CAPTURE_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + CONDITIONING_CAPTURE_SECONDS + CAPTURE_START_GRACE_SECONDS + LEAD_IN_SECONDS + TAIL_SECONDS))}", "ANALYSIS_TIMELINE_WINDOW=${ANALYSIS_TIMELINE_WINDOW:-0}", "compute_analysis_window_arg", "analyzer timeline window:", + "run_output_delay_probe", + "conditioning Tethys UVC/UAC signal path before measured probe", + "signal_conditioning_reply: ${LOCAL_SIGNAL_CONDITIONING_REPLY}", + "signal_conditioning_timeline_json: ${LOCAL_SIGNAL_CONDITIONING_TIMELINE_JSON}", "output-delay-probe", "server-generated UVC/UAC output-delay probe", "server output-delay probe timed out after ${PROBE_TIMEOUT_SECONDS}s", @@ -422,15 +434,21 @@ fn server_rc_mode_matrix_validates_advertised_uvc_profiles() { "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_MODE=${LESAVKA_SERVER_RC_SIGNAL_READY_MODE:-conditioned_capture}", "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:-12}", "LESAVKA_SERVER_RC_SIGNAL_READY_ATTEMPTS=${LESAVKA_SERVER_RC_SIGNAL_READY_ATTEMPTS:-4}", "LESAVKA_SERVER_RC_SIGNAL_READY_RETRY_DELAY_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_READY_RETRY_DELAY_SECONDS:-5}", + "LESAVKA_SERVER_RC_SIGNAL_CONDITION_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_SECONDS:-12}", + "LESAVKA_SERVER_RC_SIGNAL_CONDITION_WARMUP_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_WARMUP_SECONDS:-1}", + "LESAVKA_SERVER_RC_SIGNAL_CONDITION_GAP_SECONDS=${LESAVKA_SERVER_RC_SIGNAL_CONDITION_GAP_SECONDS:-1}", + "LESAVKA_SERVER_RC_ANALYSIS_TIMELINE_WINDOW=${LESAVKA_SERVER_RC_ANALYSIS_TIMELINE_WINDOW:-auto}", "signal_readiness_passed", "write_signal_readiness_attempt_result", "write_signal_readiness_attempts_summary", "schema\": \"lesavka.server-rc-signal-readiness-attempt.v1\"", "schema\": \"lesavka.server-rc-signal-readiness-summary.v1\"", + "using same-capture signal conditioning before measured probe", "proving Tethys signal readiness before measured probe", "readiness attempt ${readiness_attempt}/${LESAVKA_SERVER_RC_SIGNAL_READY_ATTEMPTS}", "waiting ${LESAVKA_SERVER_RC_SIGNAL_READY_RETRY_DELAY_SECONDS}s before retrying signal readiness",