Line-by-line profiling

Download notebook View on GitHubRun when the site was built.

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

The cells below profile into a temporary directory, so nothing is left in the working directory. The example is first written to a script file and then run with %run: line_profiler reports the source of a function from its file, and the command-line viewer further down reads the source lines from that file too, which a function defined directly in a notebook cell does not have.

%%writefile ex_line_profiling.py
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(verbose_line_profiler=True)

Writing ex_line_profiling.py

%run ex_line_profiling.py

Show output

  ╭───────────────────────────╮
  │ region        total [s]   │
  ├───────────────────────────┤
  │ compute       0.039333    │
  │ allocate      0.040350    │
  │ scope_only    0.000890    │
  ╰───────────────────────────╯

  ╭─ 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.    │
  ╰──────────────────────────────────────────────────────────────────────────╯

Timer unit: 1e-09 s

Total time: 0.0315502 s
File: /tmp/scope-profiler-lines-b1xldzsn/ex_line_profiling.py
Function: compute at line 9

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     9                                           @ProfileManager.profile("compute")
    10                                           def compute(N=50_000):
    11         1       1001.0   1001.0      0.0      s = 0.0
    12     50001    9164135.0    183.3     29.0      for _ in range(N):
    13     50000   10452651.0    209.1     33.1          x = random.random()
    14     50000   11930851.0    238.6     37.8          s += math.sin(x) * math.sqrt(x + 1.0)
    15         1       1573.0   1573.0      0.0      return s

Timer unit: 1e-09 s

Total time: 0.0315832 s
File: /tmp/scope-profiler-lines-b1xldzsn/ex_line_profiling.py
Function: allocate at line 18

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    18                                           @ProfileManager.profile("allocate")
    19                                           def allocate(N=100_000):
    20         1    3963437.0 3.96e+06     12.5      a = [i * i for i in range(N)]
    21         1        391.0    391.0      0.0      b = []
    22    100001   14744750.0    147.4     46.7      for i in range(N):
    23    100000   12873143.0    128.7     40.8          b.append(i * i)
    24         1       1522.0   1522.0      0.0      return a, b

Timer unit: 1e-09 s

Total time: 0 s
File: /tmp/scope-profiler-lines-b1xldzsn/ex_line_profiling.py
Function: run_scope_only at line 27

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
    27                                           def run_scope_only():
    28                                               with ProfileManager.region("scope_only"):
    29                                                   total = sum(range(100_000))
    30                                               return total

The output of the run is the region summary followed by a standard line_profiler table for every profiled function (finalize(verbose_line_profiler=True) prints the tables; a plain finalize() only prints the region summary).

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 with line_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. Passing functions=[...] remains useful when the scope should also profile other functions it calls.

Accessing stats programmatically

from scope_profiler import ProfileManager

region = ProfileManager.get_region("compute")

# Get the line_profiler stats object
stats = region.get_stats()

# Print formatted output
region.print_stats()

Show output

Timer unit: 1e-09 s

Total time: 0.0315502 s
File: /tmp/scope-profiler-lines-b1xldzsn/ex_line_profiling.py
Function: compute at line 9

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     9                                           @ProfileManager.profile("compute")
    10                                           def compute(N=50_000):
    11         1       1001.0   1001.0      0.0      s = 0.0
    12     50001    9164135.0    183.3     29.0      for _ in range(N):
    13     50000   10452651.0    209.1     33.1          x = random.random()
    14     50000   11930851.0    238.6     37.8          s += math.sin(x) * math.sqrt(x + 1.0)
    15         1       1573.0   1573.0      0.0      return s

print_stats() prints a standard line_profiler table.

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)

Show output

compute 11 1 1.001e-06
compute 12 50001 0.009164135
compute 13 50000 0.010452651
compute 14 50000 0.011930851000000001
compute 15 1 1.573e-06
allocate 20 1 0.003963437
allocate 21 1 3.9100000000000005e-07
allocate 22 100001 0.014744750000000001
allocate 23 100000 0.012873143
allocate 24 1 1.522e-06

The lines above are the persisted records of the example run: function, line number, hits and seconds spent on that line.

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

Show output

/bin/bash: line 1: scope-profiler: command not found
/bin/bash: line 1: scope-profiler: command not found

The second, filtered command prints only the line table of compute.

Fortran and C code

Line-level profiling covers Python source only, because it relies on line_profiler. Native Fortran and C/C++ regions record region timings and an optional source file and line, but no per-line breakdown inside the region.

To get line-level detail for native code, narrow the region to the code you care about (a region per loop or statement block), or profile the compiled program with a native tool such as perf annotate, gprof -l, or valgrind --tool=callgrind (build with -g). Use the scope-profiler regions to find which region is hot, then use the native tool on that code.

Overhead considerations

Line profiling adds ~50 µ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.