← Index
NYTProf Performance Profile   « line view »
For /usr/local/bin/sa-learn
  Run on Sun Nov 5 03:09:29 2017
Reported on Mon Nov 6 13:20:48 2017

Filename/usr/local/lib/perl5/site_perl/Mail/SpamAssassin/Plugin/Razor2.pm
StatementsExecuted 39 statements in 4.68ms
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
11111.5ms137msMail::SpamAssassin::Plugin::Razor2::::newMail::SpamAssassin::Plugin::Razor2::new
11149µs199µsMail::SpamAssassin::Plugin::Razor2::::set_configMail::SpamAssassin::Plugin::Razor2::set_config
11138µs38µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@43Mail::SpamAssassin::Plugin::Razor2::BEGIN@43
11125µs189µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@44Mail::SpamAssassin::Plugin::Razor2::BEGIN@44
11123µs34µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@46Mail::SpamAssassin::Plugin::Razor2::BEGIN@46
11122µs60µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@47Mail::SpamAssassin::Plugin::Razor2::BEGIN@47
11121µs89µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@51Mail::SpamAssassin::Plugin::Razor2::BEGIN@51
11120µs87µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@49Mail::SpamAssassin::Plugin::Razor2::BEGIN@49
11120µs27µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@48Mail::SpamAssassin::Plugin::Razor2::BEGIN@48
11113µs13µsMail::SpamAssassin::Plugin::Razor2::::BEGIN@45Mail::SpamAssassin::Plugin::Razor2::BEGIN@45
0000s0sMail::SpamAssassin::Plugin::Razor2::::__ANON__[:304]Mail::SpamAssassin::Plugin::Razor2::__ANON__[:304]
0000s0sMail::SpamAssassin::Plugin::Razor2::::check_razor2Mail::SpamAssassin::Plugin::Razor2::check_razor2
0000s0sMail::SpamAssassin::Plugin::Razor2::::check_razor2_rangeMail::SpamAssassin::Plugin::Razor2::check_razor2_range
0000s0sMail::SpamAssassin::Plugin::Razor2::::plugin_reportMail::SpamAssassin::Plugin::Razor2::plugin_report
0000s0sMail::SpamAssassin::Plugin::Razor2::::plugin_revokeMail::SpamAssassin::Plugin::Razor2::plugin_revoke
0000s0sMail::SpamAssassin::Plugin::Razor2::::razor2_accessMail::SpamAssassin::Plugin::Razor2::razor2_access
Call graph for these subroutines as a Graphviz dot language file.
Line State
ments		 Time
on line		 Calls Time
in subs		 Code
1# <@LICENSE>
2# Licensed to the Apache Software Foundation (ASF) under one or more
3# contributor license agreements. See the NOTICE file distributed with
4# this work for additional information regarding copyright ownership.
5# The ASF licenses this file to you under the Apache License, Version 2.0
6# (the "License"); you may not use this file except in compliance with
7# the License. You may obtain a copy of the License at:
8#
9# http://www.apache.org/licenses/LICENSE-2.0
10#
11# Unless required by applicable law or agreed to in writing, software
12# distributed under the License is distributed on an "AS IS" BASIS,
13# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14# See the License for the specific language governing permissions and
15# limitations under the License.
16# </@LICENSE>
17
18=head1 NAME
19
20Mail::SpamAssassin::Plugin::Razor2 - perform Razor check of messages
21
22=head1 SYNOPSIS
23
24 loadplugin Mail::SpamAssassin::Plugin::Razor2
25
26=head1 DESCRIPTION
27
28Vipul's Razor is a distributed, collaborative, spam detection and
29filtering network based on user submissions of spam. Detection is done
30with signatures that efficiently spot mutating spam content and user
31input is validated through reputation assignments.
32
33See http://razor.sourceforge.net/ for more information about Razor.
34
35=head1 USER SETTINGS
36
37=over 4
38
39=cut
40
41package Mail::SpamAssassin::Plugin::Razor2;
42
43262µs138µs
# spent 38µs within Mail::SpamAssassin::Plugin::Razor2::BEGIN@43 which was called: # once (38µs+0s) by Mail::SpamAssassin::PluginHandler::load_plugin at line 43
use Mail::SpamAssassin::Plugin;
# spent 38µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@43
44259µs2353µs
# spent 189µs (25+164) within Mail::SpamAssassin::Plugin::Razor2::BEGIN@44 which was called: # once (25µs+164µs) by Mail::SpamAssassin::PluginHandler::load_plugin at line 44
use Mail::SpamAssassin::Logger;
# spent 189µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@44 # spent 164µs making 1 call to Exporter::import
45253µs113µs
# spent 13µs within Mail::SpamAssassin::Plugin::Razor2::BEGIN@45 which was called: # once (13µs+0s) by Mail::SpamAssassin::PluginHandler::load_plugin at line 45
use Mail::SpamAssassin::Timeout;
# spent 13µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@45
46255µs245µs
# spent 34µs (23+11) within Mail::SpamAssassin::Plugin::Razor2::BEGIN@46 which was called: # once (23µs+11µs) by Mail::SpamAssassin::PluginHandler::load_plugin at line 46
use strict;
# spent 34µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@46 # spent 11µs making 1 call to strict::import
47254µs297µs
# spent 60µs (22+37) within Mail::SpamAssassin::Plugin::Razor2::BEGIN@47 which was called: # once (22µs+37µs) by Mail::SpamAssassin::PluginHandler::load_plugin at line 47
use warnings;
# spent 60µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@47 # spent 37µs making 1 call to warnings::import
48256µs234µs
# spent 27µs (20+7) within Mail::SpamAssassin::Plugin::Razor2::BEGIN@48 which was called: # once (20µs+7µs) by Mail::SpamAssassin::PluginHandler::load_plugin at line 48
use bytes;
# spent 27µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@48 # spent 7µs making 1 call to bytes::import
49261µs2153µs
# spent 87µs (20+66) within Mail::SpamAssassin::Plugin::Razor2::BEGIN@49 which was called: # once (20µs+66µs) by Mail::SpamAssassin::PluginHandler::load_plugin at line 49
use re 'taint';
# spent 87µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@49 # spent 66µs making 1 call to re::import
50
5123.80ms2158µs
# spent 89µs (21+69) within Mail::SpamAssassin::Plugin::Razor2::BEGIN@51 which was called: # once (21µs+69µs) by Mail::SpamAssassin::PluginHandler::load_plugin at line 51
use vars qw(@ISA);
# spent 89µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::BEGIN@51 # spent 69µs making 1 call to vars::import
52116µs@ISA = qw(Mail::SpamAssassin::Plugin);
53
54
# spent 137ms (11.5+126) within Mail::SpamAssassin::Plugin::Razor2::new which was called: # once (11.5ms+126ms) by Mail::SpamAssassin::PluginHandler::load_plugin at line 1 of (eval 44)[Mail/SpamAssassin/PluginHandler.pm:129]
sub new {
5512µs my $class = shift;
5612µs my $mailsaobject = shift;
57
5812µs $class = ref($class) || $class;
59111µs118µs my $self = $class->SUPER::new($mailsaobject);
# spent 18µs making 1 call to Mail::SpamAssassin::Plugin::new
6012µs bless ($self, $class);
61
62 # figure out if razor is even available or not ...
6318µs $self->{razor2_available} = 0;
6415µs if ($mailsaobject->{local_tests_only}) {
65 dbg("razor2: local tests only, skipping Razor");
66 }
67 else {
682298µs if (eval { require Razor2::Client::Agent; }) {
6916µs $self->{razor2_available} = 1;
70120µs118µs dbg("razor2: razor2 is available, version " . $Razor2::Client::Version::VERSION . "\n");
# spent 18µs making 1 call to Mail::SpamAssassin::Logger::dbg
71 }
72 else {
73 dbg("razor2: razor2 is not available");
74 }
75 }
76
77126µs141µs $self->register_eval_rule("check_razor2");
# spent 41µs making 1 call to Mail::SpamAssassin::Plugin::register_eval_rule
7817µs124µs $self->register_eval_rule("check_razor2_range");
# spent 24µs making 1 call to Mail::SpamAssassin::Plugin::register_eval_rule
79
80111µs1199µs $self->set_config($mailsaobject->{conf});
# spent 199µs making 1 call to Mail::SpamAssassin::Plugin::Razor2::set_config
81
82111µs return $self;
83}
84
85
# spent 199µs (49+150) within Mail::SpamAssassin::Plugin::Razor2::set_config which was called: # once (49µs+150µs) by Mail::SpamAssassin::Plugin::Razor2::new at line 80
sub set_config {
8612µs my ($self, $conf) = @_;
8712µs my @cmds;
88
89=item use_razor2 (0|1) (default: 1)
90
91Whether to use Razor2, if it is available.
92
93=cut
94
95110µs push(@cmds, {
96 setting => 'use_razor2',
97 default => 1,
98 type => $Mail::SpamAssassin::Conf::CONF_TYPE_NUMERIC,
99 });
100
101=back
102
103=head1 ADMINISTRATOR SETTINGS
104
105=over 4
106
107=item razor_timeout n (default: 5)
108
109How many seconds you wait for Razor to complete before you go on without
110the results
111
112=cut
113
11418µs push(@cmds, {
115 setting => 'razor_timeout',
116 is_admin => 1,
117 default => 5,
118 type => $Mail::SpamAssassin::Conf::CONF_TYPE_DURATION,
119 });
120
121=item razor_config filename
122
123Define the filename used to store Razor's configuration settings.
124Currently this is left to Razor to decide.
125
126=cut
127
12815µs push(@cmds, {
129 setting => 'razor_config',
130 is_admin => 1,
131 type => $Mail::SpamAssassin::Conf::CONF_TYPE_STRING,
132 });
133
134122µs1150µs $conf->{parser}->register_commands(\@cmds);
# spent 150µs making 1 call to Mail::SpamAssassin::Conf::Parser::register_commands
135}
136
137sub razor2_access {
138 my ($self, $fulltext, $type, $deadline) = @_;
139 my $timeout = $self->{main}->{conf}->{razor_timeout};
140 my $return = 0;
141 my @results;
142
143 my $debug = $type eq 'check' ? 'razor2' : 'reporter';
144
145 # razor also debugs to stdout. argh. fix it to stderr...
146 if (would_log('dbg', $debug)) {
147 open(OLDOUT, ">&STDOUT");
148 open(STDOUT, ">&STDERR");
149 }
150
151 Mail::SpamAssassin::PerMsgStatus::enter_helper_run_mode($self);
152
153 my $rnd = rand(0x7fffffff); # save entropy before Razor clobbers it
154
155 my $timer = Mail::SpamAssassin::Timeout->new(
156 { secs => $timeout, deadline => $deadline });
157 my $err = $timer->run_and_catch(sub {
158
159 local ($^W) = 0; # argh, warnings in Razor
160
161 # everything's in the module!
162 my $rc = Razor2::Client::Agent->new("razor-$type");
163
164 if ($rc) {
165 $rc->{opt} = {
166 debug => (would_log('dbg', $debug) > 1),
167 foreground => 1,
168 config => $self->{main}->{conf}->{razor_config}
169 };
170 # no facility prefix on this die
171 $rc->do_conf() or die "$debug: " . $rc->errstr;
172
173 # Razor2 requires authentication for reporting
174 my $ident;
175 if ($type ne 'check') {
176 # no facility prefix on this die
177 $ident = $rc->get_ident
178 or die("$type requires authentication");
179 }
180
181 my @msg = ($fulltext);
182 # no facility prefix on this die
183 my $objects = $rc->prepare_objects(\@msg)
184 or die "$debug: error in prepare_objects";
185 unless ($rc->get_server_info()) {
186 my $error = $rc->errprefix("$debug: spamassassin") || "$debug: razor2 had unknown error during get_server_info";
187 die $error;
188 }
189
190 # let's reset the alarm since get_server_info() calls
191 # nextserver() which calls discover() which very likely will
192 # reset the alarm for us ... how polite. :(
193 $timer->reset();
194
195 # no facility prefix on this die
196 my $sigs = $rc->compute_sigs($objects)
197 or die "$debug: error in compute_sigs";
198
199 # if mail isn't whitelisted, check it out
200 # see 'man razor-whitelist'
201 if ($type ne 'check' || ! $rc->local_check($objects->[0])) {
202 # provide a better error message when servers are unavailable,
203 # than "Bad file descriptor Died".
204 $rc->connect() or die "$debug: could not connect to any servers\n";
205
206 # Talk to the Razor server and do work
207 if ($type eq 'check') {
208 unless ($rc->check($objects)) {
209 my $error = $rc->errprefix("$debug: spamassassin") || "$debug: razor2 had unknown error during check";
210 die $error;
211 }
212 }
213 else {
214 unless ($rc->authenticate($ident)) {
215 my $error = $rc->errprefix("$debug: spamassassin") || "$debug: razor2 had unknown error during authenticate";
216 die $error;
217 }
218 unless ($rc->report($objects)) {
219 my $error = $rc->errprefix("$debug: spamassassin") || "$debug: razor2 had unknown error during report";
220 die $error;
221 }
222 }
223
224 unless ($rc->disconnect()) {
225 my $error = $rc->errprefix("$debug: spamassassin") || "$debug: razor2 had unknown error during disconnect";
226 die $error;
227 }
228 }
229
230 # Razor 2.14 says that if we get here, we did ok.
231 $return = 1;
232
233 # figure out if we have a log file we need to close...
234 if (ref($rc->{logref}) && exists $rc->{logref}->{fd}) {
235 # the fd can be stdout or stderr, so we need to find out if it is
236 # so we don't close them by accident. Note: we can't just
237 # undef the fd here (like the IO::Handle manpage says we can)
238 # because it won't actually close, unfortunately. :(
239 my $untie = 1;
240 foreach my $log (*STDOUT{IO}, *STDERR{IO}) {
241 if ($log == $rc->{logref}->{fd}) {
242 $untie = 0;
243 last;
244 }
245 }
246 if ($untie) {
247 close($rc->{logref}->{fd}) or die "error closing log: $!";
248 }
249 }
250
251 if ($type eq 'check') {
252 # so $objects->[0] is the first (only) message, and ->{spam} is a general yes/no
253 push(@results, { result => $objects->[0]->{spam} });
254
255 # great for debugging, but leave this off!
256 #use Data::Dumper;
257 #print Dumper($objects),"\n";
258
259 # ->{p} is for each part of the message
260 # so go through each part, taking the highest cf we find
261 # of any part that isn't contested (ct). This helps avoid false
262 # positives. equals logic_method 4.
263 #
264 # razor-agents < 2.14 have a different object format, so we now support both.
265 # $objects->[0]->{resp} vs $objects->[0]->{p}->[part #]->{resp}
266 my $part = 0;
267 my $arrayref = $objects->[0]->{p} || $objects;
268 if (defined $arrayref) {
269 foreach my $cf (@{$arrayref}) {
270 if (exists $cf->{resp}) {
271 for (my $response=0; $response<@{$cf->{resp}}; $response++) {
272 my $tmp = $cf->{resp}->[$response];
273 my $tmpcf = $tmp->{cf}; # Part confidence
274 my $tmpct = $tmp->{ct}; # Part contested?
275 my $engine = $cf->{sent}->[$response]->{e};
276
277 # These should always be set, but just in case ...
278 $tmpcf = 0 unless defined $tmpcf;
279 $tmpct = 0 unless defined $tmpct;
280 $engine = 0 unless defined $engine;
281
282 push(@results,
283 { part => $part, engine => $engine, contested => $tmpct, confidence => $tmpcf });
284 }
285 }
286 else {
287 push(@results, { part => $part, noresponse => 1 });
288 }
289 $part++;
290 }
291 }
292 else {
293 # If we have some new $objects format that isn't close to
294 # the current razor-agents 2.x version, we won't FP but we
295 # should alert in debug.
296 dbg("$debug: it looks like the internal Razor object has changed format!");
297 }
298 }
299 }
300 else {
301 warn "$debug: undefined Razor2::Client::Agent\n";
302 }
303
304 });
305
306 # OK, that's enough Razor stuff. now, reset all that global
307 # state it futzes with :(
308 # work around serious brain damage in Razor2 (constant seed)
309 $rnd ^= int(rand(0xffffffff)); # mix old acc with whatever came out of razor
310 srand; # let Perl give it a try ...
311 $rnd ^= int(rand(0xffffffff)); # ... and mix-in that too
312 srand($rnd & 0x7fffffff); # reseed, keep it unsigned 32-bit just in case
313
314 Mail::SpamAssassin::PerMsgStatus::leave_helper_run_mode($self);
315
316 if ($timer->timed_out()) {
317 dbg("$debug: razor2 $type timed out after $timeout seconds");
318 }
319
320 if ($err) {
321 chomp $err;
322 if ($err =~ /(?:could not connect|network is unreachable)/) {
323 # make this a dbg(); SpamAssassin will still continue,
324 # but without Razor checking. otherwise there may be
325 # DSNs and errors in syslog etc., yuck
326 dbg("$debug: razor2 $type could not connect to any servers");
327 } elsif ($err =~ /timeout/i) {
328 dbg("$debug: razor2 $type timed out connecting to servers");
329 } else {
330 warn("$debug: razor2 $type failed: $! $err");
331 }
332 }
333
334 # razor also debugs to stdout. argh. fix it to stderr...
335 if (would_log('dbg', $debug)) {
336 open(STDOUT, ">&OLDOUT");
337 close OLDOUT;
338 }
339
340 return wantarray ? ($return, @results) : $return;
341}
342
343sub plugin_report {
344 my ($self, $options) = @_;
345
346 return unless $self->{razor2_available};
347 return if $self->{main}->{local_tests_only};
348 return unless $self->{main}->{conf}->{use_razor2};
349 return if $options->{report}->{options}->{dont_report_to_razor};
350
351 if ($self->razor2_access($options->{text}, 'report', undef)) {
352 $options->{report}->{report_available} = 1;
353 info('reporter: spam reported to Razor');
354 $options->{report}->{report_return} = 1;
355 }
356 else {
357 info('reporter: could not report spam to Razor');
358 }
359}
360
361sub plugin_revoke {
362 my ($self, $options) = @_;
363
364 return unless $self->{razor2_available};
365 return if $self->{main}->{local_tests_only};
366 return unless $self->{main}->{conf}->{use_razor2};
367 return if $options->{revoke}->{options}->{dont_report_to_razor};
368
369 if ($self->razor2_access($options->{text}, 'revoke', undef)) {
370 $options->{revoke}->{revoke_available} = 1;
371 dbg('reporter: spam revoked from Razor');
372 $options->{revoke}->{revoke_return} = 1;
373 }
374 else {
375 dbg('reporter: could not revoke spam from Razor');
376 }
377}
378
379sub check_razor2 {
380 my ($self, $permsgstatus, $full) = @_;
381
382 return $permsgstatus->{razor2_result} if (defined $permsgstatus->{razor2_result});
383 $permsgstatus->{razor2_result} = 0;
384 $permsgstatus->{razor2_cf_score} = { '4' => 0, '8' => 0 };
385
386 return unless $self->{razor2_available};
387 return unless $self->{main}->{conf}->{use_razor2};
388
389 my $timer = $self->{main}->time_method("check_razor2");
390
391 my $return;
392 my @results;
393
394 # TODO: check for cache header, set results appropriately
395
396 # do it this way to make it easier to get out the results later from the
397 # netcache plugin
398 ($return, @results) =
399 $self->razor2_access($full, 'check', $permsgstatus->{master_deadline});
400 $self->{main}->call_plugins ('process_razor_result',
401 { results => \@results, permsgstatus => $permsgstatus }
402 );
403
404 foreach my $result (@results) {
405 if (exists $result->{result}) {
406 $permsgstatus->{razor2_result} = $result->{result} if $result->{result};
407 }
408 elsif ($result->{noresponse}) {
409 dbg('razor2: part=' . $result->{part} . ' noresponse');
410 }
411 else {
412 dbg('razor2: part=' . $result->{part} .
413 ' engine=' . $result->{engine} .
414 ' contested=' . $result->{contested} .
415 ' confidence=' . $result->{confidence});
416
417 next if $result->{contested};
418
419 my $cf = $permsgstatus->{razor2_cf_score}->{$result->{engine}} || 0;
420 if ($result->{confidence} > $cf) {
421 $permsgstatus->{razor2_cf_score}->{$result->{engine}} = $result->{confidence};
422 }
423 }
424 }
425
426 dbg("razor2: results: spam? " . $permsgstatus->{razor2_result});
427 while(my ($engine, $cf) = each %{$permsgstatus->{razor2_cf_score}}) {
428 dbg("razor2: results: engine $engine, highest cf score: $cf");
429 }
430
431 return $permsgstatus->{razor2_result};
432}
433
434# Check the cf value of a given message and return if it's within the
435# given range
436sub check_razor2_range {
437 my ($self, $permsgstatus, $body, $engine, $min, $max) = @_;
438
439 # If Razor2 isn't available, or the general test is disabled, don't
440 # continue.
441 return unless $self->{razor2_available};
442 return unless $self->{main}->{conf}->{use_razor2};
443 return unless $self->{main}->{conf}->{scores}->{'RAZOR2_CHECK'};
444
445 # If Razor2 hasn't been checked yet, go ahead and run it.
446 unless (defined $permsgstatus->{razor2_result}) {
447 $self->check_razor2($permsgstatus, $body);
448 }
449
450 my $cf = 0;
451 if ($engine) {
452 $cf = $permsgstatus->{razor2_cf_score}->{$engine};
453 return unless defined $cf;
454 }
455 else {
456 # If no specific engine was given to the rule, find the highest cf
457 # determined and use that
458 while(my ($engine, $ecf) = each %{$permsgstatus->{razor2_cf_score}}) {
459 if ($ecf > $cf) {
460 $cf = $ecf;
461 }
462 }
463 }
464
465 if ($cf >= $min && $cf <= $max) {
466 $permsgstatus->test_log(sprintf("cf: %3d", $cf));
467 return 1;
468 }
469
470 return;
471}
472
47319µs1;
474
475=back
476
477=cut
Report produced by the NYTProf 6.04 Perl profiler, developed by Tim Bunce based on work by Adam Kaplan and Salvador Fandiño García.