--- name: measuring performance on pperl --- # Measuring You cannot tune what you have not measured, and on pperl the usual measuring tools split into three groups: the ones that work unchanged, the ones that work because they are plain Perl running on a faster interpreter, and the one everybody reaches for that does not work at all. This chapter sorts them out and shows how to read what the working ones tell you. ## The tool that does not work: Devel::NYTProf `Devel::NYTProf` is the standard line-and-subroutine profiler on upstream Perl. It is an XS module - it hooks the interpreter through a C extension. pperl ships no XS layer, so `Devel::NYTProf` does not load. Neither does any other XS-based profiler (`Devel::DProf`, `Devel::Profiler`'s XS paths). This is not a gap to be worked around with a pure-Perl reimplementation of NYTProf's output format. pperl has its own profiler, built into the runtime, that sees what the interpreter actually executes - op counts and the time spent in each. Use it. ## The pperl profiler pperl's profiler is compiled into a dedicated build and switched on at run time by an environment variable. It is off by default and costs nothing in a normal build. Build once with the `profile` feature, then run with `PPERL_PROFILE` set: ```bash cargo build --release --features=profile PPERL_PROFILE=1 ./target/release/pperl script.pl ``` When the program exits - or on `SIGINT` / `SIGTERM`, so a long-running or hung program can still be profiled by interrupting it - the report prints to `STDERR`. It has two sections. **Subroutine timings**, the top entries by total time: ``` -- Subroutine Timings (top 20 by total time) -- Sub Calls Total ms Avg µs ---------------------------------------------------------------------------- main::parse_record 10000 412.318 41.23 main::normalise 120000 88.004 0.73 ``` **Op timings**, the top entries by total time, naming the interpreter operation rather than a line of your source: ``` -- Op Timings (top 30 by total time) -- Op Count Total ms Avg ns ---------------------------------------------------------------- helem 12400000 210.114 16 padsv 31000000 180.700 5 ``` Read the subroutine section first: it tells you *where* in your code the time goes. Read the op section when the subroutine section has pointed you at a routine and you want to know *what kind* of work dominates it - a routine heavy in `helem` is doing hash lookups; one heavy in `padsv` is touching lexicals; one whose time is in `subcall` is paying call overhead worth inlining. The profiler counts what the interpreter executes. Code that the JIT compiled to native machine code does not run through the interpreter's op dispatch, so it does not show up op-by-op. A loop that has vanished from the op timings is a loop the JIT took over - which is the answer you wanted. To profile interpreter behaviour in isolation, disable the JIT with `--no-jit` (see below). ## Whole-program timing: the benchmark runner When the question is "how fast is pperl on this, versus system perl, with and without JIT and parallelism", the project benchmark runner answers it directly. `bench/run-perlbench` always runs `/usr/bin/perl` as the baseline (normalised to 100) and compares pperl in up to four configurations. ```bash ./bench/run-perlbench # no JIT, no parallel ./bench/run-perlbench +J # add the JIT-enabled run ./bench/run-perlbench +P # add the parallel run ./bench/run-perlbench +J+P # all four combinations ./bench/run-perlbench -t arith # only benchmarks matching "arith" ``` Every runner shares one iteration count, derived from the slowest runner's empty-loop rate, so the reported ratios compare like with like. The `+J` / `+P` columns are exactly the comparison you want when deciding whether a piece of code benefits from the JIT or the parallelizer: if `+J` is no faster than the plain run, the loop is not being compiled, and [Writing fast pperl](writing-fast-pperl) explains why and what to change. ## Plain-Perl tools that work: Benchmark and Time::HiRes The classic in-program measuring tools are plain Perl. They run on pperl through the normal module path - `Benchmark` is reachable on the standard include path and executes as Perl on the pperl interpreter; `Time::HiRes` is provided natively. Both behave exactly as a Perl programmer expects. `Benchmark` for A/B comparison of two ways to write the same routine: ```perl use Benchmark qw(cmpthese); my @data = (1 .. 100_000); cmpthese(-3, { # run each for ~3 CPU-seconds grep_count => sub { my $n = grep { $_ % 2 == 0 } @data }, loop_count => sub { my $n = 0; $_ % 2 or $n++ for @data }, }); ``` `Time::HiRes` for ad-hoc wall-clock timing of a single block: ```perl use Time::HiRes qw(time); my $t0 = time; do_the_work(); printf "took %.3f s\n", time - $t0; ``` A caution that matters more on pperl than on upstream: a `Benchmark` micro-comparison that wraps the code in a `sub { ... }` measures the code *as a subroutine body*. Subroutine bodies are not JIT-compiled - the JIT targets loops, not call frames (see [JIT compilation](../pperl-architecture/jit)). So a tight numeric loop that would be compiled at file scope may run interpreted inside a `Benchmark` callback, and the comparison understates the loop's real speed. When the thing you are timing is a loop that should JIT, prefer `bench/run-perlbench` or a `Time::HiRes` span around the loop in situ. ## Turning the optimisers off to isolate a cause Two flags let you attribute a speedup - or a slowdown - to the right layer: ```bash pperl --no-jit script.pl # interpreter only, no native compilation pperl --no-parallel script.pl # single-threaded, no Rayon dispatch ``` Run a program three ways - default, `--no-jit`, `--no-parallel` - and the differences tell you which optimiser is carrying the work. If `--no-jit` barely changes the time, the JIT was not engaging on this code, and the loop shape is the thing to look at. If `--no-parallel` barely changes it, the parallelizer declined the loop - usually because of a side effect it could not rule out (see [Parallel execution](../concurrent-execution/parallel)). ## A measuring discipline 1. Run the program once under the profiler build. Read the subroutine timings. The top two or three lines are your budget. 2. If a hot routine is a loop you expected to be compiled, confirm with `run-perlbench +J` or by timing it `--no-jit` versus default. A loop that does not speed up under the JIT is shaped wrong, not slow. 3. Only now change code. Re-measure the same way. Keep the change if the number moved and the program still produces the same output. Performance claims are cheap; the profiler report and the benchmark ratio are not. Trust the measurement. ## See also - [Writing fast pperl](writing-fast-pperl) - once you have found the hot loop, how to shape it so the JIT and parallelizer take it. - [Idioms](idioms) - which classic optimisations are still worth applying before you reach for the profiler. - [JIT compilation](../pperl-architecture/jit) - what the JIT compiles and why interpreted op timings disappear for compiled loops. - [Parallel execution](../concurrent-execution/parallel) - what the `+P` column and `--no-parallel` flag are exercising. - [Regex performance](../regular-expression/performance) - if the profiler points at a regexp, the cause and cure live there, not here.