2. Post-processing profiling data#

Install for this tutorial: pip install "scope-profiler[pproc]"; pandas is used for the DataFrame examples.

This notebook is a tour of the analysis API: ProfilingResults and the MPIRegion / Region objects it hands out.

The one thing worth memorising: every duration and timestamp in this API is in seconds, converted from the nanoseconds stored on disk.

import tempfile
import time
from pathlib import Path

from scope_profiler import ProfileManager, read_h5

WORKDIR = Path(tempfile.mkdtemp(prefix="scope-profiler-tutorial-"))
DATA_FILE = WORKDIR / "profiling_data.h5"

ProfileManager.setup(file_path=str(DATA_FILE))


@ProfileManager.profile("assemble")
def assemble(scale):
    time.sleep(0.004 * scale)


with ProfileManager.region("setup"):
    time.sleep(0.02)

for step in range(5):
    with ProfileManager.region("timestep"):
        assemble(scale=1 + step % 3)
        with ProfileManager.region("solve"):
            time.sleep(0.003)

ProfileManager.finalize(verbose=False)
results = read_h5(DATA_FILE)
results

<ProfilingResults 'profiling_data.h5': 4 region(s), 1 rank(s)>

`ProfilingResults` is a mapping of regions#

It behaves like an ordered mapping from region name to region, so the usual Python idioms work.

print("regions:", results.region_names)
print("count:", len(results))
print("'solve' recorded?", "solve" in results)
print("ranks in file:", results.num_ranks)

for region in results:
    print(f"  {region.name:<10} {region.num_calls:>3} calls")

regions: ['assemble', 'setup', 'timestep', 'solve']
count: 4
'solve' recorded? True
ranks in file: 1
  assemble     5 calls
  setup        1 calls
  timestep     5 calls
  solve        5 calls

Asking for something that is not there tells you what is there:

try:
    results["sovle"]  # typo
except KeyError as exc:
    print(exc)

"No region named 'sovle' in /tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5. Available regions: ['assemble', 'setup', 'timestep', 'solve']"

Two levels: MPIRegion and Region#

results["solve"] returns an MPIRegion — the region across every rank that recorded it. Indexing it by rank gives a Region, the timings from that one rank.

For a serial run there is only rank 0, but the two levels are the same API you use for an MPI run.

timestep = results["timestep"]

print("aggregated over ranks")
print("  ranks       :", timestep.ranks)
print("  num_calls   :", timestep.num_calls)
print("  total   [s] :", timestep.total_duration)
print("  average [s] :", timestep.average_duration)
print("  min/max [s] :", timestep.min_duration, timestep.max_duration)
print("  std     [s] :", timestep.std_duration)

rank0 = timestep[0]
print("\nrank 0 only")
print("  durations [s]:", rank0.durations)
print("  start times [s]:", rank0.start_times)
print("  summary:", rank0.get_summary())

aggregated over ranks
  ranks       : [0]
  num_calls   : 5
  total   [s] : 0.051952459
  average [s] : 0.0103904918
  min/max [s] : 0.007170388 0.015161241
  std     [s] : 0.002962193788557623

rank 0 only
  durations [s]: [0.00729908 0.01116411 0.01516124 0.00717039 0.01115765]
  start times [s]: [151.80791315 151.81521668 151.82638527 151.84155175 151.84872659]
  summary: {'num_calls': 5, 'total_duration': 0.051952459, 'inclusive_duration': 0.051952459, 'exclusive_duration': 0.000186458, 'average_duration': 0.0103904918, 'min_duration': 0.007170388, 'max_duration': 0.015161241, 'first_duration': 0.007299078, 'last_duration': 0.011157645, 'std_duration': 0.0029621937885576225}

Per-rank breakdowns are available as dictionaries keyed by rank, which is where load imbalance shows up in an MPI run:

print("calls per rank :", timestep.num_calls_per_rank())
print("total per rank :", timestep.total_durations())
print("avg per rank   :", timestep.average_durations())
print("max per rank   :", timestep.max_durations())

calls per rank : {0: 5}
total per rank : {0: 0.051952459}
avg per rank   : {0: 0.0103904918}
max per rank   : {0: 0.015161241}

Summaries and DataFrames#

summary() returns one dict per region, aggregated over ranks. print_summary() formats the same data as a table.

results.print_summary()

  ╭─────────────────────────────────╮
  │ region              total [s]   │
  ├─────────────────────────────────┤
  │ setup               0.020085    │
  │ timestep (5x)       0.051952    │
  │ └─ (own)               0.000186 │
  │ └─ assemble (5x)       0.036391 │
  │ └─ solve (5x)          0.015375 │
  ╰─────────────────────────────────╯

  ╭─ Info ──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────╮
  │ Summary: ../../../../../../tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5 (1 rank)                                      │
  │                                                                                                                                 │
  │ Explore:                                                                                                                        │
  │   Inspect: scope-profiler inspect ../../../../../../tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5                      │
  │   TUI:     scope-profiler tui ../../../../../../tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5                          │
  │                                                                                                                                 │
  │ Visualize and export:                                                                                                           │
  │   Plot:    scope-profiler plot default ../../../../../../tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5 -o plots --show │
  │   Report:  scope-profiler report ../../../../../../tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5 -o report.html        │
  │   Export:  scope-profiler export plot-data ../../../../../../tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5 -o data     │
  │   Lines:   scope-profiler line-profile ../../../../../../tmp/scope-profiler-tutorial-d_d8_xni/profiling_data.h5                 │
  │                                                                                                                                 │
  │ Compare runs:                                                                                                                   │
  │   Diff:    scope-profiler diff BASE.h5 CANDIDATE.h5                                                                             │
  │   Check:   scope-profiler check BASE.h5 CANDIDATE.h5                                                                            │
  │                                                                                                                                 │
  │ Durations are in seconds.                                                                                                       │
  │ Regions may nest, so the summed total can exceed the wall-clock time.                                                           │
  ╰─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────╯

for row in results.summary():
    print(row)

{'name': 'setup', 'num_ranks': 1, 'num_calls': 1, 'total_duration': 0.020084566, 'inclusive_duration': 0.020084566, 'exclusive_duration': 0.020084566, 'average_duration': 0.020084566, 'min_duration': 0.020084566, 'max_duration': 0.020084566, 'first_duration': 0.020084566, 'last_duration': 0.020084566, 'std_duration': 0.0, 'tags': (), 'p50_duration': 0.020084566, 'p95_duration': 0.020084566, 'p99_duration': 0.020084566, 'rank_imbalance': 0.0, 'rank_imbalance_pct': 0.0, 'p50': 0.020084566, 'p95': 0.020084566, 'p99': 0.020084566, 'imbalance': 0.0}
{'name': 'timestep', 'num_ranks': 1, 'num_calls': 5, 'total_duration': 0.051952459, 'inclusive_duration': 0.051952459, 'exclusive_duration': 0.000186458, 'average_duration': 0.0103904918, 'min_duration': 0.007170388, 'max_duration': 0.015161241, 'first_duration': 0.007299078, 'last_duration': 0.011157645, 'std_duration': 0.002962193788557623, 'tags': (), 'p50_duration': 0.011157645, 'p95_duration': 0.0143618142, 'p99_duration': 0.01500135564, 'rank_imbalance': 0.0, 'rank_imbalance_pct': 0.0, 'p50': 0.011157645, 'p95': 0.0143618142, 'p99': 0.01500135564, 'imbalance': 0.0}
{'name': 'assemble', 'num_ranks': 1, 'num_calls': 5, 'total_duration': 0.036391272, 'inclusive_duration': 0.036391272, 'exclusive_duration': 0.036391272, 'average_duration': 0.007278254400000001, 'min_duration': 0.004080088, 'max_duration': 0.012074417, 'first_duration': 0.004085358, 'last_duration': 0.008074167, 'std_duration': 0.0029899126903858986, 'tags': (), 'p50_duration': 0.008074167, 'p95_duration': 0.011274982, 'p99_duration': 0.01191453, 'rank_imbalance': 0.0, 'rank_imbalance_pct': 0.0, 'p50': 0.008074167, 'p95': 0.011274982, 'p99': 0.01191453, 'imbalance': 0.0}
{'name': 'solve', 'num_ranks': 1, 'num_calls': 5, 'total_duration': 0.015374729, 'inclusive_duration': 0.015374729, 'exclusive_duration': 0.015374729, 'average_duration': 0.0030749458, 'min_duration': 0.003072538, 'max_duration': 0.003080052, 'first_duration': 0.003080052, 'last_duration': 0.003072538, 'std_duration': 2.622732956288094e-06, 'tags': (), 'p50_duration': 0.00307409, 'p95_duration': 0.0030788896, 'p99_duration': 0.00307981952, 'rank_imbalance': 0.0, 'rank_imbalance_pct': 0.0, 'p50': 0.00307409, 'p95': 0.0030788896, 'p99': 0.00307981952, 'imbalance': 0.0}

With pandas installed (it comes with the plot extra), to_dataframe() gives you the same data ready for sorting, filtering and plotting.

frame = results.to_dataframe()
frame.sort_values("total_duration", ascending=False)

	name	num_ranks	num_calls	total_duration	inclusive_duration	exclusive_duration	average_duration	min_duration	max_duration	first_duration	…	tags	p50_duration	p95_duration	p99_duration	p50	p95	p99
1	timestep	1	5	0.051952	0.051952	0.000186	0.010390	0.007170	0.015161	0.007299	…	()	0.011158	0.014362	0.015001	0.011158	0.014362	0.015001
2	assemble	1	5	0.036391	0.036391	0.036391	0.007278	0.004080	0.012074	0.004085	…	()	0.008074	0.011275	0.011915	0.008074	0.011275	0.011915
0	setup	1	1	0.020085	0.020085	0.020085	0.020085	0.020085	0.020085	0.020085	…	()	0.020085	0.020085	0.020085	0.020085	0.020085	0.020085
3	solve	1	5	0.015375	0.015375	0.015375	0.003075	0.003073	0.003080	0.003080	…	()	0.003074	0.003079	0.003080	0.003074	0.003079	0.003080

4 rows × 22 columns

per_rank=True emits one row per (region, rank) instead — the shape you want for load-balance analysis.

results.to_dataframe(per_rank=True)

	name	num_calls	total_duration	inclusive_duration	exclusive_duration	average_duration	min_duration	max_duration	first_duration	last_duration	std_duration	p50_duration	p95_duration	p99_duration
0	setup	1	0.020085	0.020085	0.020085	0.020085	0.020085	0.020085	0.020085	0.020085	0.000000	0.020085	0.020085	0.020085
1	timestep	5	0.051952	0.051952	0.000186	0.010390	0.007170	0.015161	0.007299	0.011158	0.002962	0.011158	0.014362	0.015001
2	assemble	5	0.036391	0.036391	0.036391	0.007278	0.004080	0.012074	0.004085	0.008074	0.002990	0.008074	0.011275	0.011915
3	solve	5	0.015375	0.015375	0.015375	0.003075	0.003073	0.003080	0.003080	0.003073	0.000003	0.003074	0.003079	0.003080

# Share of total recorded time per region.
frame = frame.assign(share=lambda df: df.total_duration / df.total_duration.sum())
frame[["name", "num_calls", "total_duration", "share"]].sort_values(
    "share", ascending=False
)

	name	num_calls	total_duration	share
1	timestep	5	0.051952	0.419638
2	assemble	5	0.036391	0.293945
0	setup	1	0.020085	0.162230
3	solve	5	0.015375	0.124187

Selecting regions#

get_regions(), summary(), to_dataframe() and the plotting functions all take include / exclude, which are regular expressions matched against the region name (via re.match, so they anchor at the start).

print([region.name for region in results.get_regions(include="s")])
print([region.name for region in results.get_regions(exclude=["setup", "assemble"])])
print([row["name"] for row in results.summary(include=["solve", "timestep"])])

['setup', 'solve']
['timestep', 'solve']
['timestep', 'solve']

Run metadata#

Each file carries the environment it was recorded in: the host and CPU, the loaded environment modules, the Slurm job it ran under, and selected environment variables such as PATH and VIRTUAL_ENV. This is what tells two otherwise identical runs apart months later.

for key, value in sorted(results.metadata.items()):
    # PATH and friends run to thousands of characters; clip them for display.
    text = str(value)
    if len(text) > 70:
        text = text[:70] + " […]"
    print(f"{key:>24}: {text}")

        chip_information: AMD EPYC 7763 64-Core Processor
        finalize_time_ns: 151859991735
                mpi_size: 1
               num_nodes: 1
         omp_num_threads: 4
                platform: Linux-6.17.0-1022-azure-x86_64-with-glibc2.39
          python_version: 3.10.22
  scope_profiler_version: 0.7.4
           start_time_ns: 151786002816
               timestamp: 2026-10-16T14:13:15.104525+00:00
             total_cores: 4

scope-profiler inspect prints the same metadata grouped and readable — together with per-region statistics — straight from the command line:

scope-profiler inspect profiling_data.h5
scope-profiler inspect profiling_data.h5 --metadata-only

write_metadata_json() exports it instead, with one entry per file and no clipping of long values:

from scope_profiler.inspection import write_metadata_json

payload = write_metadata_json(DATA_FILE, WORKDIR / "metadata.json")
print(sorted(payload["files"][0]["metadata"])[:8])

['chip_information', 'finalize_time_ns', 'mpi_size', 'num_nodes', 'omp_num_threads', 'platform', 'python_version', 'scope_profiler_version']

Exporting statistics#

collect_region_statistics() builds a JSON-ready dict (durations in seconds, with a units field spelling that out), and write_region_statistics_json() writes it to a file. Both accept several runs at once for run comparisons.

from scope_profiler import collect_region_statistics, write_region_statistics_json

stats = collect_region_statistics(results, include="solve")
print(stats["units"])
print(stats["files"][0]["region_statistics"]["solve"])

stats_path = WORKDIR / "region_statistics.json"
write_region_statistics_json(results, stats_path)
print("wrote", stats_path)

{'durations': 'seconds'}
{'count': 5, 'average_duration_seconds': 0.0030749458, 'min_duration_seconds': 0.003072538, 'max_duration_seconds': 0.003080052, 'first_duration_seconds': 0.003080052, 'last_duration_seconds': 0.003072538, 'std_duration_seconds': 2.622732956288094e-06, 'total_duration_seconds': 0.015374729, 'per_rank': {'0': {'count': 5, 'average_duration_seconds': 0.0030749458, 'min_duration_seconds': 0.003072538, 'max_duration_seconds': 0.003080052, 'first_duration_seconds': 0.003080052, 'last_duration_seconds': 0.003072538, 'std_duration_seconds': 2.622732956288094e-06, 'total_duration_seconds': 0.015374729}}}
wrote /tmp/scope-profiler-tutorial-d_d8_xni/region_statistics.json

Next#

3. Visualizing results turns these numbers into Gantt, flame and duration charts, and 5. Custom analysis goes below the summaries to the individual calls.

2. Post-processing profiling data

Contents