From e16580e00c54f536292e35578c4a68eeb61bd6eb Mon Sep 17 00:00:00 2001
From: Christopher Haster <geky@geky.net>
Date: Mon, 2 Feb 2026 13:30:25 -0600
Subject: [PATCH] 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?
---
 scripts/bench.py | 9 +++++++--
 1 file changed, 7 insertions(+), 2 deletions(-)

diff --git a/scripts/bench.py b/scripts/bench.py
index 2cdadb1e..4839e567 100755
--- a/scripts/bench.py
+++ b/scripts/bench.py
@@ -1138,6 +1138,7 @@ def run_stage(name, runner, bench_ids, stdout_, trace_, output_, **args):
         last_defines = None # fetched on demand
         last_stdout = co.deque(maxlen=args.get('context', 5) + 1)
         last_assert = None
+        last_time = time.time()
         try:
             while True:
                 # 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_stdout.clear()
                         last_assert = None
+                        last_time = time.time()
                     elif op == 'finished':
                         # force a failure
                         if args.get('fail'):
@@ -1227,7 +1229,9 @@ def run_stage(name, runner, bench_ids, stdout_, trace_, output_, **args):
                                     'bench_readed': readed_,
                                     'bench_progged': progged_,
                                     'bench_erased': erased_,
-                                    'bench_simtime': simtime_})
+                                    'bench_simtime': simtime_,
+                                    'bench_runtime': '%.6f' % (
+                                        time.time() - last_time)})
                         # keep track of total for summary
                         readed += readed_
                         progged += progged_
@@ -1413,7 +1417,8 @@ def run(runner, bench_ids=[], **args):
                     'bench_readed',
                     'bench_progged',
                     'bench_erased',
-                    'bench_simtime'])
+                    'bench_simtime',
+                    'bench_runtime'])
 
     # measure runtime
     start = time.time()