Line-by-line profiling#
Install for this page:
pip install "scope-profiler[line-profiler]".
scope-profiler can integrate line_profiler to give you per-source-line timing breakdowns of decorated functions, alongside the usual region-level statistics.
Installation#
pip install "scope-profiler[line-profiler]"
Enabling line profiling#
Pass use_line_profiler=True to setup():
from scope_profiler import ProfileManager
ProfileManager.setup(use_line_profiler=True)
This selects LineProfilerRegion for all regions. Each region records
nanosecond timestamps and enables line_profiler tracing for decorated
functions and for the function containing a with scope.
Example#
import math
import random
from scope_profiler import ProfileManager
ProfileManager.setup(use_line_profiler=True)
@ProfileManager.profile("compute")
def compute(N=50_000):
s = 0.0
for _ in range(N):
x = random.random()
s += math.sin(x) * math.sqrt(x + 1.0)
return s
@ProfileManager.profile("allocate")
def allocate(N=100_000):
a = [i * i for i in range(N)]
b = []
for i in range(N):
b.append(i * i)
return a, b
def run_scope_only():
with ProfileManager.region("scope_only"):
total = sum(range(100_000))
return total
compute()
allocate()
run_scope_only()
ProfileManager.finalize()
Output:
╭──────────────────────────────────────────────────────╮
│ region % session total [s] │
├──────────────────────────────────────────────────────┤
│ scope_profiler.session 100.00% 0.101074 │
│ └─ (own) 2.05% 0.002074 │
│ └─ compute 48.44% 0.048961 │
│ └─ allocate 49.51% 0.050040 │
╰──────────────────────────────────────────────────────╯
╭─ Info ──────────────────────────────────────────────────────────────────────╮
│ Summary: profiling_data.h5 (1 rank) │
│ │
│ Explore: │
│ Inspect: scope-profiler inspect profiling_data.h5 │
│ TUI: scope-profiler tui profiling_data.h5 │
│ │
│ Visualize and export: │
│ Plot: scope-profiler plot default profiling_data.h5 -o plots --show │
│ Report: scope-profiler report profiling_data.h5 -o report.html │
│ Export: scope-profiler export plot-data profiling_data.h5 -o data │
│ Lines: scope-profiler line-profile 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. │
│ % session uses wall-clock coverage; overlapping recursive calls count once. │
╰─────────────────────────────────────────────────────────────────────────────╯
Timer unit: 1e-09 s
Total time: 0.0406542 s
File: examples/ex_line_profiling.py
Function: compute at line 42
Line # Hits Time Per Hit % Time Line Contents
==============================================================
42 @ProfileManager.profile("compute")
43 def compute(N=50_000):
44 """Some mixed math to illustrate per-line costs."""
45 1 251.0 251.0 0.0 s = 0.0
46 50001 7445008.0 148.9 18.3 for _ in range(N):
47 50000 10560673.0 211.2 26.0 x = random.random()
48 50000 22647884.0 453.0 55.7 s += math.sin(x) * math.sqrt(x + 1.0)
49 1 351.0 351.0 0.0 return s
Timer unit: 1e-09 s
Total time: 3.51e-07 s
File: /home/runner/work/scope-profiler/scope-profiler/src/scope_profiler/profile_manager.py
Function: __enter__ at line 320
Line # Hits Time Per Hit % Time Line Contents
==============================================================
320 def __enter__(self):
321 self._manager.setup(**self._setup_kwargs)
322 # Keep every region created in the session under one interval. Apart
323 # from making the total elapsed time explicit, this gives call-graph
324 # consumers a single root instead of a forest whose display order can
325 # be mistaken for execution order (notably by SnakeViz).
326 self._root_region = self._manager.profile_region(self.ROOT_REGION_NAME)
327 self._root_region.__enter__()
328 1 351.0 351.0 100.0 return self
Timer unit: 1e-09 s
Total time: 0.0500175 s
File: examples/ex_line_profiling.py
Function: run_allocate at line 66
Line # Hits Time Per Hit % Time Line Contents
==============================================================
66 def run_allocate(N=100_000):
67 """The enclosing function is line-profiled automatically."""
68 with ProfileManager.region("allocate"):
69 1 50017466.0 5e+07 100.0 return allocate(N)
70 print("print allocate")
The line-by-line table shows, for each source line:
Column |
Meaning |
|---|---|
Hits |
Number of times the line was executed |
Time |
Total time spent on that line (in timer units) |
Per Hit |
Average time per execution |
% Time |
Fraction of the function’s total time |
Decorator vs. context manager#
Decorator (
@ProfileManager.profile) — automatically registers the function withline_profiler. This is the primary use case.Context manager (
with ProfileManager.region()) — enables/disables the profiler around the block and automatically registers the active caller function. Lines executed in the scope are included even when the function is not decorated. Passingfunctions=[...]remains useful when the scope should also profile other functions it calls.
Accessing stats programmatically#
region = ProfileManager.get_region("compute")
# Get the line_profiler stats object
stats = region.get_stats()
# Print formatted output
region.print_stats()
The generated example prints a standard line_profiler table:
Total time: 0.0406542 s
File: examples/ex_line_profiling.py
Function: compute at line 42
Line # Hits Time Per Hit % Time Line Contents
==============================================================
42 @ProfileManager.profile("compute")
43 def compute(N=50_000):
44 """Some mixed math to illustrate per-line costs."""
45 1 251.0 251.0 0.0 s = 0.0
46 50001 7445008.0 148.9 18.3 for _ in range(N):
47 50000 10560673.0 211.2 26.0 x = random.random()
48 50000 22647884.0 453.0 55.7 s += math.sin(x) * math.sqrt(x + 1.0)
49 1 351.0 351.0 0.0 return s
Line-profiler data is also persisted in the HDF5 output. After reopening
a run, access the rank-local records through
ProfilingResults.line_profile:
from scope_profiler import read_h5
results = read_h5("profiling_data.h5")
for record in results.line_profile.get(0, []):
seconds_per_unit = record["unit"]
for line, hits, elapsed in zip(
record["line_numbers"], record["hits"], record["times"]
):
print(record["function"], line, hits, elapsed * seconds_per_unit)
This prints the persisted records from the generated example:
compute 45 1 2.51e-07
compute 46 50001 0.007445008
compute 47 50000 0.010560673000000001
compute 48 50000 0.022647884
compute 49 1 3.51e-07
run_allocate 69 1 0.050017466000000003
Each record is associated with its region, source file, and function.
The stored times values use the unit reported by line_profiler.
The same data can be printed from the command line:
scope-profiler line-profile profiling_data.h5
scope-profiler line-profile profiling_data.h5 --rank 0 --function compute
The filtered command produces:
Line profile: profiling_data.h5
Rank 0 | compute | compute (ex_line_profiling.py:42)
╭────────┬────────┬────────────┬───────────────┬──────────┬──────────────────────╮
│ line │ hits │ time [s] │ per hit [s] │ % time │ source │
├────────┼────────┼────────────┼───────────────┼──────────┼──────────────────────┤
│ 45 │ 1 │ 2.51e-07 │ 2.51e-07 │ 0.00 │ <source unavailable> │
│ 46 │ 50001 │ 0.00744501 │ 1.48897e-07 │ 18.31 │ <source unavailable> │
│ 47 │ 50000 │ 0.0105607 │ 2.11213e-07 │ 25.98 │ <source unavailable> │
│ 48 │ 50000 │ 0.0226479 │ 4.52958e-07 │ 55.71 │ <source unavailable> │
│ 49 │ 1 │ 3.51e-07 │ 3.51e-07 │ 0.00 │ <source unavailable> │
╰────────┴────────┴────────────┴───────────────┴──────────┴──────────────────────╯
Overhead considerations#
Line profiling adds ~40 µs per call because line_profiler instruments
every source line in the function. It is designed for targeted
debugging, not for always-on use in hot loops. See Profiling overhead for
benchmark data.