Was performance benchmarked before and after this change?
Daryl On 23/07/2011 5:41 PM, jhar...@apache.org wrote:
Author: jhardin Date: Sat Jul 23 21:41:27 2011 New Revision: 1150225 URL: http://svn.apache.org/viewvc?rev=1150225&view=rev Log: Add per-rule timing (debug "ruletimes" channel) for most rule types Modified: spamassassin/trunk/lib/Mail/SpamAssassin/Plugin/Check.pm Modified: spamassassin/trunk/lib/Mail/SpamAssassin/Plugin/Check.pm URL: http://svn.apache.org/viewvc/spamassassin/trunk/lib/Mail/SpamAssassin/Plugin/Check.pm?rev=1150225&r1=1150224&r2=1150225&view=diff ============================================================================== --- spamassassin/trunk/lib/Mail/SpamAssassin/Plugin/Check.pm (original) +++ spamassassin/trunk/lib/Mail/SpamAssassin/Plugin/Check.pm Sat Jul 23 21:41:27 2011 @@ -310,6 +310,8 @@ sub run_generic_tests { my $package_name = __PACKAGE__; my $methodname = $package_name."::_".$ruletype."_tests_".$clean_priority; + my $do_timing = would_log('dbg', 'ruletimes'); + if (!defined&{$methodname} || $doing_user_rules) { # use %nopts for named parameter-passing; it's more friendly @@ -334,6 +336,7 @@ sub run_generic_tests { $self->push_evalstr_prefix($pms, ' # start_rules_plugin_code '.$ruletype.' '.$priority.' my $scoresptr = $self->{conf}->{scores}; + my $time = time; '); if (defined $opts{pre_loop_body}) { $opts{pre_loop_body}->($self, $pms, $conf, %nopts); @@ -341,7 +344,18 @@ sub run_generic_tests { $self->add_evalstr($pms, $self->start_rules_plugin_code($ruletype, $priority) ); while (my($rulename, $test) = each %{$opts{testhash}->{$priority}}) { + if ($do_timing> 0&& $ruletype ne "meta") { + $self->add_evalstr($pms, ' + $time = time; + '); + } $opts{loop_body}->($self, $pms, $conf, $rulename, $test, %nopts); + if ($do_timing> 0&& $ruletype ne "meta") { + $self->add_evalstr($pms, ' + $time = time - $time; + dbg(sprintf("ruletimes: '.$ruletype.' '.$rulename.' %.4f s", $time)); + '); + } } if (defined $opts{post_loop_body}) { $opts{post_loop_body}->($self, $pms, $conf, %nopts); @@ -423,6 +437,7 @@ sub begin_evalstr_chunk { my $package_name = __PACKAGE__; my $evalstr =<<"EOT"; package $package_name; +use Time::HiRes qw(time); sub $chunk_methodname { my \$self = shift; EOT