From 546edd583c9e53c829d63ad7c4af78154599a893 Mon Sep 17 00:00:00 2001 From: Ricardo Salveti Date: Thu, 27 Aug 2026 15:10:31 +0000 Subject: [PATCH 1/5] send-to-lava: drain the console before restoring printk The script quiets printk around each signal printf, but printf returns once the line is in the tty buffer, not once the UART has sent it, so printk resumes while the signal is still on the wire and can split it: << --- Runner/utils/send-to-lava.sh | 65 +++++++++++++++++++++++++++--------- 1 file changed, 50 insertions(+), 15 deletions(-) diff --git a/Runner/utils/send-to-lava.sh b/Runner/utils/send-to-lava.sh index 10c7d99a..f8997f41 100755 --- a/Runner/utils/send-to-lava.sh +++ b/Runner/utils/send-to-lava.sh @@ -13,26 +13,41 @@ # # This script minimizes that risk by: # - validating/sanitizing result-file content before emitting signals -# - lowering kernel console_loglevel only for the tiny critical section where -# the LAVA signal line is printed, when /proc/sys/kernel/printk is writable +# - lowering kernel console_loglevel for the critical section where the LAVA +# signal lines are printed, when /proc/sys/kernel/printk is writable # - emitting each LAVA signal as one userspace printf operation -# - restoring the exact original printk settings immediately afterwards +# - holding the quiet window open until the bytes have left the serial link +# - restoring the exact original printk settings afterwards # - removing the temporary signal buffer explicitly after emission # +# The drain delay matters: printf returns when the line reaches the tty +# buffer, not when the UART has sent it, so the quiet window must stay open +# until the signal has cleared the wire. The same delay before the first +# printf lets kernel output already queued on the UART finish first. +# # Important: this does not suppress kernel logs during test execution. The -# printk loglevel is changed only around the LAVA signal printf, after the test -# has already completed and is reporting the result. Kernel messages generated -# during that short window remain available in the kernel ring buffer via dmesg. +# printk loglevel is changed only around the LAVA signal emission, after the +# test has already completed and is reporting the result. Kernel messages +# generated during that short window remain available in the kernel ring buffer +# via dmesg. # # If /proc/sys/kernel/printk is not writable, the script does not change printk # settings and falls back to the existing safe printf behavior. It intentionally # does not use "dmesg -n" as a fallback because that cannot restore the exact # original console loglevel. +# +# Tunables: +# LAVA_SIGNAL_DRAIN_SECONDS - console drain delay, default 0.3, "0" disables RESULT_FILE="${1:-}" SIGNAL_FILE="${TMPDIR:-/tmp}/lava_signals_$$.log" PRINTK_SAVED="" PRINTK_CHANGED=0 +LAVA_SIGNAL_DRAIN_SECONDS="${LAVA_SIGNAL_DRAIN_SECONDS:-0.3}" +# Reject anything but a plain, optionally fractional, number. +case "$LAVA_SIGNAL_DRAIN_SECONDS" in + ''|.|*[!0-9.]*|*.*.*) LAVA_SIGNAL_DRAIN_SECONDS=0.3 ;; +esac valid_result() { case "$1" in @@ -80,6 +95,20 @@ save_and_quiet_kernel_console() { return 0 } +# Sleep so the quiet window covers the bytes still leaving the UART. +drain_kernel_console() { + # No quiet window, nothing to protect. + [ "$PRINTK_CHANGED" = "1" ] || return 0 + + # Zero in any spelling (0, 0.0, 00, ...) disables the drain. + case "$(printf '%s' "$LAVA_SIGNAL_DRAIN_SECONDS" | tr -d '0.')" in + '') return 0 ;; + esac + + # Whole-second fallback for shells without fractional sleep. + sleep "$LAVA_SIGNAL_DRAIN_SECONDS" 2>/dev/null || sleep 1 +} + restore_kernel_console() { if [ "$PRINTK_CHANGED" = "1" ] && [ -n "$PRINTK_SAVED" ] && @@ -163,19 +192,25 @@ else echo "[WARNING] Result file missing: $RESULT_FILE" >&2 fi -# Emit signals with the smallest possible critical section. -# -# Kernel console quieting is applied only for the individual printf and restored -# immediately afterwards. Test execution logs remain visible; only asynchronous -# printk injection into the LAVA protocol line is avoided. +# Quiet printk across the whole emission for one result file, draining on +# each side so neither queued kernel output nor the signals themselves are +# cut by the loglevel change. if [ -s "$SIGNAL_FILE" ]; then - while IFS= read -r signal_line || [ -n "$signal_line" ]; do + # Read first: the INT/TERM trap deletes SIGNAL_FILE without exiting, + # and the emission must survive that. + signal_lines="$(cat "$SIGNAL_FILE")" + + save_and_quiet_kernel_console + drain_kernel_console + + printf '%s\n' "$signal_lines" | while IFS= read -r signal_line; do [ -n "$signal_line" ] || continue - save_and_quiet_kernel_console printf '\n%s\n\n' "$signal_line" - restore_kernel_console - done < "$SIGNAL_FILE" + done + + drain_kernel_console + restore_kernel_console fi # Explicit cleanup after signal emission. The trap remains as backup for early From 0a27b2f507a0c2596aeac70ba801918f66033449 Mon Sep 17 00:00:00 2001 From: Ricardo Salveti Date: Sun, 30 Aug 2026 16:24:47 +0000 Subject: [PATCH 2/5] lib_display: keep the missing-DRM warning off stdout display_connected_summary() warns via log_warn when /sys/class/drm is missing, and log() writes to stdout, which callers capture as the summary: a board whose display driver never probed reads as having a connected panel, because "[WARN] ..." is neither empty nor "none". Send the warning to stderr. Assisted-by: Claude Code:claude-fable-5 Signed-off-by: Ricardo Salveti --- Runner/utils/lib_display.sh | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/Runner/utils/lib_display.sh b/Runner/utils/lib_display.sh index 62860fd9..c3f5ce43 100755 --- a/Runner/utils/lib_display.sh +++ b/Runner/utils/lib_display.sh @@ -207,7 +207,8 @@ display_connected_summary() { ds_base="/sys/class/drm" if [ ! -d "$ds_base" ]; then - log_warn "display_connected_summary: $ds_base not found" + # stderr: callers capture stdout as the summary. + log_warn "display_connected_summary: $ds_base not found" >&2 printf '%s\n' "none" return 0 fi From effa59136404f3c256290b0084518f0d4b1016f2 Mon Sep 17 00:00:00 2001 From: Ricardo Salveti Date: Thu, 27 Aug 2026 15:10:31 +0000 Subject: [PATCH 3/5] lib_display: wait for a connected DRM connector before skipping display_log_snapshot_and_require_connector() samples /sys/class/drm once, but hot-plug detection is asynchronous, so a board with a panel can still read disconnected seconds after boot. Between 19 and 27 Aug 2026 boards tagged display skipped at rates only a race explains: hamoa-iot-evk-04 42 of 196 runs, lemans-hyd-01 36 of 197, and every skip is silent. Poll instead, bounded by DISPLAY_CONNECTOR_WAIT (default 20s) every DISPLAY_CONNECTOR_POLL (2s), on the monotonic clock so an NTP step cannot cut the wait short. Headless boards reach the same skip and pay the wait once per job rather than once per test in the ten suites sharing the gate: an exhausted wait leaves a tmpfs marker that reduces later checks to a single sample until a connector shows up or the board reboots. Assisted-by: Claude Code:claude-opus-5 Signed-off-by: Ricardo Salveti --- Runner/utils/lib_display.sh | 83 +++++++++++++++++++++++++++++++++---- 1 file changed, 75 insertions(+), 8 deletions(-) diff --git a/Runner/utils/lib_display.sh b/Runner/utils/lib_display.sh index c3f5ce43..effdbb22 100755 --- a/Runner/utils/lib_display.sh +++ b/Runner/utils/lib_display.sh @@ -2488,6 +2488,77 @@ display_detect_build_flavour() { return 0 } +# Wait for at least one connected DRM connector to appear. +# +# Hot-plug detection is asynchronous, so a single sysfs read right after boot +# can report "none" on a board that does have a display. Poll instead. An +# exhausted wait leaves a marker on tmpfs so a headless board pays the wait +# once per job; while it exists the check is a single sample, and a connector +# showing up clears it. +# +# Tunables: +# DISPLAY_CONNECTOR_WAIT, seconds to wait, default 20 +# DISPLAY_CONNECTOR_POLL, poll interval in seconds, default 2 +# Exports: +# DISPLAY_CONNECTED_SUMMARY, sysfs display summary, or none +# DISPLAY_CONNECTOR_WAIT_USED, the sanitized wait bound that was applied +# Return: +# 0 when at least one connected display is found +# 1 when the wait expired with no connected display +display_wait_for_connector() { + dwc_wait="${DISPLAY_CONNECTOR_WAIT:-20}" + dwc_poll="${DISPLAY_CONNECTOR_POLL:-2}" + + is_unsigned_number "$dwc_wait" || dwc_wait=20 + is_unsigned_number "$dwc_poll" || dwc_poll=2 + [ "$dwc_poll" -gt 0 ] 2>/dev/null || dwc_poll=1 + + DISPLAY_CONNECTOR_WAIT_USED="$dwc_wait" + export DISPLAY_CONNECTOR_WAIT_USED + + DISPLAY_CONNECTED_SUMMARY="none" + export DISPLAY_CONNECTED_SUMMARY + + command -v display_connected_summary >/dev/null 2>&1 || return 1 + + dwc_marker="${TMPDIR:-/tmp}/display_connector_absent_marker" + if [ -e "$dwc_marker" ]; then + DISPLAY_CONNECTED_SUMMARY="$(display_connected_summary 2>/dev/null || true)" + export DISPLAY_CONNECTED_SUMMARY + if [ -n "$DISPLAY_CONNECTED_SUMMARY" ] && + [ "$DISPLAY_CONNECTED_SUMMARY" != "none" ]; then + rm -f "$dwc_marker" + return 0 + fi + return 1 + fi + + dwc_start="$(get_monotonic_seconds)" + dwc_waited=0 + + while :; do + DISPLAY_CONNECTED_SUMMARY="$(display_connected_summary 2>/dev/null || true)" + export DISPLAY_CONNECTED_SUMMARY + + if [ -n "$DISPLAY_CONNECTED_SUMMARY" ] && + [ "$DISPLAY_CONNECTED_SUMMARY" != "none" ]; then + if [ "$dwc_waited" -gt 0 ]; then + log_info "Connector appeared after ${dwc_waited}s" + fi + return 0 + fi + + dwc_waited=$(($(get_monotonic_seconds) - dwc_start)) + [ "$dwc_waited" -lt 0 ] && dwc_waited=0 + [ "$dwc_waited" -ge "$dwc_wait" ] && break + + sleep "$dwc_poll" + done + + : > "$dwc_marker" 2>/dev/null || true + return 1 +} + # Log display snapshots and require at least one connected DRM display. # This helper keeps display gating dynamic, no connector names or fixed paths are hardcoded. # Arguments: @@ -2502,8 +2573,9 @@ display_log_snapshot_and_require_connector() { ds_testname="$1" ds_modetest_cap="${2:-200}" - DISPLAY_CONNECTED_SUMMARY="none" - export DISPLAY_CONNECTED_SUMMARY + # Settle first so the snapshots below describe the state the gate acts on; + # the verdict lands in DISPLAY_CONNECTED_SUMMARY. + display_wait_for_connector if command -v display_debug_snapshot >/dev/null 2>&1; then display_debug_snapshot "pre-display-check" @@ -2520,13 +2592,8 @@ display_log_snapshot_and_require_connector() { log_warn "modetest not found in PATH, skipping modetest snapshot" fi - if command -v display_connected_summary >/dev/null 2>&1; then - DISPLAY_CONNECTED_SUMMARY="$(display_connected_summary 2>/dev/null || true)" - export DISPLAY_CONNECTED_SUMMARY - fi - if [ -z "$DISPLAY_CONNECTED_SUMMARY" ] || [ "$DISPLAY_CONNECTED_SUMMARY" = "none" ]; then - log_warn "No connected DRM display found, skipping ${ds_testname}" + log_warn "No connected DRM display found after ${DISPLAY_CONNECTOR_WAIT_USED:-20}s, skipping ${ds_testname}" return 1 fi From fbf6143a7b42b260b6ca8b803c8503fc5cc519e2 Mon Sep 17 00:00:00 2001 From: Ricardo Salveti Date: Thu, 27 Aug 2026 15:10:31 +0000 Subject: [PATCH 4/5] remoteproc: wait for an instance to reach running before failing The boot check compares a state snapshot taken moments after login against running, so an instance still coming up is recorded as a failure; on lemans-evk the second CDSP loses that race. Between 19 and 27 Aug 2026 cdsp_remoteproc failed this way on every board with more than one instance (kaanapali-mtp-06 8 of 17, lemans-02 9 of 89), at rates that rule out a processor that never boots. Re-read the state through the existing wait_remoteproc_state() before deciding, bounded by BOOT_TO/--boot-to (default 30s, 0 restores the single shot), in all four suites sharing the check. The wait runs on get_monotonic_seconds() so an NTP step cannot cut it short, and a non-numeric BOOT_TO falls back to the default instead of silently disabling the wait. Assisted-by: Claude Code:claude-opus-5 Signed-off-by: Ricardo Salveti --- .../Kernel/Baseport/adsp_remoteproc/run.sh | 28 +++++++++++++++++-- .../Kernel/Baseport/cdsp_remoteproc/run.sh | 27 ++++++++++++++++-- .../Kernel/Baseport/gpdsp_remoteproc/run.sh | 27 ++++++++++++++++-- .../Kernel/Baseport/wpss_remoteproc/run.sh | 27 ++++++++++++++++-- Runner/utils/functestlib.sh | 5 ++-- 5 files changed, 104 insertions(+), 10 deletions(-) diff --git a/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh b/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh index 833b675c..2764a80d 100755 --- a/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh +++ b/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh @@ -42,6 +42,7 @@ log_info "------------------- Starting $TESTNAME Testcase ---------------------- log_info "=== Test Initialization ===" # --- Tunables (override via env) ---------------------------------------------- +BOOT_TO="${BOOT_TO:-30}" # wait for a processor to reach running (s) STOP_TO="${STOP_TO:-10}" # remoteproc stop timeout (s) START_TO="${START_TO:-10}" # remoteproc start timeout (s) POLL_I="${POLL_I:-1}" # state poll interval (s) @@ -53,10 +54,11 @@ FATAL_ON_UNSUSPENDED="${FATAL_ON_UNSUSPENDED:-0}" # 1 = abort if audio not suspe DO_SSR=0 usage() { - echo "Usage: $0 [--ssr] [--pre-stop-delay SEC] [--fatal-on-unsuspended] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 + echo "Usage: $0 [--ssr] [--pre-stop-delay SEC] [--fatal-on-unsuspended] [--boot-to SEC] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 echo " --ssr Perform ADSP stop/start (SSR). Default: OFF" >&2 echo " --pre-stop-delay SEC Delay before stop when --ssr is used (default: $PRE_STOP_DELAY)" >&2 echo " --fatal-on-unsuspended Abort if audio not suspended/unsupported after delay (only meaningful with --ssr)" >&2 + echo " --boot-to SEC Boot-state wait (default: $BOOT_TO, 0 disables)" >&2 echo " --stop-to SEC Stop timeout (default: $STOP_TO)" >&2 echo " --start-to SEC Start timeout (default: $START_TO)" >&2 echo " --poll-i SEC Poll interval (default: $POLL_I)" >&2 @@ -81,6 +83,15 @@ while [ $# -gt 0 ]; do FATAL_ON_UNSUSPENDED=1 shift ;; + --boot-to) + if [ $# -lt 2 ]; then + log_fail "Missing value for --boot-to" + usage + exit 2 + fi + BOOT_TO="$2" + shift 2 + ;; --stop-to) if [ $# -lt 2 ]; then log_fail "Missing value for --stop-to" @@ -120,7 +131,10 @@ while [ $# -gt 0 ]; do esac done -log_info "Tunables: STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I PRE_STOP_DELAY=$PRE_STOP_DELAY FATAL_ON_UNSUSPENDED=$FATAL_ON_UNSUSPENDED" +# A non-numeric BOOT_TO would silently disable the boot wait below. +is_unsigned_number "$BOOT_TO" || BOOT_TO=30 + +log_info "Tunables: BOOT_TO=$BOOT_TO STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I PRE_STOP_DELAY=$PRE_STOP_DELAY FATAL_ON_UNSUSPENDED=$FATAL_ON_UNSUSPENDED" log_info "SSR control: DO_SSR=$DO_SSR (0=no stop/start, 1=do stop/start)" # --- Audio readiness snapshot (no hardcoding, no long wait) ------------------- @@ -265,6 +279,16 @@ while IFS='|' read -r rpath rstate rfirm rname; do start_res="NA" ping_res="SKIPPED" + # Boot check + # + # rstate is a snapshot taken moments after login; give a processor still + # coming up BOOT_TO seconds to reach running before failing it. + if [ "$rstate" != "running" ] && [ "$BOOT_TO" -gt 0 ] 2>/dev/null; then + log_info "$inst_id: state=$rstate, waiting up to ${BOOT_TO}s for state=running" + wait_remoteproc_state "$rpath" running "$BOOT_TO" "$POLL_I" || true + rstate="$(get_remoteproc_state "$rpath")" + fi + if [ "$rstate" = "running" ]; then log_pass "$inst_id: boot check PASS" else diff --git a/Runner/suites/Kernel/Baseport/cdsp_remoteproc/run.sh b/Runner/suites/Kernel/Baseport/cdsp_remoteproc/run.sh index 45beda88..b08898bf 100755 --- a/Runner/suites/Kernel/Baseport/cdsp_remoteproc/run.sh +++ b/Runner/suites/Kernel/Baseport/cdsp_remoteproc/run.sh @@ -40,6 +40,7 @@ log_info "------------------- Starting $TESTNAME Testcase ---------------------- log_info "=== Test Initialization ===" # Timeouts (can be overridden via env) +BOOT_TO="${BOOT_TO:-30}" STOP_TO="${STOP_TO:-10}" START_TO="${START_TO:-10}" POLL_I="${POLL_I:-1}" @@ -49,8 +50,9 @@ POLL_I="${POLL_I:-1}" DO_SSR=0 usage() { - echo "Usage: $0 [--ssr] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 + echo "Usage: $0 [--ssr] [--boot-to SEC] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 echo " --ssr Perform CDSP stop/start (SSR). Default: OFF" >&2 + echo " --boot-to SEC Boot-state wait (default: $BOOT_TO, 0 disables)" >&2 echo " --stop-to SEC Stop timeout (default: $STOP_TO)" >&2 echo " --start-to SEC Start timeout (default: $START_TO)" >&2 echo " --poll-i SEC Poll interval (default: $POLL_I)" >&2 @@ -62,6 +64,15 @@ while [ $# -gt 0 ]; do DO_SSR=1 shift ;; + --boot-to) + if [ $# -lt 2 ]; then + log_fail "Missing value for --boot-to" + usage + exit 2 + fi + BOOT_TO="$2" + shift 2 + ;; --stop-to) if [ $# -lt 2 ]; then log_fail "Missing value for --stop-to" @@ -101,7 +112,10 @@ while [ $# -gt 0 ]; do esac done -log_info "Tunables: STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" +# A non-numeric BOOT_TO would silently disable the boot wait below. +is_unsigned_number "$BOOT_TO" || BOOT_TO=30 + +log_info "Tunables: BOOT_TO=$BOOT_TO STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" log_info "SSR control: DO_SSR=$DO_SSR (0=no stop/start, 1=do stop/start)" # --- Device Tree gate ---------------------------------------------------- @@ -146,6 +160,15 @@ while IFS='|' read -r rpath rstate rfirm rname; do ping_res="SKIPPED" # Boot check + # + # rstate is a snapshot taken moments after login; give a processor still + # coming up BOOT_TO seconds to reach running before failing it. + if [ "$rstate" != "running" ] && [ "$BOOT_TO" -gt 0 ] 2>/dev/null; then + log_info "$inst_id: state=$rstate, waiting up to ${BOOT_TO}s for state=running" + wait_remoteproc_state "$rpath" running "$BOOT_TO" "$POLL_I" || true + rstate="$(get_remoteproc_state "$rpath")" + fi + if [ "$rstate" = "running" ]; then log_pass "$inst_id: boot check PASS" else diff --git a/Runner/suites/Kernel/Baseport/gpdsp_remoteproc/run.sh b/Runner/suites/Kernel/Baseport/gpdsp_remoteproc/run.sh index aa07858d..2199ca82 100755 --- a/Runner/suites/Kernel/Baseport/gpdsp_remoteproc/run.sh +++ b/Runner/suites/Kernel/Baseport/gpdsp_remoteproc/run.sh @@ -40,6 +40,7 @@ log_info "------------------- Starting $TESTNAME Testcase ---------------------- log_info "=== Test Initialization ===" # Tunables +BOOT_TO="${BOOT_TO:-30}" STOP_TO="${STOP_TO:-10}" START_TO="${START_TO:-10}" POLL_I="${POLL_I:-1}" @@ -49,8 +50,9 @@ POLL_I="${POLL_I:-1}" DO_SSR=0 usage() { - echo "Usage: $0 [--ssr] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 + echo "Usage: $0 [--ssr] [--boot-to SEC] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 echo " --ssr Perform $FW stop/start (SSR). Default: OFF" >&2 + echo " --boot-to SEC Boot-state wait (default: $BOOT_TO, 0 disables)" >&2 echo " --stop-to SEC Stop timeout (default: $STOP_TO)" >&2 echo " --start-to SEC Start timeout (default: $START_TO)" >&2 echo " --poll-i SEC Poll interval (default: $POLL_I)" >&2 @@ -62,6 +64,15 @@ while [ $# -gt 0 ]; do DO_SSR=1 shift ;; + --boot-to) + if [ $# -lt 2 ]; then + log_fail "Missing value for --boot-to" + usage + exit 2 + fi + BOOT_TO="$2" + shift 2 + ;; --stop-to) if [ $# -lt 2 ]; then log_fail "Missing value for --stop-to" @@ -101,7 +112,10 @@ while [ $# -gt 0 ]; do esac done -log_info "Tunables: STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" +# A non-numeric BOOT_TO would silently disable the boot wait below. +is_unsigned_number "$BOOT_TO" || BOOT_TO=30 + +log_info "Tunables: BOOT_TO=$BOOT_TO STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" log_info "SSR control: DO_SSR=$DO_SSR (0=no stop/start, 1=do stop/start)" # DT check for entries @@ -143,6 +157,15 @@ while IFS='|' read -r rpath rstate rfirm rname; do ping_res="SKIPPED" # Boot check + # + # rstate is a snapshot taken moments after login; give a processor still + # coming up BOOT_TO seconds to reach running before failing it. + if [ "$rstate" != "running" ] && [ "$BOOT_TO" -gt 0 ] 2>/dev/null; then + log_info "$inst_id: state=$rstate, waiting up to ${BOOT_TO}s for state=running" + wait_remoteproc_state "$rpath" running "$BOOT_TO" "$POLL_I" || true + rstate="$(get_remoteproc_state "$rpath")" + fi + if [ "$rstate" = "running" ]; then log_pass "$inst_id: boot check PASS" else diff --git a/Runner/suites/Kernel/Baseport/wpss_remoteproc/run.sh b/Runner/suites/Kernel/Baseport/wpss_remoteproc/run.sh index df72f35d..57d817e1 100755 --- a/Runner/suites/Kernel/Baseport/wpss_remoteproc/run.sh +++ b/Runner/suites/Kernel/Baseport/wpss_remoteproc/run.sh @@ -43,6 +43,7 @@ log_info "------------------- Starting $TESTNAME Testcase ---------------------- log_info "=== Test Initialization ===" # Tunables +BOOT_TO="${BOOT_TO:-30}" STOP_TO="${STOP_TO:-10}" START_TO="${START_TO:-10}" POLL_I="${POLL_I:-1}" @@ -52,8 +53,9 @@ POLL_I="${POLL_I:-1}" DO_SSR=0 usage() { - echo "Usage: $0 [--ssr] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 + echo "Usage: $0 [--ssr] [--boot-to SEC] [--stop-to SEC] [--start-to SEC] [--poll-i SEC]" >&2 echo " --ssr Perform WPSS stop/start (SSR). Default: OFF" >&2 + echo " --boot-to SEC Boot-state wait (default: $BOOT_TO, 0 disables)" >&2 echo " --stop-to SEC Stop timeout (default: $STOP_TO)" >&2 echo " --start-to SEC Start timeout (default: $START_TO)" >&2 echo " --poll-i SEC Poll interval (default: $POLL_I)" >&2 @@ -65,6 +67,15 @@ while [ $# -gt 0 ]; do DO_SSR=1 shift ;; + --boot-to) + if [ $# -lt 2 ]; then + log_fail "Missing value for --boot-to" + usage + exit 2 + fi + BOOT_TO="$2" + shift 2 + ;; --stop-to) if [ $# -lt 2 ]; then log_fail "Missing value for --stop-to" @@ -104,7 +115,10 @@ while [ $# -gt 0 ]; do esac done -log_info "Tunables: STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" +# A non-numeric BOOT_TO would silently disable the boot wait below. +is_unsigned_number "$BOOT_TO" || BOOT_TO=30 + +log_info "Tunables: BOOT_TO=$BOOT_TO STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" log_info "SSR control: DO_SSR=$DO_SSR (0=no stop/start, 1=do stop/start)" # ---------- Try remoteproc path ---------- @@ -140,6 +154,15 @@ if [ -n "$rp_entries" ]; then ping_res="SKIPPED" # Boot check + # + # rstate is a snapshot taken moments after login; give a processor still + # coming up BOOT_TO seconds to reach running before failing it. + if [ "$rstate" != "running" ] && [ "$BOOT_TO" -gt 0 ] 2>/dev/null; then + log_info "$inst: state=$rstate, waiting up to ${BOOT_TO}s for state=running" + wait_remoteproc_state "$rpath" running "$BOOT_TO" "$POLL_I" || true + rstate="$(get_remoteproc_state "$rpath")" + fi + if [ "$rstate" = "running" ]; then log_pass "$inst: boot check PASS" else diff --git a/Runner/utils/functestlib.sh b/Runner/utils/functestlib.sh index e8ab66ff..27242a2f 100755 --- a/Runner/utils/functestlib.sh +++ b/Runner/utils/functestlib.sh @@ -3886,12 +3886,13 @@ wait_remoteproc_state() { *) rpath="/sys/class/remoteproc/$rp" ;; esac - start_ts=$(date +%s) + # Monotonic, so an NTP step cannot skew the wait. + start_ts=$(get_monotonic_seconds) while :; do cur=$(get_remoteproc_state "$rpath") [ "$cur" = "$want" ] && return 0 - now_ts=$(date +%s) + now_ts=$(get_monotonic_seconds) [ $((now_ts - start_ts)) -ge "$to" ] && { log_info "Waiting for state='$want' timed out (got='$cur')..." return 1 From 25f21342a6f8b08399e27b54613c0ad51bd49f07 Mon Sep 17 00:00:00 2001 From: Ricardo Salveti Date: Thu, 27 Aug 2026 15:10:31 +0000 Subject: [PATCH 5/5] AudioRecord: give the capture watchdog start-up headroom pw-record has no duration flag on this path, so the recording is ended by the external watchdog, whose clock starts before PipeWire has opened the device: whatever the graph spends coming up is taken out of the recording, and a slow start fails the duration check (duration-too-short:0.724<3.500). Between 19 and 27 Aug 2026 this cost iq-x7181-evk 19 to 29 failures per AudioRecord config out of ~207 runs. Run the watchdog for the requested duration plus AUDIO_RECORD_START_GRACE (default 5s) so a slow start eats the headroom instead of the recording. The duration validated against is unchanged and an explicit --timeout still overrides the watchdog. Assisted-by: Claude Code:claude-opus-5 Signed-off-by: Ricardo Salveti --- .../Multimedia/Audio/AudioRecord/run.sh | 29 +++++++++++++++++-- 1 file changed, 26 insertions(+), 3 deletions(-) diff --git a/Runner/suites/Multimedia/Audio/AudioRecord/run.sh b/Runner/suites/Multimedia/Audio/AudioRecord/run.sh index 37d59724..6a067dea 100755 --- a/Runner/suites/Multimedia/Audio/AudioRecord/run.sh +++ b/Runner/suites/Multimedia/Audio/AudioRecord/run.sh @@ -539,7 +539,7 @@ if [ -n "$CONFIG_NAMES" ] && [ -n "$CONFIG_FILTER" ]; then CONFIG_FILTER="" fi -log_info "Args: backend=${AUDIO_BACKEND:-auto} source=$SRC_CHOICE overlay=$AUDIO_OVERLAY_REQUESTED loops=$LOOPS durations='$DURATIONS' record_seconds=$RECORD_SECONDS timeout=$TIMEOUT strict=$STRICT signal_strict=$AUDIO_RECORD_STRICT_SIGNAL dmesg=$DMESG_SCAN bootstrap=$AUDIO_BOOTSTRAP_MODE runtime_dir=${AUDIO_RUNTIME_DIR:-auto}" +log_info "Args: backend=${AUDIO_BACKEND:-auto} source=$SRC_CHOICE overlay=$AUDIO_OVERLAY_REQUESTED loops=$LOOPS durations='$DURATIONS' record_seconds=$RECORD_SECONDS timeout=$TIMEOUT start_grace=${AUDIO_RECORD_START_GRACE:-5} strict=$STRICT signal_strict=$AUDIO_RECORD_STRICT_SIGNAL dmesg=$DMESG_SCAN bootstrap=$AUDIO_BOOTSTRAP_MODE runtime_dir=${AUDIO_RUNTIME_DIR:-auto}" # Resolve backend (allow minimal-build ALSA capture fallback) if [ -z "$AUDIO_BACKEND" ]; then @@ -960,6 +960,29 @@ auto_secs_for() { esac } +# Add startup headroom to the capture watchdog. +# +# pw-record has no duration flag on this path, so the watchdog is what ends +# the recording, and its clock starts before PipeWire has opened the device: +# a slow start is taken out of the recording and fails the duration check. +# Grant AUDIO_RECORD_START_GRACE extra watchdog seconds so the requested +# duration is still captured. The duration validated against is unchanged, +# and an explicit --timeout still overrides the watchdog. +audio_record_timeout_with_grace() { + artg_requested="$(audio_parse_secs "$1" 2>/dev/null || echo 0)" + artg_grace="${AUDIO_RECORD_START_GRACE:-5}" + + is_unsigned_number "$artg_grace" || artg_grace=5 + + if [ "${artg_requested:-0}" -gt 0 ] 2>/dev/null && + [ "$artg_grace" -gt 0 ] 2>/dev/null; then + printf '%ss\n' "$((artg_requested + artg_grace))" + return 0 + fi + + printf '%s\n' "$1" +} + # Validate the final capture selected by the existing backend/retry flow. # Size remains useful only for deciding whether compatibility fallbacks should # run; PASS requires a structurally valid WAV with acceptable sample content. @@ -1079,7 +1102,7 @@ if [ "$USE_CONFIG_DISCOVERY" = "true" ]; then while [ "$i" -le "$LOOPS" ]; do iso="$(date -u +%Y-%m-%dT%H:%M:%SZ)" - effective_timeout="$secs" + effective_timeout="$(audio_record_timeout_with_grace "$secs")" if [ -n "$TIMEOUT" ] && [ "$TIMEOUT" != "0" ]; then effective_timeout="$TIMEOUT" fi @@ -1384,7 +1407,7 @@ else while [ "$i" -le "$LOOPS" ]; do iso="$(date -u +%Y-%m-%dT%H:%M:%SZ)" - effective_timeout="$secs" + effective_timeout="$(audio_record_timeout_with_grace "$secs")" if [ -n "$TIMEOUT" ] && [ "$TIMEOUT" != "0" ]; then effective_timeout="$TIMEOUT" fi