Performance and profiling

Measure before you change

Perl is fast enough for most jobs, and guesses about hot spots are usually wrong. Start with a timer around the part that feels slow, and only then decide what to rewrite.

use Time::HiRes qw(time); my $start = time; my $lines = parse_log($file); printf "parsed %d lines in %.3f s\n", scalar @$lines, time - $start;

Time::HiRes gives sub-second resolution; the built-in time only counts whole seconds, which is useless for a function that takes 80 milliseconds. For a whole program, the shell already measures it:

time perl analyze.pl access.log

real 0m4.812s user 0m4.601s sys 0m0.204s

Real time includes waiting for disk and network; user time is the CPU your code burned. If user and real are close, the program is CPU-bound and code changes will help. If real is much larger, look at input and output first.

Benchmark

When two implementations look equally reasonable, race them instead of arguing. Benchmark runs each variant for a fixed time and prints a comparison table:

use Benchmark qw(cmpthese); my $text = "the quick brown fox jumps over the lazy dog. " x 2000; cmpthese(-1, { regex => sub { my $n = () = $text =~ /quick/g }, index => sub { my ($n, $pos) = (0, 0); while (($pos = index($text, "quick", $pos)) >= 0) { $n++; $pos++; } }, });

Rate regex index regex 1420/s -- -88% index 11800/s 731% --

The literal search wins because it never runs the regex engine. That does not mean every regex should become an index loop: the regex version is shorter and handles patterns that index cannot. Measure the real input before choosing.

The first run of a benchmark is always slower because of warm-up, and a busy machine adds noise. Run it twice, and ignore differences under ten percent: they are usually measurement error, not a real win.

Profile with NYTProf

A benchmark tells you which snippet is faster. A profiler tells you which part of your program is slow, including the calls you did not suspect. Devel::NYTProf is the standard choice.

cpanm Devel::NYTProf

perl -d:NYTProf bin/report.pl access.log

The run writes nytprof.out. Converting it to HTML gives a report with time per subroutine, per line, and per call site:

nytprofhtml --open

Read the report from the top: the subroutine list shows where the time went, and the line view shows which statement inside it is hot. A line called a million times for one microsecond each is a different problem from one call that takes ten seconds.

Profiling adds overhead, so measure a smaller input if the full run takes minutes. The proportions usually survive the reduction, and the hot path is the same.

The usual wins

Most slow Perl scripts are slow for one of a few reasons, and none of them is the interpreter:

• A linear scan where a hash lookup would do: grep over ten thousand items inside a loop is quadratic.
• Reading a huge file into memory, or reading it twice when one pass would do.
• Compiling the same regex in a loop instead of once with qr//.
• Calling a subroutine a million times for a value that never changes.
• Sorting with an expensive comparison function instead of a Schwartzian transform.

my $re = qr/^\d{4}-\d{2}-\d{2}$/; # compiled once my %seen = map { $_ => 1 } @ids; # lookup later is O(1)

Use index($haystack, $needle) >= 0 instead of a regex when you search for a literal string. Use Devel::Size::total_size when memory is the limit and you need to know which structure is huge.

Finally, treat readability as a feature. A ten percent speedup that makes the code unmaintainable is a bad trade unless the program runs on every request of a busy service. Measure, fix the hot spot, measure again, and stop when it is fast enough.

Next: Modern Perl tour

Article author: Arthur Isaev