From b211188a8ce5cbc44fdad9fc287c06a8ddb60d8f 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..350f79b7 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 +# before the first signal and after each one, so printk only resumes once +# the last signal has cleared the wire however many lines the file holds. 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" + drain_kernel_console + done + + restore_kernel_console fi # Explicit cleanup after signal emission. The trap remains as backup for early From 84da16c25e50062ff04ab87d079e14bfff991176 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 b0a87819f018ad93468ac88484c3a302811e6e3c 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. Connector nodes are created at driver bind, not by hot-plug, so when none exists the gate skips immediately; boards with a connector and nothing attached reach the same skip, only later. Assisted-by: Claude Code:claude-opus-5 Signed-off-by: Ricardo Salveti --- Runner/utils/lib_display.sh | 75 +++++++++++++++++++++++++++++++++---- 1 file changed, 67 insertions(+), 8 deletions(-) diff --git a/Runner/utils/lib_display.sh b/Runner/utils/lib_display.sh index c3f5ce43..3282fbf7 100755 --- a/Runner/utils/lib_display.sh +++ b/Runner/utils/lib_display.sh @@ -2488,6 +2488,69 @@ 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. +# +# 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 + + # Connector nodes are created at driver bind, not by hot-plug: with none + # present there is nothing to wait for, skip immediately. + set -- /sys/class/drm/card*-* + if [ ! -e "$1" ]; then + DISPLAY_CONNECTOR_WAIT_USED=0 + 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 + + 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 +2565,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 +2584,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 8a2df9a3cbf29fda3613203138ee042a085dcbc0 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. Add wait_remoteproc_boot_state() to functestlib.sh: re-read the state, give a processor not yet running a bounded wait, and return the refreshed state. All four suites call it with BOOT_TO/--boot-to (default 30s, 0 restores the single shot), keeping the boot-wait policy in one place. 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 | 19 +++++++++++-- .../Kernel/Baseport/cdsp_remoteproc/run.sh | 20 +++++++++++-- .../Kernel/Baseport/gpdsp_remoteproc/run.sh | 20 +++++++++++-- .../Kernel/Baseport/wpss_remoteproc/run.sh | 20 +++++++++++-- Runner/utils/functestlib.sh | 28 +++++++++++++++++-- 5 files changed, 94 insertions(+), 13 deletions(-) diff --git a/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh b/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh index 833b675c..802f8f5a 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,7 @@ 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" +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 +276,10 @@ while IFS='|' read -r rpath rstate rfirm rname; do start_res="NA" ping_res="SKIPPED" + # Boot check: the instance list snapshot was taken moments after login, + # so let a processor still coming up reach running before judging it. + rstate="$(wait_remoteproc_boot_state "$rpath" "$inst_id" "$BOOT_TO" "$POLL_I")" + 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..fad845df 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,7 @@ while [ $# -gt 0 ]; do esac done -log_info "Tunables: STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" +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 ---------------------------------------------------- @@ -145,7 +156,10 @@ while IFS='|' read -r rpath rstate rfirm rname; do start_res="NA" ping_res="SKIPPED" - # Boot check + # Boot check: the instance list snapshot was taken moments after login, + # so let a processor still coming up reach running before judging it. + rstate="$(wait_remoteproc_boot_state "$rpath" "$inst_id" "$BOOT_TO" "$POLL_I")" + 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..a7a3e5df 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,7 @@ while [ $# -gt 0 ]; do esac done -log_info "Tunables: STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" +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 @@ -142,7 +153,10 @@ while IFS='|' read -r rpath rstate rfirm rname; do start_res="NA" ping_res="SKIPPED" - # Boot check + # Boot check: the instance list snapshot was taken moments after login, + # so let a processor still coming up reach running before judging it. + rstate="$(wait_remoteproc_boot_state "$rpath" "$inst_id" "$BOOT_TO" "$POLL_I")" + 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..617e08f7 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,7 @@ while [ $# -gt 0 ]; do esac done -log_info "Tunables: STOP_TO=$STOP_TO START_TO=$START_TO POLL_I=$POLL_I" +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 ---------- @@ -139,7 +150,10 @@ if [ -n "$rp_entries" ]; then start_res="NA" ping_res="SKIPPED" - # Boot check + # Boot check: the instance list snapshot was taken moments after login, + # so let a processor still coming up reach running before judging it. + rstate="$(wait_remoteproc_boot_state "$rpath" "$inst" "$BOOT_TO" "$POLL_I")" + 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..99ca72aa 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 @@ -3900,6 +3901,29 @@ wait_remoteproc_state() { done } +# wait_remoteproc_boot_state