UAV-develop/PX4-Autopilot
1
0
Fork 0
mirror of https://github.com/PX4/PX4-Autopilot.git synced 2026-09-25 12:09:56 +08:00
Code Issues Packages Projects Releases Wiki Activity

fix(bench): confirm param committed and saved before reboot in persistence test

Browse Source 
The full-suite persistence check failed on hardware with 'after reboot
SDLOG_UTC_OFFSET = 740 (expected 777)'. Firmware persistence is solid;
this was a test race. A PARAM_SET propagates through the param system
asynchronously, and phase_persistence ran 'param save' on the strength
of the PARAM_VALUE echo alone. When save raced ahead of the commit it
persisted the PRIOR value (740, the last value Phase 2 wrote). The echo
was not even proof of the new value: wait_param_echo returned
seen=[740, 777], a stale queued PARAM_VALUE from Phase 2 having slipped
past drain_param_values.

Make persistence deterministic with two gates instead of timing:

1. After setting the marker, read it back from the board until it reports
   MARKER_VALUE (read_until) before saving. This confirms the value is
   committed to RAM and trusts the board's read over any stale echo.
2. After 'param save', confirm the saved state with 'param show <name>'
   and require the '+' (saved) flag AND the marker value before rebooting
   (retry save once first). '*' means unsaved; the test never reboots on
   an unsaved marker. Flag columns per src/systemcmds/param/param.cpp:822
   (x used, + saved, * unsaved, l locked).

phase_set_readback now also trusts read_until over the echo, so the same
stale-queued-echo does not fail it either; its pass criteria stay the
readback match. Restores in phase_persistence and the final cleanup use
read_until too.

New shared helpers in px4bench.params: read_until(mav, name, expected,
timeout) -> (ok, last_seen), and param_is_saved(shell, name) plus its
parse_param_show() parser for the 'param show' saved flag and value.

Signed-off-by: Ramon Roche <mrpollo@gmail.com>
This commit is contained in:
Ramon Roche
2026-07-07 16:08:51 -07:00
parent 6e2ef3345f
commit bf7dcb7229
2 changed files with 159 additions and 42 deletions
Download Patch File Download Diff File Expand all files Collapse all files

124
Tools/bench_test/bench/param_stress.py
View File

@@ -34,8 +34,10 @@ sys.path.insert(0, os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
import px4bench
from px4bench.params import (READ_TIMEOUT_S, SET_ECHO_TIMEOUT_S,
drain_param_values, param_float_to_int32,
param_id_str, read_param, set_param_int32,
wait_param_echo)
param_id_str, param_is_saved, read_param,
read_until, set_param_int32, wait_param_echo)
COMMIT_TIMEOUT_S = 8.0
DEFAULT_PARAM = 'SDLOG_UTC_OFFSET'
DEFAULT_ITERATIONS = 50
@@ -133,7 +135,6 @@ def phase_set_readback(report, mav, param, iterations):
Individual failures are counted but the loop continues.
"""
report.info('Phase 2: set/readback loop, {} iterations'.format(iterations))
echo_failures = 0
read_failures = 0
mismatch_failures = 0
@@ -143,32 +144,37 @@ def phase_set_readback(report, mav, param, iterations):
drain_param_values(mav)
set_param_int32(mav, param, value)
matched, seen = wait_param_echo(mav, param, value, SET_ECHO_TIMEOUT_S)
if not matched:
report.fail('param_set_echo',
'set iteration {}: no echo of {} within {}s (saw: {})'.format(
i, value, SET_ECHO_TIMEOUT_S, seen or 'nothing'))
echo_failures += 1
# keep going: still try to read back
readback, _ = read_param(mav, param, READ_TIMEOUT_S)
if readback is None:
report.fail('param_readback',
'set iteration {}: no PARAM_VALUE on readback'.format(i))
read_failures += 1
continue
if readback != value:
report.fail('param_readback',
'set iteration {}: readback {} != set {}'.format(
i, readback, value))
mismatch_failures += 1
# read_param is the source of truth: a set propagates asynchronously,
# so the echo can be a stale queued PARAM_VALUE from a prior set that
# slipped past the drain. read_until confirms the board actually holds
# the new value; an echo that disagrees with a confirmed read-back is
# not counted as a failure.
confirmed, readback = read_until(mav, param, value, COMMIT_TIMEOUT_S)
if not confirmed:
if readback is None:
report.fail('param_readback',
'set iteration {}: no PARAM_VALUE on readback'.format(i))
read_failures += 1
else:
report.fail('param_readback',
'set iteration {}: readback {} != set {}'.format(
i, readback, value))
mismatch_failures += 1
elif not matched:
# board holds the right value but the echo never showed it; this is
# the stale-echo case, informational not a failure
report.info(' iteration {}: value confirmed by read-back; echo saw '
'{} (stale queued echo tolerated)'.format(i, seen or 'nothing'))
if (i + 1) % 10 == 0:
report.info(' {}/{} iterations done'.format(i + 1, iterations))
report.check('param_set_readback_loop',
echo_failures == 0 and read_failures == 0 and mismatch_failures == 0,
'{} iterations: {} echo, {} read, {} mismatch failures'.format(
iterations, echo_failures, read_failures, mismatch_failures))
read_failures == 0 and mismatch_failures == 0,
'{} iterations: {} read, {} mismatch failures (readback is the '
'source of truth; stale echoes tolerated)'.format(
iterations, read_failures, mismatch_failures))
def phase_persistence(report, mav, param, conn_str, baud, original_value):
@@ -179,29 +185,61 @@ def phase_persistence(report, mav, param, conn_str, baud, original_value):
"""
report.info('Phase 3: persistence across reboot')
# 1. Set the marker and confirm it is actually committed to RAM by reading
# it back, not merely by matching the echo. A PARAM_SET propagates
# asynchronously; if we saved on the strength of the echo alone, save
# could race ahead of the commit and persist the PRIOR value (the last
# value Phase 2 wrote). read_until closes that gap, and it trusts the
# board's read over any stale queued echo.
drain_param_values(mav)
set_param_int32(mav, param, MARKER_VALUE)
matched, seen = wait_param_echo(mav, param, MARKER_VALUE, SET_ECHO_TIMEOUT_S)
if not matched:
committed, seen = read_until(mav, param, MARKER_VALUE, COMMIT_TIMEOUT_S)
if not committed:
report.fail('persistence_set',
'no echo of marker {} (saw: {})'.format(MARKER_VALUE, seen or 'nothing'))
'marker {} not committed to RAM within {:.0f}s (read back: '
'{})'.format(MARKER_VALUE, COMMIT_TIMEOUT_S,
seen if seen is not None else 'nothing'))
return mav
# Force an explicit flush to storage before we pull the power.
# 2. Save, then confirm the SAVED state before rebooting: param show must
# report the '+' (saved) flag AND the marker value. A '*' (unsaved) or a
# wrong value means save did not persist the marker; retry once, then
# fail without rebooting on an unsaved marker.
shell = px4bench.MavlinkShell(mav)
if not shell.open(timeout=5):
report.fail('persistence_shell', 'could not open nsh shell for param save')
return mav
try:
out, timed_out = shell.run('param save', timeout=10)
saved_ok = False
saved, shown = None, None
for attempt in range(2):
out, timed_out = shell.run('param save', timeout=10)
if timed_out:
report.fail('persistence_save',
"'param save' did not complete within 10s (stalled)")
return mav
report.info("'param save' output: {}".format(out.strip() or '(none)'))
saved, shown, show_timed_out = param_is_saved(shell, param)
if show_timed_out:
report.fail('persistence_save',
"'param show {}' stalled confirming the saved "
'state'.format(param))
return mav
if saved is True and shown == MARKER_VALUE:
saved_ok = True
break
report.info('param show reports saved={} value={} after save '
'attempt {}'.format(saved, shown, attempt + 1))
if not saved_ok:
report.fail('persistence_save',
'marker {} not confirmed saved (param show saved={} '
'value={}); not rebooting on an unsaved marker'.format(
MARKER_VALUE, saved, shown))
return mav
finally:
shell.close()
if timed_out:
report.fail('persistence_save',
"'param save' did not complete within 10s (stalled)")
return mav
report.info("'param save' output: {}".format(out.strip() or '(none)'))
# 3. Reboot and read the marker back.
try:
newmav, elapsed = px4bench.reboot_and_reconnect(mav, conn_str, baud, timeout=60)
except TimeoutError as e:
@@ -220,13 +258,14 @@ def phase_persistence(report, mav, param, conn_str, baud, original_value):
'after reboot {} = {} (expected {})'.format(
param, survived, MARKER_VALUE))
# Restore original inside this phase too, then verify.
# Restore original inside this phase too, then verify by read-back.
drain_param_values(mav)
set_param_int32(mav, param, original_value)
matched, seen = wait_param_echo(mav, param, original_value, SET_ECHO_TIMEOUT_S)
restored, seen = read_until(mav, param, original_value, COMMIT_TIMEOUT_S)
report.check('persistence_restore',
matched,
'restored {} to {} (saw: {})'.format(param, original_value, seen))
restored,
'restored {} to {} (read back: {})'.format(
param, original_value, seen if seen is not None else 'nothing'))
return mav
@@ -288,12 +327,13 @@ def main():
try:
drain_param_values(mav)
set_param_int32(mav, args.param, original_value)
matched, seen = wait_param_echo(mav, args.param, original_value,
SET_ECHO_TIMEOUT_S)
restored, seen = read_until(mav, args.param, original_value,
COMMIT_TIMEOUT_S)
report.check('final_restore',
matched,
'restored {} to {} (saw: {})'.format(
args.param, original_value, seen))
restored,
'restored {} to {} (read back: {})'.format(
args.param, original_value,
seen if seen is not None else 'nothing'))
except Exception as e:
report.fail('final_restore',
'exception while restoring {}: {}'.format(args.param, e))

77
Tools/bench_test/px4bench/params.py
View File

@@ -13,6 +13,7 @@ before a set and then match the echo by expected value, never consume it
positionally.
"""
import re
import struct
import time
@@ -22,6 +23,7 @@ MAV_PARAM_TYPE_INT32 = mavutil.mavlink.MAV_PARAM_TYPE_INT32
SET_ECHO_TIMEOUT_S = 5.0
READ_TIMEOUT_S = 5.0
READ_UNTIL_TIMEOUT_S = 8.0
def int32_to_param_float(value):
@@ -104,3 +106,78 @@ def wait_param_echo(mav, name, expected, timeout=SET_ECHO_TIMEOUT_S):
if value == expected:
return True, seen
return False, seen
def read_until(mav, name, expected, timeout=READ_UNTIL_TIMEOUT_S):
"""Poll read_param until the board reports the expected int32 value.
A PARAM_SET propagates through the param system asynchronously, so an
echo (or even a single read) right after a set can still reflect the
prior value. Reading back in a loop until the board actually reports the
new value confirms it is committed to RAM, which closes the gap before a
save or a dependent check. This trusts the board's own read, not a queued
echo, so a stale PARAM_VALUE from an earlier set cannot satisfy it.
Returns (ok, last_seen): ok True once the board reports expected,
otherwise False with the last value read (None if nothing read back).
"""
deadline = time.monotonic() + timeout
last_seen = None
while True:
remaining = deadline - time.monotonic()
if remaining <= 0:
return False, last_seen
value, _ = read_param(mav, name, timeout=min(READ_TIMEOUT_S, remaining))
if value is not None:
last_seen = value
if value == expected:
return True, last_seen
else:
# brief pause so a non-responding read does not busy-spin
time.sleep(0.2)
# param show <name> prints one line:
# x + l SDLOG_UTC_OFFSET [used,idx] : 777
# three flag columns then the name; the SECOND flag is the save state:
# '*' unsaved, '+' saved, ' ' unmodified from default
# (src/systemcmds/param/param.cpp:822-823).
_PARAM_SHOW_RE = re.compile(
r'^\s*(?P<used>[x ])\s?(?P<saved>[*+ ])\s?(?P<ro>[l ])\s+'
r'(?P<name>[A-Z0-9_]+)\s+\[[^\]]*\]\s*:\s*(?P<value>-?\d+)')
def parse_param_show(output, name):
"""Parse `param show <name>` output for one parameter.
Returns (saved, value) where saved is True/False/None (None when the
line is not found or the save state is 'default'/unknown) and value is
the int32 value or None. Tolerant of ANSI escapes and the prompt.
"""
for raw in output.splitlines():
line = re.sub(r'\x1b\[[0-9;]*[A-Za-z]', '', raw).replace('nsh>', '')
m = _PARAM_SHOW_RE.search(line)
if not m or m.group('name') != name:
continue
flag = m.group('saved')
saved = True if flag == '+' else (False if flag == '*' else None)
try:
value = int(m.group('value'))
except ValueError:
value = None
return saved, value
return None, None
def param_is_saved(shell, name, timeout=10):
"""Run `param show <name>` over an open MavlinkShell and report save state.
Returns (saved, value, timed_out): saved True/False/None as parsed by
parse_param_show, value the int32 shown, timed_out True if the shell
command did not complete. Caller owns the shell (open and close it).
"""
out, timed_out = shell.run('param show {}'.format(name), timeout=timeout)
if timed_out:
return None, None, True
saved, value = parse_param_show(out, name)
return saved, value, False