diff --git a/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh b/Runner/suites/Kernel/Baseport/adsp_remoteproc/run.sh index 833b675c3..2764a80d7 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 45beda881..b08898bf9 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 aa07858d9..2199ca821 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 df72f35de..57d817e1a 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/suites/Multimedia/Audio/AudioRecord/run.sh b/Runner/suites/Multimedia/Audio/AudioRecord/run.sh index 37d597247..6a067dea2 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 diff --git a/Runner/utils/functestlib.sh b/Runner/utils/functestlib.sh index e8ab66ff8..27242a2f7 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 diff --git a/Runner/utils/lib_display.sh b/Runner/utils/lib_display.sh index 62860fd9d..effdbb22c 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 @@ -2487,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: @@ -2501,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" @@ -2519,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 diff --git a/Runner/utils/send-to-lava.sh b/Runner/utils/send-to-lava.sh index 10c7d99a5..f8997f41b 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