Note that this is outdated documentation, you should rather use HitFreqsRuleTiming plugin, see: FasterPerformance#Findingslowrules

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 the Devel::DProf manual.

  • No labels