scripts: bench.py: Added bench_runtime to probe measurements

This mirrors test_runtime in test.py, which has been useful for finding
test cases that are slowing down our tests.

Though note bench.py's output is per-probe, so summing bench_runtime
would be longer than the total runtime of the bench if multiple probes
are involved. Probes can be nested, so I'm not sure this is avoidable. I
guess it's the worst-case runtime if all probes were run independently?

Also note, confusingly, bench_runtime is cumulative while bench_simtime
remains per-sample. Maybe this will help prevent interchanging the two?
This commit is contained in:
Christopher Haster
2026-02-02 13:30:25 -06:00
parent 5dc88e3e00
commit e16580e00c
+7 -2
View File
@@ -1138,6 +1138,7 @@ def run_stage(name, runner, bench_ids, stdout_, trace_, output_, **args):
last_defines = None # fetched on demand last_defines = None # fetched on demand
last_stdout = co.deque(maxlen=args.get('context', 5) + 1) last_stdout = co.deque(maxlen=args.get('context', 5) + 1)
last_assert = None last_assert = None
last_time = time.time()
try: try:
while True: while True:
# parse a line for state changes # parse a line for state changes
@@ -1168,6 +1169,7 @@ def run_stage(name, runner, bench_ids, stdout_, trace_, output_, **args):
last_defines = None last_defines = None
last_stdout.clear() last_stdout.clear()
last_assert = None last_assert = None
last_time = time.time()
elif op == 'finished': elif op == 'finished':
# force a failure # force a failure
if args.get('fail'): if args.get('fail'):
@@ -1227,7 +1229,9 @@ def run_stage(name, runner, bench_ids, stdout_, trace_, output_, **args):
'bench_readed': readed_, 'bench_readed': readed_,
'bench_progged': progged_, 'bench_progged': progged_,
'bench_erased': erased_, 'bench_erased': erased_,
'bench_simtime': simtime_}) 'bench_simtime': simtime_,
'bench_runtime': '%.6f' % (
time.time() - last_time)})
# keep track of total for summary # keep track of total for summary
readed += readed_ readed += readed_
progged += progged_ progged += progged_
@@ -1413,7 +1417,8 @@ def run(runner, bench_ids=[], **args):
'bench_readed', 'bench_readed',
'bench_progged', 'bench_progged',
'bench_erased', 'bench_erased',
'bench_simtime']) 'bench_simtime',
'bench_runtime'])
# measure runtime # measure runtime
start = time.time() start = time.time()