Profiling with Devel::NYTProf

“What is taking so long?” is not easy to answer. To spot quickly a problem in the source code, you can be helped by a profiling tool. On StackOverflow Brian D Foy suggests to use Devel::NYTPROF (and DBI::Profile for databases queries benchmark). Here is a quick how to of Devel::NYTPROF with Koha.

Make Koha CGI scripts generates profiling data collection

Install the module :

 sudo apt-get install libdevel-nytprof-perl

Devel::NYTPROF write an output file, by default in the directory where the script is executed. You can change the location by providing a NYTPROF variable. Since the koha scripts are launched from Apache, you can add the variable in your apache configuration :

 ...
 SetEnv KOHA_CONF "/etc/koha/koha-conf.xml"
 SetEnv PERL5LIB "/usr/share/koha/lib"
 SetEnv NYTPROF "file=/tmp/nytprof.out:addpid=1:endatexit=1:stmts=0"
 ...

And reload the server:

 sudo service apache2 reload

Now, when you want to profile a CGI script, just change the shebang this way:

 #!/usr/bin/perl -d:NYTProf

And load the script as usual in your browser. Your /tmp should soon be populated with nytprof.out.[0-9]+ files (the number at the end is the PID, so you can have multiple profiling files for the same CGI).

Mine the data collection

You can generate a whole web site showing the script execution in details, with all calls and the time they took :

 nytprofhtml -f <nytprof.out.[0-9]+> --open

It should open your browser in the output directory (defaults to nytprof).

Alternatively, if you don't have a browser to hand, you can just output to a directory and then open "index.html" later:

 nytprofhtml -f <nytprof.out.[0-9]+> -o ~/nytprof

The HTML pages are handy and show directly the bad guys :

You can navigate trough the code with timing details :

What else?

You can plug to mod_perl with Devel::NYTProf::Apache if your using mod_perl.