A useful code profiling tool is the dprofpp tool which gives detailed information on the various functions and their relative performance. The tool needs to be provided the input of a code profile file. This file can be generated by the Devel::DProf module in conjunction with the perl debugger. The Devel::DProf can be downloaded from CPAN using the command
perl -MCPAN -e 'install Devel::DProf'
After installing the module, you can profile the execution of flowscan by running the perl debugger as:
perl -d:DProf flowscan
This generates a tmon.out file which contains the code profiling information. Once the execution is complete you can examine a summary of the performance of the subroutines and overall code by:
dprofpp -F tmon.out
In my case this produced the following output for the execution of flowscan for about 50 flow files. Meanings of various columns are given at dprofpp:
akbar@iepm-resp $ dprofpp -F tmon.out Faking 6 exit timestamp(s). Total Elapsed Time = -2.14996 Seconds User+System Time = 0 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 0.00 3.050 3.034 10560 0.0003 0.0003 HTML::Table::getTable 0.00 2.990 2.956 22906 0.0001 0.0001 RRDs::update 0.00 1.730 1.730 18 0.0961 0.0961 JKFlow::pushApplications 0.00 1.523 6.549 1761 0.0009 0.0037 JKFlow::scoreboard 0.00 1.000 5.145 22906 0.0000 0.0002 JKFlow::reporttorrd 0.00 0.780 1.178 61390 0.0000 0.0000 JKFlow::countDirections 0.00 0.750 0.749 468 0.0016 0.0016 RRDs::create 0.00 0.720 0.716 32383 0.0000 0.0000 JKFlow::scale 0.00 0.620 1.826 61390 0.0000 0.0000 main::wanted 0.00 0.570 3.458 22906 0.0000 0.0002 JKFlow::updateRRD 0.00 0.568 12.226 881 0.0006 0.0139 JKFlow::reporttorrdfiles 0.00 0.540 0.356 122780 0.0000 0.0000 Net::Patricia::match_integer 0.00 0.460 0.436 15958 0.0000 0.0000 HTML::Table::addRow 0.00 0.460 1.454 61390 0.0000 0.0000 JKFlow::wanted 0.00 0.345 2.142 49 0.0070 0.0437 Cflow::find
It is apparent from the above report that the HTML::Table package is taking up a bulk of the execution time. HTML::Table::getTable takes 3.050 secs of exclusive execution time and 3.034 secs of cumulative execution time (including the subroutines called from within). Clearly this is on of the performance bottlenecks which needs to be removed. HTML::Table is mostly used in the scoreboarding functions of JKFlow which is done for every direction and every few flowfiles. I am currently working on filtering out the scoreboarding code of the JKFlow and making it available via a datastructure so that the user has more control over the scoreboarding capabilities and unnecessary use of the HTML::Table can be removed.