diff --git a/Cargo.lock b/Cargo.lock index e8cb121..ae22958 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -1642,7 +1642,7 @@ checksum = "09edd9e8b54e49e587e4f6295a7d29c3ea94d469cb40ab8ca70b288248a81db2" [[package]] name = "lesavka_client" -version = "0.14.41" +version = "0.14.42" dependencies = [ "anyhow", "async-stream", @@ -1676,7 +1676,7 @@ dependencies = [ [[package]] name = "lesavka_common" -version = "0.14.41" +version = "0.14.42" dependencies = [ "anyhow", "base64", @@ -1688,7 +1688,7 @@ dependencies = [ [[package]] name = "lesavka_server" -version = "0.14.41" +version = "0.14.42" dependencies = [ "anyhow", "base64", diff --git a/client/Cargo.toml b/client/Cargo.toml index 8101de5..27cb5b0 100644 --- a/client/Cargo.toml +++ b/client/Cargo.toml @@ -4,7 +4,7 @@ path = "src/main.rs" [package] name = "lesavka_client" -version = "0.14.41" +version = "0.14.42" edition = "2024" [dependencies] diff --git a/common/Cargo.toml b/common/Cargo.toml index bc820e4..dfc00a8 100644 --- a/common/Cargo.toml +++ b/common/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "lesavka_common" -version = "0.14.41" +version = "0.14.42" edition = "2024" build = "build.rs" diff --git a/scripts/daemon/lesavka-core.sh b/scripts/daemon/lesavka-core.sh index b736d11..aeb12a6 100755 --- a/scripts/daemon/lesavka-core.sh +++ b/scripts/daemon/lesavka-core.sh @@ -9,10 +9,22 @@ log() { printf '[lesavka-core] %s\n' "$*"; } G=/sys/kernel/config/usb_gadget/lesavka -if [[ -r /etc/lesavka/uvc.env ]]; then - # shellcheck disable=SC1091 - source /etc/lesavka/uvc.env -fi +load_uvc_env_defaults() { + local env_file=/etc/lesavka/uvc.env + [[ -r $env_file ]] || return 0 + local line key value + while IFS= read -r line || [[ -n $line ]]; do + [[ $line =~ ^[[:space:]]*# || -z $line ]] && continue + [[ $line == *=* ]] || continue + key=${line%%=*} + value=${line#*=} + [[ $key =~ ^[A-Za-z_][A-Za-z0-9_]*$ ]] || continue + [[ -z ${!key+x} ]] || continue + export "$key=$value" + done <"$env_file" +} + +load_uvc_env_defaults find_udc() { ls /sys/class/udc 2>/dev/null | head -n1 || true @@ -505,19 +517,7 @@ EOF fi popd >/dev/null - streaming_class_speeds=(fs) - control_class_speeds=(fs) - case "$MAX_SPEED" in - super-speed|super-speed-plus) - streaming_class_speeds+=(hs ss) - control_class_speeds+=(ss) - ;; - high-speed) - streaming_class_speeds+=(hs) - ;; - esac - - for s in "${streaming_class_speeds[@]}"; do + for s in fs hs ss; do mkdir -p "$F/streaming/class/$s" pushd "$F/streaming/class/$s" >/dev/null ln -s ../../header/h h @@ -526,12 +526,11 @@ EOF # ── 4. Video‑Control interface ───────────────────────────────────── mkdir -p "$F/control/header/h" - # The kernel UVC gadget docs make the control-speed links optional; only - # advertise the descriptor sets that match the configured gadget speed. + # The kernel UVC gadget docs require direct symlinks at control/class/fs and + # control/class/ss. High-speed control descriptors are not exposed here. pushd "$F/control" >/dev/null - for s in "${control_class_speeds[@]}"; do - ln -s header/h "class/$s" 2>/dev/null || true - done + ln -s header/h class/fs 2>/dev/null || true + ln -s header/h class/ss 2>/dev/null || true popd >/dev/null if [[ -n $UVC_DISABLE_IRQ ]]; then diff --git a/scripts/daemon/lesavka-uvc.sh b/scripts/daemon/lesavka-uvc.sh index 4363b6d..20cabcd 100755 --- a/scripts/daemon/lesavka-uvc.sh +++ b/scripts/daemon/lesavka-uvc.sh @@ -2,11 +2,24 @@ # scripts/daemon/lesavka-uvc.sh - launch UVC control helper as a standalone service set -euo pipefail -# Optional env file for runtime overrides (debug, width/fps, etc.) -if [[ -r /etc/lesavka/uvc.env ]]; then - # shellcheck disable=SC1091 - source /etc/lesavka/uvc.env -fi +# Optional env file for runtime defaults (debug, width/fps, etc.). Explicit +# environment from a recovery shell wins so bench overrides are not masked. +load_uvc_env_defaults() { + local env_file=/etc/lesavka/uvc.env + [[ -r $env_file ]] || return 0 + local line key value + while IFS= read -r line || [[ -n $line ]]; do + [[ $line =~ ^[[:space:]]*# || -z $line ]] && continue + [[ $line == *=* ]] || continue + key=${line%%=*} + value=${line#*=} + [[ $key =~ ^[A-Za-z_][A-Za-z0-9_]*$ ]] || continue + [[ -z ${!key+x} ]] || continue + export "$key=$value" + done <"$env_file" +} + +load_uvc_env_defaults resolve_default_uvc_dev() { local ctrl="" diff --git a/scripts/install/server.sh b/scripts/install/server.sh index 9f816cf..6d17b84 100755 --- a/scripts/install/server.sh +++ b/scripts/install/server.sh @@ -829,7 +829,8 @@ echo "==> 6b. Systemd units - lesavka-server" cat <<'UNIT' | sudo tee /etc/systemd/system/lesavka-server.service >/dev/null [Unit] Description=lesavka gRPC relay -After=network.target lesavka-core.service +After=network.target lesavka-core.service lesavka-uvc.service +Wants=lesavka-uvc.service StartLimitIntervalSec=30 StartLimitBurst=10 @@ -850,11 +851,12 @@ Environment=LESAVKA_EYE_FPS=20 Environment=LESAVKA_MIC_INIT_ATTEMPTS=5 Environment=LESAVKA_MIC_INIT_DELAY_MS=250 Environment=LESAVKA_ALLOW_GADGET_CYCLE=1 +Environment=LESAVKA_SERVER_LOG_PATH=/var/log/lesavka/server.log EnvironmentFile=-/etc/lesavka/uvc.env EnvironmentFile=-/etc/lesavka/server.env Restart=always RestartSec=5 -StandardError=append:/tmp/lesavka-server.stderr +StandardError=append:/var/log/lesavka/server.stderr User=root [Install] @@ -862,7 +864,9 @@ WantedBy=multi-user.target UNIT echo "==> 6c. Systemd units - initialization" -sudo truncate -s 0 /tmp/lesavka-server.log +sudo install -d -m 0755 /var/log/lesavka +sudo rm -f /tmp/lesavka-server.log +sudo truncate -s 0 /var/log/lesavka/server.log sudo systemctl daemon-reload sudo systemctl enable lesavka-core lesavka-server @@ -878,6 +882,8 @@ if [[ "$UVC_ENV_CHANGED" == "1" ]] && is_attached_state "$UDC_STATE"; then fi if [[ -n ${LESAVKA_ALLOW_GADGET_RESET:-} ]] || [[ "$FORCE_GADGET_REBUILD" == "1" ]] || ! is_attached_state "$UDC_STATE"; then echo "⚠️ UDC state is '$UDC_STATE' - forcing a Lesavka gadget rebuild before server start." + sudo systemctl stop lesavka-uvc >/dev/null 2>&1 || true + sudo systemctl reset-failed lesavka-uvc >/dev/null 2>&1 || true sudo env \ LESAVKA_ALLOW_GADGET_RESET=1 \ LESAVKA_ATTACH_WRITE_UDC=1 \ @@ -906,7 +912,7 @@ RestartSec=2 KillSignal=SIGTERM KillMode=control-group TimeoutStopSec=10 -StandardError=append:/tmp/lesavka-uvc.stderr +StandardError=append:/var/log/lesavka/uvc.stderr User=root EnvironmentFile=-/etc/lesavka/uvc.env @@ -934,12 +940,14 @@ if [[ "$UVC_ENV_CHANGED" == "1" ]] && systemctl is-active --quiet lesavka-uvc; t elif systemctl is-active --quiet lesavka-uvc; then echo "✅ lesavka-uvc already active; runtime settings unchanged." else - echo "⚠️ lesavka-uvc is not active; start via lesavka-core dependency path." + sudo truncate -s 0 /var/log/lesavka/uvc.stderr + sudo systemctl start lesavka-uvc + echo "✅ lesavka-uvc started to attach the UVC gadget to the host." fi validate_uvc_gadget_ready -sudo truncate -s 0 /tmp/lesavka-server.stderr +sudo truncate -s 0 /var/log/lesavka/server.stderr sudo systemctl stop lesavka-server >/dev/null 2>&1 || true clear_stale_server_listener sudo systemctl reset-failed lesavka-server >/dev/null 2>&1 || true diff --git a/scripts/manual/run_upstream_av_sync.sh b/scripts/manual/run_upstream_av_sync.sh index 8055b79..f90bbf9 100755 --- a/scripts/manual/run_upstream_av_sync.sh +++ b/scripts/manual/run_upstream_av_sync.sh @@ -15,7 +15,10 @@ LESAVKA_SERVER_CONNECT_HOST=${LESAVKA_SERVER_CONNECT_HOST:-38.28.125.112} LESAVKA_SERVER_ADDR=${LESAVKA_SERVER_ADDR:-auto} PROBE_DURATION_SECONDS=${PROBE_DURATION_SECONDS:-10} PROBE_WARMUP_SECONDS=${PROBE_WARMUP_SECONDS:-4} -LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-8} +# Do not open the UVC host capture far ahead of the probe. The gadget side only +# has frames once the sync probe is feeding the server, and some hosts time out +# VIDIOC_STREAMON if the camera is starved during pre-roll. +LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-0} TAIL_SECONDS=${TAIL_SECONDS:-2} CAPTURE_SECONDS=${CAPTURE_SECONDS:-$((PROBE_DURATION_SECONDS + PROBE_WARMUP_SECONDS + LEAD_IN_SECONDS + TAIL_SECONDS))} REMOTE_CAPTURE=${REMOTE_CAPTURE:-/tmp/lesavka-upstream-av-sync.mkv} @@ -773,6 +776,11 @@ if [[ -f "${LOCAL_CAPTURE_LOG}" ]] \ && grep -q 'VIDIOC_QBUF): Bad file descriptor' "${LOCAL_CAPTURE_LOG}"; then capture_v4l2_fault=1 fi +capture_streamon_timeout=0 +if [[ -f "${LOCAL_CAPTURE_LOG}" ]] \ + && grep -q 'VIDIOC_STREAMON.*Connection timed out' "${LOCAL_CAPTURE_LOG}"; then + capture_streamon_timeout=1 +fi if ssh ${SSH_OPTS} "${TETHYS_HOST}" "test -f '${REMOTE_CAPTURE}'"; then remote_fetch_capture="${REMOTE_CAPTURE}" @@ -826,6 +834,10 @@ if [[ "${probe_status}" -ne 0 ]]; then exit "${probe_status}" fi if [[ "${capture_status}" -ne 0 ]]; then + if [[ "${capture_streamon_timeout}" -eq 1 ]]; then + echo "Tethys capture timed out during VIDIOC_STREAMON; the UVC host opened before MJPEG frames reached the gadget." >&2 + echo "Keep LEAD_IN_SECONDS=0 and restart lesavka-uvc/lesavka-server before retrying if the gadget is wedged from an earlier failed run." >&2 + fi if [[ "${capture_status}" -eq 141 && ( -f "${LOCAL_CAPTURE}" || -f "${LOCAL_ANALYSIS_JSON}" ) ]]; then echo "Tethys capture ended with PipeWire SIGPIPE after ffmpeg closed; accepting preserved analysis artifacts" >&2 elif [[ "${capture_status}" -eq 124 && ( -f "${LOCAL_CAPTURE}" || -f "${LOCAL_ANALYSIS_JSON}" ) ]]; then diff --git a/server/Cargo.toml b/server/Cargo.toml index c40975d..382e392 100644 --- a/server/Cargo.toml +++ b/server/Cargo.toml @@ -10,7 +10,7 @@ bench = false [package] name = "lesavka_server" -version = "0.14.41" +version = "0.14.42" edition = "2024" autobins = false diff --git a/server/src/runtime_support/hid_recovery.rs b/server/src/runtime_support/hid_recovery.rs index 9909283..04183d4 100644 --- a/server/src/runtime_support/hid_recovery.rs +++ b/server/src/runtime_support/hid_recovery.rs @@ -29,32 +29,66 @@ pub fn init_tracing() -> anyhow::Result { #[cfg(not(coverage))] pub fn init_tracing() -> anyhow::Result { - let file = std::fs::OpenOptions::new() - .create(true) - .truncate(true) - .write(true) - .open("/tmp/lesavka-server.log")?; - let (file_writer, guard) = tracing_appender::non_blocking(file); - let env_filter = EnvFilter::try_from_default_env() .unwrap_or_else(|_| EnvFilter::new("lesavka_server=info,lesavka_server::video=warn")); let filter_str = env_filter.to_string(); + let file = open_server_log_file(); + let log_open_error = file.as_ref().err().map(ToString::to_string); + let (file_writer, guard) = match file { + Ok(file) => { + let (writer, guard) = tracing_appender::non_blocking(file); + (Some(writer), guard) + } + Err(_) => { + let (_writer, guard) = tracing_appender::non_blocking(std::io::sink()); + (None, guard) + } + }; - tracing_subscriber::registry() + let registry = tracing_subscriber::registry() .with(env_filter) - .with(fmt::layer().with_target(true).with_thread_ids(true)) - .with( - fmt::layer() - .with_writer(file_writer) - .with_ansi(false) - .with_target(true) - .with_level(true), - ) - .init(); + .with(fmt::layer().with_target(true).with_thread_ids(true)); + if let Some(file_writer) = file_writer { + registry + .with( + fmt::layer() + .with_writer(file_writer) + .with_ansi(false) + .with_target(true) + .with_level(true), + ) + .init(); + } else { + registry.init(); + } tracing::info!("📜 effective RUST_LOG = \"{}\"", filter_str); + if let Some(error) = log_open_error { + tracing::warn!("file logging disabled: {error}"); + } Ok(guard) } +#[cfg(not(coverage))] +fn open_server_log_file() -> std::io::Result { + let preferred = std::env::var("LESAVKA_SERVER_LOG_PATH") + .unwrap_or_else(|_| "/var/log/lesavka/server.log".to_string()); + for path in [preferred.as_str(), "/tmp/lesavka-server.log"] { + match std::fs::OpenOptions::new() + .create(true) + .truncate(true) + .write(true) + .open(path) + { + Ok(file) => return Ok(file), + Err(error) if path != "/tmp/lesavka-server.log" => { + eprintln!("lesavka-server: failed to open {path}: {error}; trying /tmp fallback"); + } + Err(error) => return Err(error), + } + } + unreachable!("static log path list is non-empty") +} + /// Open a HID gadget endpoint with bounded retry logic. /// /// Inputs: the path of the gadget device node to open. diff --git a/testing/tests/client_manual_sync_script_contract.rs b/testing/tests/client_manual_sync_script_contract.rs index f5dc56f..c83b833 100644 --- a/testing/tests/client_manual_sync_script_contract.rs +++ b/testing/tests/client_manual_sync_script_contract.rs @@ -19,6 +19,9 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() { "RESOLVED_LESAVKA_SERVER_ADDR=\"http://127.0.0.1:${SERVER_TUNNEL_LOCAL_PORT}\"", "tunneled to ${LESAVKA_SERVER_HOST}:127.0.0.1:${SERVER_TUNNEL_REMOTE_PORT}", "CAPTURE_READY_MARKER=\"__LESAVKA_CAPTURE_READY__\"", + "LEAD_IN_SECONDS=${LEAD_IN_SECONDS:-0}", + "VIDIOC_STREAMON.*Connection timed out", + "the UVC host opened before MJPEG frames reached the gadget", "Tethys capture failed before the sync probe could start", "wait_for_capture_ready", "Timed out waiting for Tethys capture to become ready", @@ -34,7 +37,9 @@ fn upstream_sync_script_tunnels_auto_server_addr_through_ssh() { ); } assert!( - !SYNC_SCRIPT.contains("RESOLVED_LESAVKA_SERVER_ADDR=\"http://${LESAVKA_SERVER_CONNECT_HOST}:${port}\""), + !SYNC_SCRIPT.contains( + "RESOLVED_LESAVKA_SERVER_ADDR=\"http://${LESAVKA_SERVER_CONNECT_HOST}:${port}\"" + ), "auto server resolution should not guess a public gRPC host when SSH is already required" ); } diff --git a/testing/tests/server_core_script_contract.rs b/testing/tests/server_core_script_contract.rs index edf130f..6edbed6 100644 --- a/testing/tests/server_core_script_contract.rs +++ b/testing/tests/server_core_script_contract.rs @@ -43,9 +43,8 @@ fn core_script_skips_soft_connect_for_dwc2() { fn core_script_uses_kernel_doc_control_header_links() { for expected in [ "pushd \"$F/control\" >/dev/null", - "ln -s header/h \"class/$s\"", - "control_class_speeds=(fs)", - "for s in \"${control_class_speeds[@]}\"; do", + "ln -s header/h class/fs", + "ln -s header/h class/ss", ] { assert!( CORE_SCRIPT.contains(expected), @@ -59,21 +58,31 @@ fn core_script_uses_kernel_doc_control_header_links() { } #[test] -fn core_script_matches_uvc_descriptor_speeds_to_max_speed() { - for expected in [ - "streaming_class_speeds=(fs)", - "control_class_speeds=(fs)", - "case \"$MAX_SPEED\" in", - "super-speed|super-speed-plus)", - "streaming_class_speeds+=(hs ss)", - "control_class_speeds+=(ss)", - "high-speed)", - "streaming_class_speeds+=(hs)", - "for s in \"${streaming_class_speeds[@]}\"; do", - ] { +fn core_script_keeps_known_good_uvc_descriptor_links() { + for expected in ["for s in fs hs ss; do", "ln -s ../../header/h h"] { assert!( CORE_SCRIPT.contains(expected), - "lesavka-core speed guard missing: {expected}" + "lesavka-core descriptor guard missing: {expected}" + ); + } + for unexpected in ["streaming_class_speeds", "control_class_speeds"] { + assert!( + !CORE_SCRIPT.contains(unexpected), + "lesavka-core should not trim UVC descriptor links by gadget speed: {unexpected}" + ); + } +} + +#[test] +fn core_script_treats_uvc_env_as_defaults_not_overrides() { + for expected in [ + "load_uvc_env_defaults()", + "[[ -z ${!key+x} ]] || continue", + "export \"$key=$value\"", + ] { + assert!( + CORE_SCRIPT.contains(expected), + "lesavka-core env-default guard missing: {expected}" ); } } diff --git a/testing/tests/server_install_script_contract.rs b/testing/tests/server_install_script_contract.rs index 20bb978..e793c5e 100644 --- a/testing/tests/server_install_script_contract.rs +++ b/testing/tests/server_install_script_contract.rs @@ -57,7 +57,8 @@ fn server_install_pins_hdmi_camera_and_display_defaults() { "install script should not let ambient LESAVKA_UVC_CODEC leak into persisted defaults" ); assert!( - !SERVER_INSTALL.contains("LESAVKA_SERVER_BIND_ADDR=${LESAVKA_SERVER_BIND_ADDR:-0.0.0.0:50051}"), + !SERVER_INSTALL + .contains("LESAVKA_SERVER_BIND_ADDR=${LESAVKA_SERVER_BIND_ADDR:-0.0.0.0:50051}"), "install script should not let ambient LESAVKA_SERVER_BIND_ADDR leak into persisted defaults" ); assert!( @@ -81,13 +82,19 @@ fn server_install_pins_hdmi_camera_and_display_defaults() { "install script should detect when the live gadget is missing the expected UVC function" ); assert!( - SERVER_INSTALL.contains("UVC function is missing from the live gadget; forcing a rebuild before server start."), + SERVER_INSTALL.contains( + "UVC function is missing from the live gadget; forcing a rebuild before server start." + ), "install script should force a rebuild when the live gadget is attached but missing UVC" ); assert!( SERVER_INSTALL.contains("lesavka-core gadget rebuilt directly."), "install script should trust the direct forced rebuild instead of immediately rerunning the oneshot core unit" ); + assert!( + SERVER_INSTALL.contains("sudo systemctl stop lesavka-uvc"), + "install script should stop the UVC helper before directly rebuilding the gadget underneath it" + ); assert!( !SERVER_INSTALL.contains("sudo systemctl restart lesavka-core"), "install script should not immediately rerun lesavka-core after a successful direct forced rebuild" @@ -112,6 +119,26 @@ fn server_install_pins_hdmi_camera_and_display_defaults() { SERVER_INSTALL.contains("lesavka-uvc already active; runtime settings unchanged."), "install script should avoid unnecessary UVC restarts when nothing changed" ); + assert!( + SERVER_INSTALL.contains("sudo systemctl start lesavka-uvc"), + "install script should start the UVC helper so the host enumerates the UVC function" + ); + assert!( + SERVER_INSTALL.contains("lesavka-uvc started to attach the UVC gadget to the host."), + "install script should report when it starts the UVC helper for enumeration" + ); + assert!( + SERVER_INSTALL.contains("Wants=lesavka-uvc.service"), + "server unit should pull in the external UVC helper on UVC installs" + ); + assert!( + SERVER_INSTALL.contains("/var/log/lesavka/server.log"), + "install script should keep server logs out of sticky /tmp" + ); + assert!( + SERVER_INSTALL.contains("LESAVKA_SERVER_LOG_PATH=/var/log/lesavka/server.log"), + "server unit should point tracing at the non-sticky log path" + ); assert!( SERVER_INSTALL.contains("clear_stale_server_listener"), "install script should clear stale server listeners before restart"