{ "cells": [ { "cell_type": "markdown", "id": "0", "metadata": {}, "source": [ "# Profiling Struphy with scope-profiler\n", "\n", "This tutorial shows two ways to use `scope-profiler`:\n", "\n", "1. Profile a small standalone Python workload with `ProfileManager` region timing.\n", "2. Configure a Struphy `Simulation` with `ProfilingOptions`, including line profiling, and activate profiling at `sim.run(...)`.\n", "\n", "The same HDF5 output file can be inspected from Python, from the command-line interface, or in the terminal TUI." ] }, { "cell_type": "markdown", "id": "1", "metadata": {}, "source": [ "## Imports and output directory\n", "\n", "Use a small temporary directory so repeated notebook runs do not overwrite production simulation data." ] }, { "cell_type": "code", "execution_count": null, "id": "2", "metadata": {}, "outputs": [], "source": [ "from pathlib import Path\n", "import shutil\n", "import tempfile\n", "\n", "import numpy as np\n", "from scope_profiler import ProfileManager\n", "\n", "workdir = Path(tempfile.mkdtemp(prefix=\"struphy_profile_tutorial_\"))\n" ] }, { "cell_type": "code", "execution_count": null, "id": "3", "metadata": { "jupyter": { "source_hidden": true }, "nbsphinx": "hidden", "tags": [ "hide-input" ] }, "outputs": [], "source": [ "from contextlib import redirect_stderr, redirect_stdout\n", "from html import escape\n", "from io import StringIO\n", "\n", "from IPython.display import HTML, display\n", "\n", "\n", "def show_full_text(text: str):\n", " \"\"\"Render long text as HTML so notebook frontends do not truncate stream output.\"\"\"\n", " display(\n", " HTML(\n", " '
'\n",
    "            f\"{escape(text)}\"\n",
    "            \"
\"\n", " )\n", " )\n", "\n", "\n", "def capture_full_output(func, *args, **kwargs):\n", " stdout = StringIO()\n", " stderr = StringIO()\n", " with redirect_stdout(stdout), redirect_stderr(stderr):\n", " result = func(*args, **kwargs)\n", " text = stderr.getvalue() + stdout.getvalue()\n", " if text:\n", " show_full_text(text)\n", " return result\n" ] }, { "cell_type": "markdown", "id": "4", "metadata": {}, "source": [ "## 1. Profile standalone Python code\n", "\n", "`ProfileManager.profile_region(...)` profiles a `with` block. `@ProfileManager.profile(...)` profiles a decorated function. This first example only records region timings, which is enough for coarse timing and produces a small HDF5 profile file." ] }, { "cell_type": "code", "execution_count": null, "id": "5", "metadata": {}, "outputs": [], "source": [ "@ProfileManager.profile(\"demo: matrix multiply\")\n", "def matrix_work(n: int) -> float:\n", " a = np.arange(n * n, dtype=float).reshape(n, n)\n", " b = a.T.copy()\n", " c = a @ b\n", " return float(c.sum())\n", "\n", "\n", "profile_file = workdir / \"demo_scope_profile.h5\"\n", "\n", "with ProfileManager.session(\n", " file_path=str(profile_file),\n", " return_results=True,\n", " verbose=False,\n", ") as prof:\n", " with ProfileManager.profile_region(\"demo: total\"):\n", " total = 0.0\n", " for n in (16, 24, 32):\n", " total += matrix_work(n)\n", " print(f\"Total sum: {total:.2f}\")\n", "\n", "results = prof.results" ] }, { "cell_type": "markdown", "id": "6", "metadata": {}, "source": [ "The context manager finalizes the run and writes one HDF5 file. With `return_results=True`, the finalized result object is also available in memory." ] }, { "cell_type": "code", "execution_count": null, "id": "7", "metadata": {}, "outputs": [], "source": [ "results.print_summary(title=\"Standalone demo\", include=[r\"^demo:\"])" ] }, { "cell_type": "markdown", "id": "8", "metadata": {}, "source": [ "The same file can be inspected from Python. The CLI and TUI commands are shown later for terminal workflows.\n" ] }, { "cell_type": "code", "execution_count": null, "id": "9", "metadata": {}, "outputs": [], "source": [ "from scope_profiler import read_h5\n", "\n", "standalone_results = read_h5(profile_file)\n", "standalone_results.print_summary(title=\"Standalone HDF5 summary\", include=[r\"^demo:\"])\n" ] }, { "cell_type": "markdown", "id": "10", "metadata": {}, "source": [ "## 2. Profile a Struphy simulation\n", "\n", "Struphy instruments the important phases of `Simulation.run()` with `ProfileManager`: allocation and setup, the time-stepping loop (`model.integrate`), propagators and solvers, diagnostics, particle sorting, and output. A profiling session is only active when `sim.run(profiling_activated=True)` is called. This means the same `Simulation` setup can be used for an ordinary run or a measured run.\n", "\n", "For a useful performance experiment, keep the problem small enough to run quickly but make the time-stepping loop execute several times. Include a warm-up run when comparing configurations: compilation, cache creation, allocation, and filesystem setup can otherwise dominate the measurement. Use `save_step` to avoid measuring a workload dominated by output. Start with region timing; enable `use_line_profiler=True` only after the expensive region is known, because line profiling adds substantial overhead." ] }, { "cell_type": "code", "execution_count": null, "id": "11", "metadata": {}, "outputs": [], "source": [ "from struphy import EnvironmentOptions, ProfilingOptions, Simulation, Time, grids\n", "from struphy.models import Poisson\n", "\n", "env = EnvironmentOptions(\n", " out_folders=str(workdir),\n", " sim_folder=\"poisson_profile_demo\",\n", " # Saving every step is useful for a demo, but can dominate a benchmark.\n", " save_step=1,\n", ")\n", "\n", "profiling_opts = ProfilingOptions(\n", " file_path=str(workdir / \"poisson_profile.h5\"),\n", " # First locate the expensive region with region timing.\n", " use_line_profiler=False,\n", ")\n", "\n", "sim = Simulation(\n", " model=Poisson(),\n", " env=env,\n", " time_opts=Time(dt=0.01, Tend=0.01),\n", " grid=grids.TensorProductGrid(num_elements=(4, 4, 1)),\n", " profiling_opts=profiling_opts,\n", ")" ] }, { "cell_type": "code", "execution_count": null, "id": "12", "metadata": {}, "outputs": [], "source": [ "# This profiles the complete Simulation.run() call, including setup,\n", "# model.integrate(), diagnostics, and data output.\n", "sim.run(profiling_activated=True)\n", "struphy_profile_file = Path(profiling_opts.file_path)\n" ] }, { "cell_type": "code", "execution_count": null, "id": "13", "metadata": {}, "outputs": [], "source": [ "from scope_profiler import read_h5\n", "\n", "profile_results = read_h5(struphy_profile_file)\n", "region_names = sorted(region.name for region in profile_results.get_regions())\n", "print(\", \".join(region_names))" ] }, { "cell_type": "markdown", "id": "14", "metadata": {}, "source": [ "### Measure setup and time stepping separately\n", "\n", "The profile contains both one-time setup and repeated work. For a performance experiment, inspect them separately: setup is useful for allocation and initialization studies, while `model.integrate` and its children describe the cost per time step. For a longer benchmark, increase `Tend` so several steps are recorded, and set `save_step` larger when output is not part of the question. Include a warm-up run before comparing configurations because compilation, cache creation, allocation, and filesystem setup can otherwise dominate the measurement." ] }, { "cell_type": "code", "execution_count": null, "id": "15", "metadata": {}, "outputs": [], "source": [ "capture_full_output(\n", " profile_results.print_summary,\n", " title=\"What did Simulation.run() measure?\",\n", " include=[r\"^setup:\", r\"^model\\.integrate$\", r\"^prop: \", r\"^solve:\", r\"^kernel: \", r\"^save data$\"],\n", ")" ] }, { "cell_type": "markdown", "id": "16", "metadata": {}, "source": [ "### Line-profile output for selected Struphy regions\n", "\n", "To get line-by-line timing, repeat the run with `use_line_profiler=True` (and preferably a shorter `Tend`). The HDF5 file then contains line-profile records for decorated functions and profiled regions. The filter below prints a representative solver region:\n", "\n", "- `setup: total`, the top-level setup block in `Simulation.run`.\n", "- `solve: PoissonSolve`, the Poisson propagator solve call.\n", "\n", "The source column is shown because these regions come from real Struphy source files." ] }, { "cell_type": "code", "execution_count": null, "id": "17", "metadata": {}, "outputs": [], "source": [ "line_profile_opts = ProfilingOptions(\n", " file_path=str(workdir / \"poisson_line_profile.h5\"),\n", " use_line_profiler=True,\n", ")\n", "line_sim = Simulation(\n", " model=Poisson(),\n", " env=EnvironmentOptions(out_folders=str(workdir), sim_folder=\"poisson_line_demo\", save_step=1),\n", " time_opts=Time(dt=0.01, Tend=0.01),\n", " grid=grids.TensorProductGrid(num_elements=(4, 4, 1)),\n", " profiling_opts=line_profile_opts,\n", ")\n", "line_sim.run(profiling_activated=True)\n", "line_profile_file = Path(line_profile_opts.file_path)" ] }, { "cell_type": "code", "execution_count": null, "id": "18", "metadata": {}, "outputs": [], "source": [ "from scope_profiler.line_profile_cli import print_line_profile\n", "\n", "print_line_profile(\n", " line_profile_file,\n", " region=r\"^prop: PoissonSolve\",\n", " display_html=True,\n", ")" ] }, { "cell_type": "markdown", "id": "19", "metadata": {}, "source": [ "For a parameter file generated by `struphy params `, the same pattern is:\n", "\n", "```python\n", "profiling_opts = ProfilingOptions(\n", " file_path=\"my_profile.h5\",\n", " use_line_profiler=True,\n", ")\n", "\n", "sim = Simulation(..., profiling_opts=profiling_opts)\n", "sim.run(profiling_activated=True)\n", "```\n", "\n", "Omit the `profiling_activated` keyword for normal production runs without profiling overhead." ] }, { "cell_type": "markdown", "id": "20", "metadata": {}, "source": [ "## 3. Plot and inspect the profile\n", "\n", "There are three useful levels of inspection: the summary table finds expensive regions; the duration chart ranks them; and the Gantt/flame views explain when they run and how parent/child time is composed. A region's *inclusive* duration includes its children, so do not add the `model.integrate`, propagator, solver, and kernel bars together unless you intentionally want overlapping costs.\n", "\n", "`scope-profiler` also provides a CLI and a terminal TUI for interactive work outside the notebook:\n", "\n", "```bash\n", "scope-profiler inspect profiling_data.h5\n", "scope-profiler line-profile profiling_data.h5\n", "scope-profiler plot durations profiling_data.h5 -o figures --sort-by total --top-n 20\n", "scope-profiler plot durations profiling_data.h5 -o figures --stack-children --sort-by total --top-n 12\n", "scope-profiler plot gantt profiling_data.h5 -o figures --min-duration 0.0001 --collapse-depth 4\n", "scope-profiler plot flame_graph profiling_data.h5 -o figures\n", "scope-profiler plot flame_chart profiling_data.h5 -o figures\n", "scope-profiler plot quick profiling_data.h5 -o figures\n", "scope-profiler tui profiling_data.h5\n", "```\n", "\n", "We recommend checking out the [scope-profiler documentation](https://max-models.github.io/scope-profiler/) for details on postprocessing using the tool.\n", "\n", "The `--stack-children` option splits each duration bar into self time plus direct children. Use `--collapse-depth` and `--min-duration` to make a busy Gantt chart readable. `flame_graph` aggregates call stacks; `flame_chart` preserves their time position." ] }, { "cell_type": "markdown", "id": "21", "metadata": {}, "source": [ "### IPython magics\n", "\n", "The magics are useful for quick notebook experiments and comparisons. `%%scope` records a notebook cell as one named region; `%scope_load` imports the HDF5 profile produced by `sim.run()` into the same in-memory registry. Use the Struphy HDF5 profile for detailed nested run data, and magics for small local measurements or before/after comparisons." ] }, { "cell_type": "code", "execution_count": null, "id": "22", "metadata": {}, "outputs": [], "source": [ "%load_ext scope_profiler.ipython_magics" ] }, { "cell_type": "code", "execution_count": null, "id": "23", "metadata": {}, "outputs": [], "source": [ "%%scope notebook_overhead -p\n", "sum(i * i for i in range(10_000))\n" ] }, { "cell_type": "code", "execution_count": null, "id": "24", "metadata": {}, "outputs": [], "source": [ "%scope_load {struphy_profile_file} -n struphy_run -q\n", "%scope_last struphy_run --include ^setup: -p" ] }, { "cell_type": "markdown", "id": "25", "metadata": {}, "source": [ "Other useful magics are `%%scope_line` for a short decorated function, `%%scope_recursive` for exploratory tracing when no regions exist, `%scope_df` for pandas analysis, `%scope_compare` for two notebook runs, and `%scope_export` for `.prof` or speedscope output. Recursive tracing is noisy and expensive, so use it to discover candidate functions rather than to measure production performance." ] }, { "cell_type": "code", "execution_count": null, "id": "26", "metadata": {}, "outputs": [], "source": [ "capture_full_output(\n", " profile_results.print_summary,\n", " title=\"Poisson profiling summary\",\n", " include=[r\"^setup:\", r\"^model\\.integrate$\", r\"^prop: \", r\"^solve:\", r\"^update_feec_variables$\"],\n", ")\n" ] }, { "cell_type": "code", "execution_count": null, "id": "27", "metadata": {}, "outputs": [], "source": [ "from scope_profiler import plot_durations, plot_flame, plot_gantt\n", "\n", "include_regions = [\n", " r\"^setup:\",\n", " r\"^model\\.integrate$\",\n", " r\"^prop: \",\n", " r\"^solve:\",\n", " r\"^kernel: \",\n", " r\"^update_feec_variables$\",\n", "]" ] }, { "cell_type": "code", "execution_count": null, "id": "28", "metadata": {}, "outputs": [], "source": [ "\n", "duration_figure, _ = plot_durations(\n", " profile_results,\n", " include=include_regions,\n", " sort_by=\"total\",\n", " top_n=12,\n", " stack_children=True,\n", " filepath=str(workdir / \"durations_with_children.png\"),\n", " return_fig=True,\n", ")\n", "\n" ] }, { "cell_type": "code", "execution_count": null, "id": "29", "metadata": {}, "outputs": [], "source": [ "gantt_figure, _ = plot_gantt(\n", " profile_results,\n", " include=include_regions,\n", " min_duration=1e-4,\n", " collapse_depth=4,\n", " filepath=str(workdir / \"gantt.png\"),\n", " return_fig=True,\n", ")\n", "\n", "flame_figure = plot_flame(\n", " profile_results,\n", " include=include_regions,\n", " filepath=str(workdir / \"flame_graph.png\"),\n", " return_fig=True,\n", ")" ] }, { "cell_type": "markdown", "id": "30", "metadata": {}, "source": [ "The duration chart ranks regions by aggregate time and stacks self time with direct children. The Gantt chart shows the execution timeline and can expose idle time, serialization, or rank imbalance. The flame graph reconstructs nested calls and is useful for reading parent/child relationships between `setup`, `model.integrate`, propagators, solvers, and kernels. The figures are also saved under `workdir`, so the same workflow works in a headless batch job." ] }, { "cell_type": "markdown", "id": "31", "metadata": {}, "source": [ "## Cleanup\n", "\n", "Remove the temporary directory when you no longer need the profiling files." ] }, { "cell_type": "code", "execution_count": null, "id": "32", "metadata": {}, "outputs": [], "source": [ "# shutil.rmtree(workdir)" ] } ], "metadata": { "kernelspec": { "display_name": ".venv (3.12.3)", "language": "python", "name": "python3" }, "language_info": { "codemirror_mode": { "name": "ipython", "version": 3 }, "file_extension": ".py", "mimetype": "text/x-python", "name": "python", "nbconvert_exporter": "python", "pygments_lexer": "ipython3", "version": "3.12.3" }, "nbsphinx": { "execute": "always" } }, "nbformat": 4, "nbformat_minor": 5 }