mcm has asked for the wisdom of the Perl Monks concerning the following question:

Esteemed Monks,

I have a series of Perl CGI scripts that intermittently are very slow. The same scripts have been in use for a long time on the same system with no problem, but this has started only recently -- and system traffic hasn't increased recently.

In investigating the problem I wrote the following test CGI to figure out which part of the CGI is taking the most time, and found that:

We're using Perl 5.00503 under Apache, without mod_perl.

What I'm looking for is some insight/speculation into why the interpreter might lag so much at the end of a BEGIN block.

BEGIN { $time1 = time; [ DO MISCELLANEOUS TASKS ] $time2 = time; unshift @INC, "$home/custom/lib"; $time3 = time; } $time4 = time; print "Content-type:text/html\n\n"; print "Begin Block: " . ($time3 - $time1) . "\n"; print " Miscellaneous Tasks: " . ($time2 - $time1) . "\n"; print " unshift inc: " . ($time3 - $time2) . "\n"; print "End begin block/begin main body: " . ($time4 - $time3) . "\n";

Replies are listed 'Best First'.
Re: Long delay at end of BEGIN block
by liz (Monsignor) on Sep 23, 2003 at 15:33 UTC
    I'm not sure whether you realize that between "$time3" and $time4" your entire script is being compiled. Which can take long or short, depending on what modules you load and what they actually do.

    So your delay could be from:

    • A slow disk (mounted with Samba, NFS, whatever) causing delays in reading the module files.
    • Lack of CPU causing delay in compiling module files.
    • Lack of RAM when swapping (causing extra disk and CPU load)
    • Anything a module does when being loaded (e.g. a DNS lookup?).

    So without knowing what else you're loading in your script, there is no way we can tell what's wrong.

    Liz

      Thanks for the insight -- I knew that BEGIN happened pre-compile, but I somehow wasn't connecting that with the module compilation.

      Anyway, I waited for another slow-time and tried the CGI again with different modules commented out, and narrowed it down to one module that seems to be the culprit.

      Now I just need to spend some time looking at the module to figure out why it sometimes takes so long to compile or initialize. A cursory glance showed that the module doesn't do much initialization (all of the logic is in the subs), except for setting some scalars to string values.

      The entire filesystem is stored locally (on a RAID array), so IO speed shouldn't be a factor. CPU or RAM might be a culprit -- our performance monitor doesn't show anything above 40%, but I suppose there could be mini-spikes that are shorter than the measurement period.

Re: Long delay at end of BEGIN block
by Elian (Parson) on Sep 23, 2003 at 15:37 UTC
    Without seeing the "do miscellaneous tasks" part it's tough to be sure, but the first thing that springs to mind is that you're seeing the lag because of variable destruction. Either you've got some variables that have slow DESTROY methods (perhaps something's doing a DNS lookup for logging purposes and resolver issues are causing this) or you're letting very large hashes fall out of scope and the cleanup's taking forever because of pathological C library behaviour.

    If it's a resolver issue, fix it. If the C library on the machine's an old-ish version of glibc, upgrade it. Otherwise you've presented insufficient details to diagnose the problem.