Profile Slow PyQGIS Code

Everyone has a theory about which line is slow. The theory is usually wrong, and acting on it produces a rewritten loop that is no faster and slightly harder to read. Profiling takes about a minute and replaces the theory with a ranked list, which is nearly always dominated by one call nobody suspected — a geometry conversion inside an inner loop, a layer lookup by name repeated per feature, a commitChanges() where there should have been one at the end.

This recipe belongs to Background Tasks and Plugin Performance. It covers running cProfile inside QGIS, reading its output, timing regions when a full profile is too coarse, and the four patterns that account for most PyQGIS slowness.

Where the time actually wentA horizontal bar breakdown of one profiled run. A repeated layer lookup by name takes just over half the total time, a geometry conversion inside the loop takes a further quarter, feature iteration takes a small share, and the arithmetic everyone assumed was the problem is barely visible.A real profile: the suspect was innocentmapLayersByName() called per feature — 52%asWkt()/fromWkt() — 25%iterationthe arithmetic — 2%the fix, in both cases, was to hoist a call out of the looplook the layer up once before iterating; keep geometry as QgsGeometry rather than round-tripping through texttotal run time fell from 41 s to 5 s without changing a single algorithm

Prerequisites

  • QGIS 3.34 LTR (bundled Python 3.12) or newer — cProfile is part of the standard library, so nothing needs installing.
  • A reproducible slow operation and a dataset big enough that it takes at least a few seconds.
  • Somewhere to write a stats file if you want to inspect the results outside QGIS.

Profile a function inside QGIS

import cProfile
import pstats
import io

def slow_operation():
    layer = QgsProject.instance().mapLayersByName("parcels")[0]
    total = 0.0
    for feature in layer.getFeatures():
        total += feature.geometry().area()
    return total

profiler = cProfile.Profile()
profiler.enable()
slow_operation()
profiler.disable()

stream = io.StringIO()
pstats.Stats(profiler, stream=stream).sort_stats("cumulative").print_stats(20)
print(stream.getvalue())

Breakdown: Wrapping the call rather than using cProfile.run() with a string keeps the code normal and debuggable. Sorting by cumulative puts the callers at the top — the functions inside which most time is spent — which is how you find the loop that is calling something expensive. Sorting by tottime instead puts the leaves at the top: the functions doing the actual work, excluding what they call. Read both: cumulative tells you where to look, total tells you what to fix. Limiting to twenty lines keeps the output readable; the tail is almost always noise.

Profiling in the Python console works exactly the same way, which makes it the fastest place to iterate — see QGIS Python Console Basics.

Read the output

The columns that matter are ncalls, tottime and cumtime. A line with a huge ncalls and a small per-call time is the classic PyQGIS problem: something cheap being done far too often.

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
   200000    9.412    0.000   21.318    0.000 qgis/core.py:1(mapLayersByName)
   200000    5.103    0.000    5.103    0.000 {method 'area' of 'QgsGeometry'}
        1    0.004    0.004   41.220   41.220 slow.py:4(slow_operation)

Breakdown: Two hundred thousand calls to a layer lookup means it is inside the loop — a lookup that should happen once is happening once per feature, and moving one line above the for removes half the run time. area() called two hundred thousand times is legitimate, and its cost is the honest price of the calculation. The one-call entry with an enormous cumtime is simply the entry point, and is always at or near the top when sorting cumulatively; it tells you nothing except that you profiled the right function.

Time regions when a profile is too coarse

cProfile reports per function. When one function contains three phases and you need to know which, time the regions directly.

import time
from contextlib import contextmanager

@contextmanager
def timed(label):
    started = time.perf_counter()
    try:
        yield
    finally:
        print(f"{label}: {time.perf_counter() - started:.2f}s")

with timed("read"):
    features = list(layer.getFeatures(request))
with timed("compute"):
    results = [compute(f) for f in features]
with timed("write"):
    provider.addFeatures(build(results))

Breakdown: A context manager keeps the timing out of the logic, so the instrumentation can stay in the code rather than being added and removed. finally means a raised exception still reports the time spent, which is useful when the slow phase is also the failing one. perf_counter() is monotonic, so an NTP adjustment mid-run cannot produce a negative duration. Three numbers of this shape usually settle the question immediately: a slow read points at the feature request, a slow compute at the algorithm, a slow write at the transaction boundary.

Four patterns behind most slow PyQGIS codeA repeated lookup inside a loop shows as a very high call count on a cheap function and is fixed by hoisting it out. Reading unnecessary attributes or geometry shows as time inside feature iteration and is fixed with a feature request. A nested loop over two layers shows as quadratic growth with data size and is fixed with a spatial index. Committing per feature shows as time inside commitChanges and is fixed by batching.Recognise the shape and you already know the fixwhat the profile showsthe causethe fixncalls equals feature counta lookup inside the loophoist it above the fortime inside getFeaturesreading unused columnsQgsFeatureRequesttime grows with the squarenested loop over two layersQgsSpatialIndextime inside commitChangescommitting per featureone commit at the end

Profile a plugin without editing it

For code you would rather not modify, wrap the entry point from the console:

import cProfile
from qgis.utils import plugins

profiler = cProfile.Profile()
profiler.enable()
plugins["my_plugin"].run()
profiler.disable()
profiler.dump_stats("/tmp/my_plugin.prof")

Breakdown: qgis.utils.plugins holds every loaded plugin by its folder name, so its public methods can be called directly from the console — which is also a fast way to test a plugin without clicking through its interface. dump_stats() writes a binary profile that external viewers such as snakeviz or tuna can render as a flame graph, which is far easier to read than a text table when the call tree is deep. Note that anything running on a QgsTask will not appear: cProfile follows the thread that enabled it, so profile the work synchronously first and move it to a task afterwards.

Keep a benchmark so an improvement stays improved

A profile tells you where the time went once. A benchmark tells you whether last month's optimisation survived this month's changes, and it costs about fifteen lines.

import time
import statistics

def benchmark(operation, runs=5, warmup=1):
    for _ in range(warmup):
        operation()                       # fill the OS file cache
    timings = []
    for _ in range(runs):
        started = time.perf_counter()
        operation()
        timings.append(time.perf_counter() - started)
    return {
        "best": min(timings),
        "median": statistics.median(timings),
        "spread": max(timings) - min(timings),
    }

print(benchmark(lambda: summarise_areas(layer)))

Breakdown: The warm-up run exists so the measurement reflects your code rather than the first read of a file from disk — comparing a cold run against a warm one is the single easiest way to convince yourself of an improvement that is not there. Reporting the median rather than the mean keeps one unlucky run from dominating, and the best time is the closest thing to the operation's true cost. The spread is the honest part: when it is large relative to the median, the machine is noisy and any difference smaller than the spread is not a result.

Record the numbers with the dataset they came from, because a benchmark without its input is meaningless. Where the operation is important enough, wire it into the test suite with a generous ceiling — assert that summarising ten thousand features takes under two seconds rather than asserting an exact time — so a regression that makes it ten times slower fails the build while ordinary variation does not. That fits naturally into the CI setup described in Run QGIS Plugin Tests in GitHub Actions.

Why the first run is discardedA cold first run takes far longer than the rest because the file cache is empty. Five subsequent runs cluster closely, and their median is reported. Including the cold run in the average would make any later comparison look like an improvement that never happened.Measure warm runs, or measure your disk0 scoldmediandiscardedfive timed runs, tightly clustered

QGIS version compatibility

cProfile, pstats and time.perf_counter() are standard library and behave identically on every QGIS 3.x release.

QGIS versionPythonNotes
3.22 LTR3.9Identical.
3.28 LTR3.9Identical.
3.34 LTR3.12Baseline for this page.
3.40 / 3.443.12Identical; the built-in Debugging/Development Tools panel also reports render and query timings.

QGIS's own Debugging and Development Tools panel is the complement to this page: it profiles rendering and provider queries, which cProfile cannot see because they happen in C++ and on other threads.

Troubleshooting

  • The profile is dominated by {built-in method builtins.exec}. You profiled the console's execution wrapper. Profile a function, not a pasted block.
  • Nothing appears for the slow part. It runs on another thread or inside C++. Time the region instead, or use the Debugging and Development Tools panel.
  • Timings vary by a factor of two between runs. The file cache is cold on the first run. Warm it and compare second runs.
  • The profiled run is much slower than the real one. Profiling overhead is real, roughly a factor of two on call-heavy code. Compare profiled runs with each other, and confirm improvements with a plain timer.
  • ncalls shows two numbers separated by a slash. The function is recursive; the second number is the primitive call count.
  • The fix made no difference. The function you optimised was not on the critical path. Re-profile rather than continuing on the same theory.

Conclusion

Profile before optimising: wrap the call in cProfile, sort by cumulative to find where the time is spent and by total to find what is spending it, and look first for a high call count on something cheap. Four patterns cover most cases — a lookup in a loop, unnecessary columns, a nested loop that wants an index, and a per-feature commit — and all four are visible in the first twenty lines of output.

Frequently Asked Questions

Does profiling work in the QGIS Python console? Yes, exactly as in a script. It is usually the quickest place to work, because you can re-run the profiled function without restarting anything.

How do I profile code inside a QgsTask? You cannot directly — cProfile follows one thread. Extract the work into a plain function, profile it synchronously against the same data, then run the optimised version on the task.

Is there a line profiler for PyQGIS?line_profiler works if you install it into the QGIS Python environment, which the virtual-environment setup in Virtual Environments for GIS makes straightforward. For most problems function-level granularity is enough.

Why is a Processing algorithm showing as one fast call? Because it is: the work happens in compiled code the profiler cannot see. Time it as a region instead, and pass a feedback object if you want progress from inside.

Should I optimise memory as well as time? Only when it is the constraint. tracemalloc will show where allocations come from, and the usual answer in PyQGIS is a list of features that should have been a generator.