diff --git a/Runner/suites/Multimedia/Graphics/weston-simple-egl/run.sh b/Runner/suites/Multimedia/Graphics/weston-simple-egl/run.sh index 04e6458a..c3914c27 100755 --- a/Runner/suites/Multimedia/Graphics/weston-simple-egl/run.sh +++ b/Runner/suites/Multimedia/Graphics/weston-simple-egl/run.sh @@ -74,6 +74,7 @@ FPS_TOL_PCT="${FPS_TOL_PCT:-10}" MIN_FPS_PCT="${MIN_FPS_PCT:-85}" REQUIRE_FPS="${REQUIRE_FPS:-1}" DESKTOP_FUNCTIONAL_FPS_CAP="${DESKTOP_FUNCTIONAL_FPS_CAP:-60}" +CLOCK_STEP_TOLERANCE="${CLOCK_STEP_TOLERANCE:-2}" REQUESTED_GRAPHICS_MODE="default" ALLOW_RELAUNCH="${ALLOW_RELAUNCH:-0}" @@ -166,6 +167,8 @@ Environment: FPS_TOL_PCT Fixed-mode tolerance, default: 10 MIN_FPS_PCT Minimum percentage, default: 85 DESKTOP_FUNCTIONAL_FPS_CAP Desktop auto-mode FPS cap, default: 60 + TIME_SYNC_WAIT Clock sync wait bound in seconds, 0 disables, default: 20 + CLOCK_STEP_TOLERANCE Wall-clock step tolerance in seconds, default: 2 EOF_USAGE exit 0 ;; @@ -226,6 +229,11 @@ if [ "$DESKTOP_FUNCTIONAL_FPS_CAP" -le 0 ]; then exit 1 fi +if ! is_unsigned_number "$CLOCK_STEP_TOLERANCE"; then + echo "[ERROR] CLOCK_STEP_TOLERANCE must be a non-negative integer: $CLOCK_STEP_TOLERANCE" >&2 + exit 1 +fi + test_path="$(find_test_case_by_name "$TESTNAME" 2>/dev/null || true)" if [ -z "$test_path" ] || [ ! -d "$test_path" ]; then @@ -570,9 +578,15 @@ WESTON_SIMPLE_EGL_FPS=1 export SIMPLE_EGL_FPS export WESTON_SIMPLE_EGL_FPS +# A clock step inside the window corrupts both the interval and the client's +# frame accounting. Settle the clock first, measure monotonically, then check +# whether a step slipped in anyway. +wait_for_time_sync || true + log_info "Launching $TESTNAME for $DURATION" start_ts="$(date +%s)" +start_mono="$(get_monotonic_seconds)" rc=0 if command -v run_with_timeout >/dev/null 2>&1; then @@ -651,10 +665,28 @@ else fi end_ts="$(date +%s)" -elapsed=$((end_ts - start_ts)) +end_mono="$(get_monotonic_seconds)" +elapsed=$((end_mono - start_mono)) + +clock_step="$( + clock_step_seconds \ + "$start_mono" \ + "$start_ts" \ + "$end_mono" \ + "$end_ts" +)" + +clock_stepped=0 + +if [ "$clock_step" -gt "$CLOCK_STEP_TOLERANCE" ]; then + clock_stepped=1 +fi log_info "Client finished, rc=${rc} elapsed=${elapsed}s" +if [ "$clock_stepped" -eq 1 ]; then + log_warn "System clock stepped by ${clock_step}s during the run; FPS samples from the client are not trustworthy" +fi fps_count=0 fps_avg="-" @@ -668,7 +700,7 @@ if command -v display_parse_fps_log >/dev/null 2>&1 && fps_min="$DISPLAY_FPS_MIN" fps_max="$DISPLAY_FPS_MAX" - log_info "FPS stats, samples=${fps_count} avg=${fps_avg} min=${fps_min} max=${fps_max}" + log_info "FPS stats, samples=${fps_count} avg=${fps_avg} min=${fps_min} max=${fps_max} single_frame=${DISPLAY_FPS_SINGLE_FRAME:-0}" else log_warn "No FPS samples were detected in $RUN_LOG" fi @@ -704,14 +736,21 @@ if [ "$elapsed" -le 1 ]; then fi -if ! display_apply_test_fps_gate_policy \ +if [ "$clock_stepped" -eq 1 ]; then + # Averaging across a step measures the step, not the GPU. + log_skip "$TESTNAME SKIP - system clock stepped by ${clock_step}s during the ${elapsed}s run, FPS gate skipped (samples=${fps_count} avg=${fps_avg} max=${fps_max} single_frame=${DISPLAY_FPS_SINGLE_FRAME:-0})" + + if [ "$final" = "PASS" ]; then + final="SKIP" + fi +elif ! display_apply_test_fps_gate_policy \ "$fps_avg" \ "$fps_count" \ "$REQUIRE_FPS"; then final="FAIL" fi -if [ "$final" = "FAIL" ]; then +if [ "$final" != "PASS" ]; then log_info "----- Last 200 client log lines -----" tail -n 200 "$RUN_LOG" 2>/dev/null | @@ -737,7 +776,9 @@ fi printf '%s\n' "fps_gate_minimum=${DISPLAY_TEST_FPS_MIN_OK:-unknown}" printf '%s\n' "client_rc=$rc" printf '%s\n' "elapsed_seconds=$elapsed" + printf '%s\n' "clock_step_seconds=$clock_step" printf '%s\n' "fps_samples=$fps_count" + printf '%s\n' "fps_single_frame_samples=${DISPLAY_FPS_SINGLE_FRAME:-0}" printf '%s\n' "fps_average=$fps_avg" printf '%s\n' "fps_minimum=$fps_min" printf '%s\n' "fps_maximum=$fps_max" @@ -749,11 +790,17 @@ echo "$TESTNAME $final" >"$RES_FILE" trap - EXIT HUP INT TERM cleanup_client -if [ "$final" = "PASS" ]; then - log_pass "$TESTNAME : PASS" -else - log_fail "$TESTNAME : FAIL" -fi +case "$final" in + PASS) + log_pass "$TESTNAME : PASS" + ;; + SKIP) + log_skip "$TESTNAME : SKIP" + ;; + *) + log_fail "$TESTNAME : FAIL" + ;; +esac log_info "------------------- Completed ${TESTNAME} Testcase -------------------------" exit 0 diff --git a/Runner/suites/Multimedia/Graphics/weston-simple-egl/weston-simple-egl.yaml b/Runner/suites/Multimedia/Graphics/weston-simple-egl/weston-simple-egl.yaml index b12b3d7a..12e43352 100755 --- a/Runner/suites/Multimedia/Graphics/weston-simple-egl/weston-simple-egl.yaml +++ b/Runner/suites/Multimedia/Graphics/weston-simple-egl/weston-simple-egl.yaml @@ -11,10 +11,12 @@ params: DURATION: "30s" WAIT_SECS: "10" REQUIRE_FPS: "1" + TIME_SYNC_WAIT: "20" + CLOCK_STEP_TOLERANCE: "2" run: steps: - REPO_PATH=$PWD - cd Runner/suites/Multimedia/Graphics/weston-simple-egl - - DURATION="${DURATION}" WAIT_SECS="${WAIT_SECS}" REQUIRE_FPS="${REQUIRE_FPS}" ./run.sh || true + - DURATION="${DURATION}" WAIT_SECS="${WAIT_SECS}" REQUIRE_FPS="${REQUIRE_FPS}" TIME_SYNC_WAIT="${TIME_SYNC_WAIT}" CLOCK_STEP_TOLERANCE="${CLOCK_STEP_TOLERANCE}" ./run.sh || true - $REPO_PATH/Runner/utils/send-to-lava.sh weston-simple-egl.res || true diff --git a/Runner/utils/functestlib.sh b/Runner/utils/functestlib.sh index da1202fc..e8ab66ff 100755 --- a/Runner/utils/functestlib.sh +++ b/Runner/utils/functestlib.sh @@ -1294,6 +1294,193 @@ ensure_reasonable_clock() { return 1 } +############################################################################### +# Monotonic time and wall-clock step helpers +# +# Boards without a valid RTC boot at the epoch and get stepped to real time +# once NTP reaches them. A step landing inside a measurement invalidates +# every wall-clock interval taken across it. +############################################################################### + +# Print whole seconds from a monotonic source, falling back to the wall clock. +get_monotonic_seconds() { + gms_value="" + + if [ -r /proc/uptime ]; then + gms_value="$(awk '{ printf "%d", $1 }' /proc/uptime 2>/dev/null)" + fi + + if ! is_unsigned_number "$gms_value"; then + gms_value="$(date +%s 2>/dev/null)" + fi + + if ! is_unsigned_number "$gms_value"; then + gms_value=0 + fi + + printf '%s\n' "$gms_value" +} + +# Print how far the wall clock moved beyond the monotonic duration of an +# interval, in either direction. Malformed input reports 0, no step detected. +# +# Usage: +# clock_step_seconds MONO_START REAL_START MONO_END REAL_END +clock_step_seconds() { + css_mono_start="$1" + css_real_start="$2" + css_mono_end="$3" + css_real_end="$4" + css_step=0 + + for css_value in \ + "$css_mono_start" \ + "$css_real_start" \ + "$css_mono_end" \ + "$css_real_end"; do + if ! is_unsigned_number "$css_value"; then + printf '%s\n' 0 + return 0 + fi + done + + css_step=$(((css_real_end - css_real_start) - (css_mono_end - css_mono_start))) + + if [ "$css_step" -lt 0 ]; then + css_step=$((0 - css_step)) + fi + + printf '%s\n' "$css_step" +} + +# Report whether the system clock is synchronized to a time source. +# +# Return: +# 0 - synchronized +# 1 - not synchronized, or no way to tell +clock_is_synchronized() { + cis_value="" + + if command -v timedatectl >/dev/null 2>&1; then + cis_value="$(timedatectl show -p NTPSynchronized --value 2>/dev/null)" + + if [ -z "$cis_value" ]; then + cis_value="$( + timedatectl status 2>/dev/null | + sed -n 's/^[[:space:]]*System clock synchronized:[[:space:]]*//p' | + head -n 1 + )" + fi + + case "$cis_value" in + yes|true|1) + return 0 + ;; + no|false|0) + return 1 + ;; + esac + fi + + # Covers images without timedatectl. + [ -e /run/systemd/timesync/synchronized ] && return 0 + + return 1 +} + +# Report whether a time synchronization service is enabled or running. +# timedatectl alone is not enough: it exists on every systemd image, even +# ones with no synchronization service configured. +# +# Return: +# 0 - a time synchronization service is enabled or running +# 1 - none detected +time_sync_service_active() { + # NTP enabled per timedated; covers systemd-timesyncd and daemons such + # as chronyd that register through ntp-units.d. + if command -v timedatectl >/dev/null 2>&1; then + tssa_value="$(timedatectl show -p NTP --value 2>/dev/null)" + + if [ -z "$tssa_value" ]; then + tssa_value="$( + timedatectl status 2>/dev/null | + sed -n 's/^[[:space:]]*NTP service:[[:space:]]*//p' | + head -n 1 + )" + fi + + case "$tssa_value" in + yes|true|1|active) + return 0 + ;; + esac + fi + + # Runtime directory created by a running systemd-timesyncd. + [ -d /run/systemd/timesync ] && return 0 + + # Daemons running without timedated integration. + if command -v pidof >/dev/null 2>&1; then + for tssa_daemon in systemd-timesyncd chronyd ntpd; do + if pidof "$tssa_daemon" >/dev/null 2>&1; then + return 0 + fi + done + fi + + return 1 +} + +# Wait, bounded, for the system clock to synchronize, so a correction cannot +# land mid-measurement. Skipped when no time source exists, so boards without +# one do not stall on every run. +# +# Usage: +# wait_for_time_sync [TIMEOUT_SECONDS] +# +# TIMEOUT_SECONDS defaults to TIME_SYNC_WAIT, then 20. 0 disables the wait. +# +# Return: +# 0 - clock is synchronized +# 1 - still unsynchronized at the timeout, or no time source exists +wait_for_time_sync() { + wfts_timeout="${1:-${TIME_SYNC_WAIT:-20}}" + wfts_waited=0 + + if ! is_unsigned_number "$wfts_timeout"; then + wfts_timeout=20 + fi + + if clock_is_synchronized; then + log_info "System clock is already synchronized" + return 0 + fi + + if ! time_sync_service_active; then + log_info "No active time synchronization service detected, not waiting" + return 1 + fi + + if [ "$wfts_timeout" -le 0 ]; then + return 1 + fi + + log_info "Waiting up to ${wfts_timeout}s for the system clock to synchronize" + + while [ "$wfts_waited" -lt "$wfts_timeout" ]; do + sleep 1 + wfts_waited=$((wfts_waited + 1)) + + if clock_is_synchronized; then + log_info "System clock synchronized after ${wfts_waited}s" + return 0 + fi + done + + log_warn "System clock did not synchronize within ${wfts_timeout}s; a later correction may disturb timing-sensitive measurements" + return 1 +} + # If the tar file already exists,then function exit. Otherwise function to check the network connectivity and it will download tar from internet. extract_tar_from_url() { url="$1" diff --git a/Runner/utils/lib_display.sh b/Runner/utils/lib_display.sh index f8d47383..62860fd9 100755 --- a/Runner/utils/lib_display.sh +++ b/Runner/utils/lib_display.sh @@ -2304,6 +2304,9 @@ display_fps_gate_avg() { # DISPLAY_FPS_AVG # DISPLAY_FPS_MIN # DISPLAY_FPS_MAX +# DISPLAY_FPS_SINGLE_FRAME - single-frame samples. A clock step turns every +# reporting window into one, so a high count next to a healthy +# DISPLAY_FPS_MAX means untrustworthy samples, not slow rendering. # # Return: # 0 - one or more usable FPS samples remain after warm-up handling @@ -2316,6 +2319,7 @@ display_parse_fps_log() { DISPLAY_FPS_AVG="-" DISPLAY_FPS_MIN="-" DISPLAY_FPS_MAX="-" + DISPLAY_FPS_SINGLE_FRAME=0 [ -n "$dpfl_log_file" ] || return 1 [ -r "$dpfl_log_file" ] || return 1 @@ -2329,6 +2333,7 @@ display_parse_fps_log() { if ($i == "frames" && i > 1 && $(i + 1) == "in") { + frames = $(i - 1) for (j = i + 2; j <= NF; j++) { # Weston 14: # 601 frames in 5 seconds: 120.199997 fps @@ -2353,6 +2358,7 @@ display_parse_fps_log() { if (value ~ /^[0-9]+([.][0-9]+)?$/) { all_n++ all_values[all_n] = value + 0.0 + all_frames[all_n] = (frames ~ /^[0-9]+$/) ? frames + 0 : -1 } } @@ -2366,11 +2372,16 @@ display_parse_fps_log() { first = (all_n > 1) ? 2 : 1 count = 0 sum = 0.0 + single = 0 for (i = first; i <= all_n; i++) { value = all_values[i] count++ sum += value + + if (all_frames[i] >= 0 && all_frames[i] <= 1) { + single++ + } if (count == 1 || value < min) { min = value @@ -2382,11 +2393,12 @@ display_parse_fps_log() { } if (count > 0) { - printf "n=%d avg=%.6f min=%.6f max=%.6f\n", + printf "n=%d avg=%.6f min=%.6f max=%.6f single=%d\n", count, sum / count, min, - max + max, + single } } ' "$dpfl_log_file" 2>/dev/null @@ -2417,6 +2429,18 @@ display_parse_fps_log() { awk '{ print $4 }' | sed 's/^max=//' )" + + DISPLAY_FPS_SINGLE_FRAME="$( + printf '%s\n' "$dpfl_stats" | + awk '{ print $5 }' | + sed 's/^single=//' + )" + + case "$DISPLAY_FPS_SINGLE_FRAME" in + ''|*[!0-9]*) + DISPLAY_FPS_SINGLE_FRAME=0 + ;; + esac case "$DISPLAY_FPS_COUNT" in ''|*[!0-9]*) @@ -2424,6 +2448,7 @@ display_parse_fps_log() { DISPLAY_FPS_AVG="-" DISPLAY_FPS_MIN="-" DISPLAY_FPS_MAX="-" + DISPLAY_FPS_SINGLE_FRAME=0 return 1 ;; esac diff --git a/Runner/utils/lib_rt.sh b/Runner/utils/lib_rt.sh index bbc53513..8900e69a 100755 --- a/Runner/utils/lib_rt.sh +++ b/Runner/utils/lib_rt.sh @@ -1947,14 +1947,11 @@ rt_evaluate_baseline_gate() { # rt_now_seconds # Return monotonic uptime seconds when available. # This avoids elapsed-time jumps when wall clock is corrected by NTP/RTC. +# Delegates to get_monotonic_seconds() from functestlib.sh, which every +# consumer sources first. # --------------------------------------------------------------------------- rt_now_seconds() { - if [ -r /proc/uptime ]; then - awk '{ printf "%d\n", $1 }' /proc/uptime 2>/dev/null - return 0 - fi - - date +%s 2>/dev/null || echo 0 + get_monotonic_seconds } # ---------------------------------------------------------------------------