Often we write perl scripts that loop a particular action. Not so often we write a perl script that is called in a loop by another tool. My script was attempting to do a http web login to emulate user traffic. However, I was not able to start more than 8 of these scripts a second.

Timing the script inside of perl was actually almost useless. Often you have a profiling marker like:

use Time::HiRes::time;
my $start = time;
# stuff
print "delta: ".(time - $start)."\n";

And that was just telling me I spent 4ms doing my stuff. And so where the heck did the other 108ms occur?

Here was another trick I started using to estimate latency: passing in the start time from the command line:

$ ./script.pl --invoked `date +%s.%4N`

and I would parse it in the script:
my $start;

GetOptions(
   "invoked=f" => \$start,
);
# stuff
print "delta: ".(time - $start)."\n";

Ah…there was my 114ms latency again. So startup of the script must be eating up ~100ms. Well, what could I remove? Anything I did not need to use obviously. Let’s comment out my strictitudinal use statements:

#use strict;
#use warnings;
#use diagnostics;
#use Carp;
#$SIG{ __DIE__ } = sub { Carp::confess( @_ ) };

Wow, I just gained 40ms! But can’t I do better than that? Ah hah, time to use a profiler. After a bit of research, I installed the NYTProf package.

I found some surprising slowdown spots:

• Time::HiRes – took up to 10ms to load, using `date` takes about 300 microseconds
• GetOpt::Long – pretty long load time, with a lot of dependencies, what I have now to parse ARGV is not as flexible, but it takes no time to start up.
• use constant – took up to 45ms to load, about 20ms of that was loading utf8_heavy.ph. Apparently it takes a lot of work to allow any utf8 character to be a legal script constant? Didn’t need it.
• including ‘use strict’ — in all my own packages, removed them when I wasn’t debugging

Removing GetOpt::Long usage was pretty time consuming. I solved it in about 100 lines of code while still keeping something very close to the original GetOpt syntax, but turning it into a map. Kinda fun, but a bit nail-biting at the same time. Resulting function weighted in at under 100 microseconds.

Result? 6.6 milliseconds run time! I was able to operate the script upto to 68 times a second.