Jeremy Smith's blog

Entry Is Labelled

Blog@Case Profiling

So, you may have noticed that the CGIs for the Blog@Case system have been running mind-numbingly slow. (For those of you not up-to-the-eyeballs in web programming, the CGIs are, mostly, the area of the system where you administrate your blog, create/edit posts, etc.) I've been meaning to profile it for a while now but have been caught up in some Federated Identity project-stuff. (Again, for people who have never programmed, the art of "profiling" is the concept of compartmentalizing the system into discrete subsystem-quanta and individually measuring how long it takes each artificially created quanta to execute.) Well, today, I had some time; so I spent several hours littering the code with statements and cranking up debug output to max fire hose status.

[Okay, seriously, for those readers who are not programmers; you might as well just stop reading now. We're coming to the part where I am going to post some code.]

So, I tracked the time it took to load — to just load up the standard blank login screen. It took about 11s. The perl code in that CGI can be boiled down to three main lines of code:

require MT::LDAP::App::CMS;
my $app = MT::LDAP::App::CMS->new( Config => $MT_DIR . 'mt.cfg', Directory => $MT_DIR ) or die MT::LDAP::App::CMS->errstr; $app->run;

One of those lines of code took 10s to run. The other two lines each took about .5s to run apiece. Can you guess which?

For those of you bright enough to catch on, that's right, it is the line you least expected: require MT::LDAP::App::CMS; takes about 10s to run. Unfortunately, that really doesn't help me a whole lot. Now, I have to go crazy with some BEGIN and END blocks trying to figure out the ludicrousness.

Update: Found it! Lesson learned: fear Data::Dumper::Simple, as it is a source filter, during require's or use statements on a sufficiently large single file, it will greatly slow down its load time.