Profilers identify bottlenecks in Perl programs

Run-Time Speed

© Dominic Ziegler, Fotolia

© Dominic Ziegler, Fotolia

Article from Issue 99/2009
Author(s):

Instead of souped up CPUs, simple programming tricks are often all it takes to speed up a program. Profilers can discover bottlenecks that need more TLC from the developer.

If you don't spend all day playing video games, you will be quite happy without the latest and greatest CPU, and you can save money on hardware while saving power and reducing your personal CO² footprint.

But what happens if a Perl program does not perform as well as you would like? As a first step, you might be able to accelerate the program with very little effort by optimizing the code at neuralgic points.

In most cases, just one or two targeted improvements will help you achieve 90 percent of the total optimization potential. The remaining 10 percent are more likely to involve wide-ranging, architectural changes that take 10 times as long to implement and make the resulting program so difficult to maintain that more experienced developers are likely to turn down the option.

Profilers are programs that discover bottlenecks, or hotspots. They show you where the program spends most of its time and help to optimize these crucial sections in a targeted way.

Perl has many tools of this kind. For example, if a module uses the Log4perl logging framework, it is simple to display the number of milliseconds (msec) that elapse along with the log messages, thus creating a timescale.

Finding Bottlenecks

The simple test script amzntest (Listing 1) uses the CPAN Net::Amazon module to retrieve book details from the Amazon Web API (assuming you enter a valid token, which you can get from Amazon Web Services [2]).

Listing 1

amzntest

01 #!/usr/bin/perl
02 use warnings;
03 use strict;
04 use Net::Amazon;
05 use Net::Amazon::Request::ASIN;
06
07 my $asin = "0132396556";
08
09 my $ua = Net::Amazon->new(
10     token => 'XXXXXXXXXXXXXXX',
11 );
12
13 my $req = Net::Amazon::Request::ASIN->new(
14     asin  => $asin,
15 );
16
17 my $resp = $ua->request($req);
18
19 if($resp->is_success()) {
20     print $resp->as_string(), "\n";
21 } else {
22     print "Error: ",
23           $resp->message(), "\n";
24 }

A request takes about a second, but what does the script use this time for – picking up the data or the analyzing the XML response? Adding

use Log::Log4perl;
 Log::Log4perl->init("timer.l4p");

to the script header enables the Log4perl statements embedded in Net::Amazon by loading the timer.l4p configuration file. This outputs the date (%d) and the number of milliseconds since the program started (%r) for each message it logs. The logging level is set to DEBUG and is thus fairly verbose.

To cut down on lengthy log messages, the configuration file in Listing 2 uses the abbreviation %S to define a so-called Custom Cspec. This appears in the layout, instead of the more typical %m (for the log message).

The associated Perl subroutine returns a shorter, 25-character message to the screen appender. The layout closes with a platform-dependent newline character defined by %n.

Listing 2

timer.l4p

1 log4perl.logger          = DEBUG, App
2 log4perl.appender.App    = Log::Log4perl::Appender::Screen
3 log4perl.appender.App.layout = PatternLayout
4 log4perl.appender.App.layout.ConversionPattern = %d %r %S%n
5 log4perl.PatternLayout.cspec.S = sub { substr($_[1], 0, 25) }

Quick Fix

Figure 1 shows that Net::Amazon sends a web request to Amazon 79msec after the program launches; however, the XML parser does not start working until 739msec have elapsed. Thus, the web request takes 75 percent of the 800msec required by the script.

As you will agree, it makes sense to use a web cache for frequently retrieved ASIN numbers, and Net::Amazon enables this if we ask it to (see Listing 3). This really does reduce the script run time, which drops to 180msec for repetitions (see Figure 2) with the use of File::Cache as a persistent cache.

Listing 3

Web Cache

01 use Cache::File;
02 my $cache = Cache::File->new(
03    cache_root        => '/tmp/mycache',
04    default_expires   => '30 min',
05 );
06
07 my $ua = Net::Amazon->new(
08     token => '0AQN5ZBDW6NXV9M60N82',
09     cache => $cache,
10 );

Quick Results

Now you might argue that tricks of this kind aren't always going to help, but the decisive issue here is that five lines of code and a minute spent thinking about options achieved a speed boost of 400 percent.

Buy this article as PDF

Express-Checkout as PDF
Price $2.95
(incl. VAT)

Buy Linux Magazine

SINGLE ISSUES
 
SUBSCRIPTIONS
 
TABLET & SMARTPHONE APPS
Get it on Google Play

US / Canada

Get it on Google Play

UK / Australia

Related content

  • Perl: amtrack

    If you are a bargain hunter, you might enjoy this Perl script that monitors price developments at Amazon and alerts you if Amazon suddenly drops the prices on the products you have been watching.

  • Perl: Yahoo API Scripting

    Following in the footsteps of Google, Amazon, and eBay, Yahoo recently introduced a web service API to its search engine. In this month’s column, we look at three Perl scripts that can help you correct typos, view other people’s vacation pictures, and track those long lost pals from school.

  • Perl: Vim

    The Vim editor supports Perl plugins that let users manipulate the text they have just edited. Complex functions can be developed far faster than with Vim’s integrated scripting language.

  • Perl: Perl Debugger

    The Perl interpreter, perl, doesn’t often crash, but if it happens, not even the excellent Perl debugger will be able to help you.

  • Perl Snapshot: Debugging

    Some developers condemn the use of debuggers, but in many cases, a debugger is a programmer’s last hope. In this Month’s Perl Snapshot, we’ll look at Perl’s integrated debugger.

comments powered by Disqus

Direct Download

Read full article as PDF:

079-082_perl.pdf  (1.15 MB)

News