Profiling PDAL Pipelines with cProfile and py-spy

This page finds where a PDAL job actually spends its time — using the pipeline’s own stage metadata first, py-spy --native when that is not enough, and cProfile only for the Python that surrounds the pipeline. The recurring finding is that reading and decompressing dominates, and the filters teams spend their time tuning are a minority of the cost, which changes what is worth optimising.

Why you hit this

A PDAL pipeline is a Python object wrapping a C++ execution graph, and that boundary is where naive profiling fails. cProfile sees one call to execute() taking eleven minutes and reports nothing else, because everything below it is native. The result is that people optimise the Python around the pipeline — the file listing, the JSON construction — which is measured in milliseconds, while the eleven minutes stay exactly where they were.

Prerequisites

  • PDAL 2.6+ with Python bindings, plus py-spy>=0.3 (pip install py-spy) and psutil>=5.9.
  • Debug symbols available for native frames. The conda-forge PDAL builds carry enough for py-spy --native to resolve stage names.
  • A representative tile — tens of millions of points, not a test fixture.
  • On Linux, either root or sysctl kernel.yama.ptrace_scope=0 so py-spy can attach to a running process.

Step-by-Step

1. Read the stage timings PDAL already reports

Before reaching for a profiler, ask the pipeline. PDAL records per-stage metadata including how long each stage ran.

python
import json
import pdal

spec = {"pipeline": [
    "tile_utm33n.laz",
    {"type": "filters.outlier", "method": "statistical", "mean_k": 12, "multiplier": 2.5},
    {"type": "filters.smrf", "window": 18.0, "slope": 0.2, "threshold": 0.45},
    {"type": "filters.range", "limits": "Classification[2:2]"},
    {"type": "writers.las", "filename": "ground.laz", "forward": "all"},
]}

p = pdal.Pipeline(json.dumps(spec))
n = p.execute()

meta = p.metadata["metadata"]
for stage, m in meta.items():
    if isinstance(m, dict) and "stage_wall_time" in m:
        print(f"{stage:<28} {m['stage_wall_time']:8.2f}s")
print(f"{n:,} points through the pipeline")

This costs nothing and answers the question most of the time. A stage taking 60% of the run is the one to think about, and no flame graph is needed to establish that.

2. Separate I/O from computation

The reader’s time is decompression plus disk, and those respond to completely different fixes. Separating them takes one extra run against an uncompressed copy.

python
import time
import json
import pdal

def time_read(path):
    t0 = time.perf_counter()
    p = pdal.Pipeline(json.dumps({"pipeline": [path]}))
    n = p.execute()
    return time.perf_counter() - t0, n

laz_s, n = time_read("tile_utm33n.laz")
las_s, _ = time_read("tile_utm33n.las")          # same data, uncompressed
print(f"LAZ {laz_s:.1f}s | LAS {las_s:.1f}s | decompression ≈ {laz_s - las_s:.1f}s "
      f"({100 * (laz_s - las_s) / laz_s:.0f}% of the read)")

If decompression dominates, the fix is COPC or a chunked reader that decompresses only the extent you need. If raw I/O dominates, the fix is faster storage or reading from object storage in parallel — and the two are frequently confused, with teams switching formats to solve a disk problem.

Splitting a reader's time into disk and decompression Reading a compressed LAZ tile takes 214 seconds. Reading the same data uncompressed takes 61, so decompression accounts for about seventy per cent of the read. The two halves respond to different remedies: faster storage helps the disk half and a chunked or COPC reader helps the decompression half. LAZ read — 214 s LAS read — 61 s (disk only) decompression — 153 s, 71% of the read Faster storage would recover at most 61 s; a chunked reader that decompresses one extent recovers most of the 153 Two runs and a subtraction, and the optimisation stops being a guess
Two numbers separate two remedies that are routinely confused. The measurement takes one extra run against an uncompressed copy.

3. Take a native flame graph when a stage needs opening up

When one stage dominates and you need to know why, sample it with native frames.

bash
python pipeline.py tile_utm33n.laz &
PID=$!
py-spy record --pid $PID --native --rate 100 --duration 120 \
              --format speedscope --output profile.json
wait $PID

Then read the profile programmatically rather than only in a viewer, so the finding can go into a commit message:

python
import collections
import json

prof = json.load(open("profile.json"))
frames = prof["shared"]["frames"]
weights = collections.Counter()

for p in prof["profiles"]:
    for ev in p["events"]:
        if ev["type"] == "C":                      # close: a frame finished
            weights[frames[ev["frame"]]["name"]] += ev["at"]

total = sum(weights.values()) or 1
for name, w in weights.most_common(12):
    print(f"{100 * w / total:5.1f}%  {name[:70]}")

4. Use cProfile only for the Python around the pipeline

There is real Python cost in a batch job — tile enumeration, manifest hashing, result aggregation — and cProfile is the right tool for exactly that.

python
import cProfile
import pstats

pr = cProfile.Profile()
pr.enable()
manifest = build_manifest(tile_paths)          # hashing, globbing, JSON
dirty = select_dirty(manifest, previous)
pr.disable()

pstats.Stats(pr).sort_stats("tottime").print_stats(10)

Keep it off the execute() call itself. Wrapping a native call in a deterministic profiler adds overhead to the wrapper and measures nothing inside.

5. Watch memory alongside time

A job that is slow because it is swapping looks in a CPU profile like a job that is slow in whatever function happened to touch memory. Sampling RSS separates the two.

python
import threading
import time
import psutil

def watch(pid, out, interval=1.0):
    proc = psutil.Process(pid)
    while proc.is_running():
        try:
            out.append((time.perf_counter(), proc.memory_info().rss / 1e9))
        except psutil.NoSuchProcess:
            break
        time.sleep(interval)

samples = []
t = threading.Thread(target=watch, args=(os.getpid(), samples), daemon=True)
t.start()

run_pipeline("tile_utm33n.laz")
peak = max(rss for _, rss in samples)
print(f"peak RSS {peak:.2f} GB over {len(samples)} samples")

A monotonically climbing curve is accumulation, a sawtooth is streaming working correctly, and a plateau at the machine’s limit with a slow run is swapping — three different problems that a CPU profile alone reports identically.

Three memory shapes, three different problems A resident-set curve that climbs monotonically means something is accumulating. A sawtooth means streaming is working and the peak is one chunk. A flat plateau at the machine limit with a slow run means the process is swapping, which a CPU profile misattributes to whichever function touched memory. machine RAM accumulating streaming correctly swapping A CPU profile reports all three as "slow in some function" — the RSS curve names which one you have
One extra sampling thread distinguishes three failures that a CPU profile cannot tell apart.
The order to reach for each tool Start with stage timings the pipeline already reports, which are free and answer the question most of the time. Escalate to a native sampled profile only when one stage dominates and you need to know why. Reach for a deterministic profiler only for the Python surrounding the pipeline, and never for the pipeline itself. 1 · stage metadatafree, exact, usually enoughanswers: which stage? 2 · py-spy --nativecheap, attaches liveanswers: why that stage? 3 · cProfilePython around the pipelinenever on execute() Most investigations end at step one, and every investigation that starts at step three measures the wrong thing Add the RSS sampler alongside whichever step you are on — it costs one thread and rules out an entire class of cause
Escalate rather than starting at the most powerful tool. The free measurement answers the question far more often than its cost suggests.

Expected Output & Verification

A representative profile of a 42-million-point tile:

text
readers.las                   214.31s
filters.outlier                31.88s
filters.smrf                   47.02s
filters.range                   2.14s
writers.las                    38.77s
42,118,904 points through the pipeline

LAZ 214.1s | LAS 61.3s | decompression ≈ 152.8s (71% of the read)
peak RSS 3.84 GB over 334 samples

Read three things out of that. Reading is 64% of the run and decompression is most of it, so a chunked reader is the highest-value change available. filters.smrf at 14% is worth tuning only after that. And a peak RSS well under the machine’s RAM means the run is not memory-bound, so parallelism is likely to help — which the pool-sizing measurement will confirm.

Verify the finding before acting on it by re-running three times and checking the shares are stable within a couple of points. A share that moves by ten points between runs is measuring contention.

Common Errors

The flame graph is one frame deep. --native was omitted, so everything below the Python boundary is invisible. For PDAL, GDAL and Open3D that is the entire workload.

Permission denied attaching to a process. Linux ptrace_scope blocks attaching to a non-child. Either run py-spy as root, set sysctl kernel.yama.ptrace_scope=0, or add SYS_PTRACE to the container.

cProfile reports the whole run inside execute. That is correct and useless. Move the profiler to the Python surrounding the pipeline and sample the pipeline itself.

The profile attributes far less time than the wall clock. The process is blocked on I/O, which a sampler records as time in whatever frame is waiting, or the sample rate is too low to catch a stage. Compare attributed time against wall clock explicitly and investigate any large gap.

Frequently Asked Questions

Can I profile a pipeline running in a container in CI?

Yes. Add --cap-add SYS_PTRACE to the container and run py-spy as a second process against the pipeline’s PID. It is worth doing once when a CI job is unexpectedly slow, and not worth doing on every build.

Does --native slow the pipeline down?

Marginally — symbol resolution costs a little per sample, and at 100 Hz that is negligible against a job measured in minutes. It is far cheaper than the distortion cProfile introduces.

How do I profile a streaming pipeline?

The same way. py-spy samples whatever the process is doing, so a streaming pipeline shows its steady-state distribution directly, which is usually more informative than a whole-run profile of a batch job.

One more habit is worth building in. Store each profile’s headline numbers — total wall clock, the share of the top stage, peak RSS, and the machine’s core count — in the build artifact next to the output. Profiles are usually taken during an incident and discarded afterwards, so the next incident starts from nothing; a four-line record per run costs nothing and turns “is this slower than it used to be” into a lookup rather than an argument.

The related discipline is to profile the workload you actually run, not a reduced version of it. Halving the tile size to make the profiling loop faster moves the bottleneck: at forty million points the run is bound by decompression and memory bandwidth, and at four million it is bound by per-call overhead in exactly the functions a profiler makes most visible. The reduced profile is not a faster version of the real one; it is a profile of a different program.

Should the RSS sampler run in production jobs?

Yes. It is one thread, one syscall per second, and it converts “the job died” into a shape that names the cause. Log the peak alongside the chunk size and the worker count and capacity planning becomes interpolation from your own history.

Can I compare profiles taken on different machines?

Only as shares, never as absolute times. Core count, memory bandwidth and disk type move wall clock by more than most optimisations do, so a cross-machine comparison of totals says nothing. The share of the top stage is comparable and is usually the number you actually wanted.

Back to Performance Profiling and Benchmarking.