Skip to content

A run of experiments shows its progress and where the time went - #399

Merged
matthiaskoenig merged 3 commits into
developfrom
feat/runner-progress
Oct 24, 2026
Merged

matthiaskoenig merged 3 commits into
developfrom
feat/runner-progress

Conversation

@matthiaskoenig

@matthiaskoenig matthiaskoenig commented Oct 24, 2026 •

Copy link
Copy Markdown
Owner

Closes #391

A run of ExperimentRunner.run_experiments (and of the function run_experiments) now shows its progress with rich on the console and ends with a table of where the time went. The timing log lines of utils.timeit on the run path are gone.

What a run shows

While it runs: a bar over all experiments and a row per running experiment with its activity (simulations, fit mappings, drawing figures, writing figures, writing datasets, writing JSON, loading models, initializing) and its steps, e.g. 3/7 tasks. In a pool the workers report to the same display, so the rows are the experiments the workers run right now (the overall row counts an experiment when it ends, in the order they end).

A frame in the middle of a run of 28 experiments on 4 workers:

⠋ experiments                      4 workers       ━━━━━━                               5/28 0:00:00
⠋   Beermann1976                   simulations     ━━━━━━━━━━━━━━━                      3/7  0:00:00
⠋   Patel1984                      writing figures ━━━━━━━━━━━━━━                       2/5  0:00:00
⠋   AVeryLongNameOfAnExperimentWh… loading models                                            0:00:00
⠋   Weir1998                       writing JSON                                              0:00:00

At the end the bar stays as a single line and the timings follow (the HCTZ studies on 3 workers, 100 columns; in a terminal the bars are stacked in the colours of the column headers):

✓ experiments 3 workers ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 3/3 0:00:02

⏱ Timings in seconds ───────────────────────────────────────────────────────────────────────────────
experiment      models  initialize  simulations  data  figures  outputs  total
────────────────────────────────────────────────────────────────────────────────────────────────
✓ Beermann1976    0.22        0.05         0.04  0.01     0.35     0.01   0.68  ━━━━━━━━━━━
✓ Patel1984       0.22        0.09         0.21  0.02     0.40     0.02   0.97  ━━━━━━━━━━━━━━━━
✓ Weir1998        0.22        0.03         0.05  0.01     0.17     0.01   0.48  ━━━━━━━━
────────────────────────────────────────────────────────────────────────────────────────────────
total             0.66        0.17         0.30  0.05     0.91     0.04   2.13  ━━━━━━━━━━━━━━━━
share              31%          8%          14%    2%      43%       2%   100%
3 experiments, initialized in 0.37 s and run in 2.16 s on 3 workers

Before, the same run printed a Running SimulationExperiment line and six timeit lines per experiment (_run_tasks <pid> 0.0379 [s], ...) through logging.

Design

  • sbmlsim/experiment/progress.py (new): Phase (models, initialize, simulations, data, figures, outputs, other), PhaseClock which measures the phases where they run and reports them as Events to the listener of the context (reporting, a ContextVar), RunProgress (the rich display, thread safe) and timings_table/show_timings.
  • The phases are measured where they happen: the runner measures loading the models and initializing an experiment, SimulationExperiment.run its simulations, fit mappings, figures and outputs; progress.advance() in the loops of _run_tasks, create_mpl_figures, save_mpl_figures, ... advances the activity. The runner adds other, the part of a run no phase measured (e.g. an overridden run), so the timings add up to the time an experiment took. The seconds are ExperimentResult.timings (also in to_dict), sent back from a worker in _Outcome, so the numbers are right for pool runs.
  • Pool: the workers get a multiprocessing queue from a new initializer/initargs of parallel.start_pool (a queue cannot be sent with a task) and put their events on it; a daemon thread of the parent forwards them to the display (_forwarded). A done callback of every future counts an experiment when its result arrives; an experiment whose worker died is noted in its row and counted when it ran again in the parent. A run without progress creates no queue.
  • progress: bool | None = None on both run_experiments: None shows the progress on an interactive terminal (console.is_interactive, so not on TERM=dumb) or in a notebook, not when the output is redirected (no frames in files or in the generated outputs of the docs pages); True forces it (a non-terminal gets the last frame once), False prints nothing, also no bar of a scan of a task (Simulator.run(progress=scan_progress())). With progress, a scan which the simulator runs in a pool shows its bar nested below the rows (rich 15 nests live displays).
  • The caption separates the initialization in the parent before the run from the run itself: in a serial run the models/initialize columns are the ones of the constructor of the runner, in a pool the ones of the workers (which load the models again); a second run of the same runner has no initialization.
  • The table drops columns of phases no experiment ran (and other when it is negligible), cuts long names before it drops the bars, drops the bars on a console too narrow for them, and on a console too narrow for the seconds of every phase prints the totals of the experiments and of the phases as two small tables. A console whose encoding is no UTF (e.g. a redirected output in cp1252 on windows) gets ASCII marks, bars and lines instead of failing with a UnicodeEncodeError.
  • Library code still does not configure logging, and real warnings and errors stay logging; the logger.info messages of the run path (which experiment runs, why a run is serial) are debug now, the reason of a serial run is in the caption of the table.
  • Removing @timeit exposed the real signatures of SimulationExperiment.run and create_mpl_figures to ty: the return annotation of create_mpl_figures was wrong (dict[str, FigureMPL]), and the test experiments which override run with an old signature on purpose carry # ty: ignore[invalid-method-override].

Tests

tests/experiment/test_progress.py: progress=False prints and logs nothing (replaces test_a_run_prints_nothing, the new contract), no output by default when stdout is not a terminal, show_progress, the final line and table of a serial run with a failure, the phases of the timings (a model loaded once per runner, other of an overridden run, a failed definition), the events of a serial run, the events of the workers of a pool, no queue without progress, a died worker counted once, a second run without initialization, PhaseClock, a failing listener, scan_progress, the table and its narrow fallback.

Docs: docs/experiments.md describes the progress and the timings, the API page experiment.progress, and CLAUDE.md the architecture.

@matthiaskoenig
matthiaskoenig force-pushed the feat/runner-progress branch 2 times, most recently from c7ebf90 to 1bb5be9 Compare October 24, 2026 20:41
`ExperimentRunner.run_experiments` shows its progress with rich on the
console: a bar over the experiments and a row per running experiment with
its activity and steps, also for the experiments of the workers of a pool,
which send their events through a queue the workers get from a new
initializer of `parallel.start_pool`. The run ends with a table of the
seconds every experiment took in every phase (models, initialize,
simulations, data, figures, outputs, other), with the totals, the shares
and a bar of the phases per experiment.

The phases are measured where they run by a `PhaseClock` of the new module
`sbmlsim.experiment.progress` and carried in `ExperimentResult.timings`,
from a worker in its `_Outcome`. The `timeit` log lines of the run path are
gone. `progress=None` shows the progress on an interactive terminal or in a
notebook only, `False` prints nothing, the bars of the scans included.
The table of the timings was cut on a console narrower than about 80
columns: the names and the totals vanished, which the continuous
integration on windows and macOS showed. A console too narrow for the
seconds of every phase now gets the totals of the experiments and of the
phases as two small tables. A console whose encoding is no UTF, e.g. a
redirected output in cp1252 on windows, failed with a UnicodeEncodeError on
the check marks; it gets ASCII marks, bars and lines instead. The tests of
the progress render on a console of a fixed width.
@matthiaskoenig
matthiaskoenig merged commit 64eb38f into develop Oct 24, 2026
17 checks passed
@matthiaskoenig
matthiaskoenig deleted the feat/runner-progress branch October 24, 2026 21:28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Better progress reports with rich of the simulation runner

1 participant