= Profiling Rules With Devel::DProf =

To get an idea of rule overhead and speed, the perl module {{{Devel::DProf}}} can be used.  Here's how:

Create a small corpus suitable for MassCheck.

run a mass-check with Devel::DProf loaded, like so:

{{{
  cd masses
  rm tmon.out
  perl -d:DProf ./mass-check [...usual mass-check switches]
  dprofpp -O 999 > profile.out
}}}

Note that sometimes the {{{perl -d:DProf}}} line will produce a core dump!   This seems to be a bug in DProf, and immediately re-running that line will work fine and produce usable output regardless.

You can also use the {{{spamassassin}}} script instead of {{{mass-check}}}, but {{{mass-check}}} scans more messages, and gives a better idea of per-message performance as it would appear where {{{spamd}}} is used.

'profile.out' now contains profiling output from the code.  Due to the way that SpamAssassin compiles runs into perl functions, these will show up in the profile data.  Here's an example:

{{{
Total Elapsed Time = 3.339984 Seconds
  User+System Time = 2.249984 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 9.78   0.220  0.220      2   0.1100 0.1100  Mail::SpamAssassin::PerMsgStatus::DOMAIN_4U2_body_test
 6.62   0.149  1.938    104   0.0014 0.0186  Mail::SpamAssassin::PerMsgStatus::BEGIN
 6.53   0.147  0.230      2   0.0736 0.1150  Mail::SpamAssassin::Conf::Parser::parse
 2.67   0.060  0.288     20   0.0030 0.0144  Mail::SpamAssassin::BEGIN
 1.78   0.040  0.040      2   0.0200 0.0200  Mail::SpamAssassin::PerMsgStatus::DRUGS_SMEAR1_body_test
 1.78   0.040  0.079     10   0.0040 0.0079  base::import
 1.73   0.039  0.066      6   0.0066 0.0110  Mail::SpamAssassin::PerMsgStatus::do_head_tests
 1.33   0.030  0.030      2   0.0150 0.0150  Mail::SpamAssassin::PerMsgStatus::__NIGERIAN_BODY_45_body_test
 1.33   0.030  0.030      2   0.0150 0.0150  Mail::SpamAssassin::PerMsgStatus::_check_unique_words
 1.33   0.030  0.030      2   0.0150 0.0150  Mail::SpamAssassin::PerMsgStatus::__T_FRAUD_235_body_test
 1.33   0.030  0.030      3   0.0100 0.0100  Cwd::abs_path
 1.33   0.030  0.030      2   0.0150 0.0150  Mail::SpamAssassin::PerMsgStatus::__T_FRAUD_227_body_test
 1.33   0.030  0.074   1878   0.0000 0.0000  Mail::SpamAssassin::Conf::__ANON__
 1.33   0.030  0.037   1135   0.0000 0.0000  Mail::SpamAssassin::Conf::Parser::add_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::__DRUGS_DIET1_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::DRUG_DOSAGE_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::__DRUGS_ANXIETY3_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::__DRUGS_SLEEP2_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::DIET_3_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::LESBIAN_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::__DRUGS_SLEEP1_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::__DRUGS_ANXIETY5_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::__DRUGS_ANXIETY1_body_test
 0.89   0.020  0.020      2   0.0100 0.0100  Mail::SpamAssassin::PerMsgStatus::ONLINE_PHARMACY_body_test
 0.89   0.020  0.020      1   0.0200 0.0200  Mail::SpamAssassin::Conf::Parser::finish_parsing
}}}

The various rules will appear as {{{Mail::SpamAssassin::PerMsgStatus::RULENAME_type_test}}}.

More information on the {{{dprofpp}}} output format can be read in [[http://www.perldoc.com/perl5.6/lib/Devel/DProf.html|the Devel::DProf manual]].