← 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:51 2017

Filename/usr/local/lib/perl5/site_perl/Mail/SpamAssassin/DBBasedAddrList.pm
StatementsExecuted 50062270 statements in 1763s
Subroutines
Calls P F Exclusive
Time		 Inclusive
Time		 Subroutine
470311125s1761sMail::SpamAssassin::DBBasedAddrList::::remove_entryMail::SpamAssassin::DBBasedAddrList::remove_entry
249728361197.1s97.1sMail::SpamAssassin::DBBasedAddrList::::CORE:regcompMail::SpamAssassin::DBBasedAddrList::CORE:regcomp (opcode)
249733062153.8s53.8sMail::SpamAssassin::DBBasedAddrList::::CORE:matchMail::SpamAssassin::DBBasedAddrList::CORE:match (opcode)
321611678ms94562sMail::SpamAssassin::DBBasedAddrList::::new_checkerMail::SpamAssassin::DBBasedAddrList::new_checker
322031300ms813msMail::SpamAssassin::DBBasedAddrList::::get_addr_entryMail::SpamAssassin::DBBasedAddrList::get_addr_entry
276631244ms303msMail::SpamAssassin::DBBasedAddrList::::add_scoreMail::SpamAssassin::DBBasedAddrList::add_score
64322124.0ms24.0msMail::SpamAssassin::DBBasedAddrList::::CORE:umaskMail::SpamAssassin::DBBasedAddrList::CORE:umask (opcode)
1111.10ms1.44msMail::SpamAssassin::DBBasedAddrList::::BEGIN@26Mail::SpamAssassin::DBBasedAddrList::BEGIN@26
11157µs69µsMail::SpamAssassin::DBBasedAddrList::::BEGIN@20Mail::SpamAssassin::DBBasedAddrList::BEGIN@20
11155µs1.02msMail::SpamAssassin::DBBasedAddrList::::finishMail::SpamAssassin::DBBasedAddrList::finish
11151µs116µsMail::SpamAssassin::DBBasedAddrList::::BEGIN@23Mail::SpamAssassin::DBBasedAddrList::BEGIN@23
11150µs73µsMail::SpamAssassin::DBBasedAddrList::::newMail::SpamAssassin::DBBasedAddrList::new
11138µs221µsMail::SpamAssassin::DBBasedAddrList::::BEGIN@28Mail::SpamAssassin::DBBasedAddrList::BEGIN@28
11135µs166µsMail::SpamAssassin::DBBasedAddrList::::BEGIN@27Mail::SpamAssassin::DBBasedAddrList::BEGIN@27
11134µs41µsMail::SpamAssassin::DBBasedAddrList::::BEGIN@22Mail::SpamAssassin::DBBasedAddrList::BEGIN@22
11130µs2.48msMail::SpamAssassin::DBBasedAddrList::::BEGIN@24Mail::SpamAssassin::DBBasedAddrList::BEGIN@24
11130µs67µsMail::SpamAssassin::DBBasedAddrList::::BEGIN@21Mail::SpamAssassin::DBBasedAddrList::BEGIN@21
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
18package Mail::SpamAssassin::DBBasedAddrList;
19
20271µs280µs
# spent 69µs (57+12) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@20 which was called: # once (57µs+12µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 20
use strict;
# spent 69µs making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@20 # spent 12µs making 1 call to strict::import
21279µs2105µs
# spent 67µs (30+37) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@21 which was called: # once (30µs+37µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 21
use warnings;
# spent 67µs making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@21 # spent 38µs making 1 call to warnings::import
22275µs248µs
# spent 41µs (34+7) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@22 which was called: # once (34µs+7µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 22
use bytes;
# spent 41µs making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@22 # spent 7µs making 1 call to bytes::import
23274µs2182µs
# spent 116µs (51+65) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@23 which was called: # once (51µs+65µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 23
use re 'taint';
# spent 116µs making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@23 # spent 65µs making 1 call to re::import
24278µs24.93ms
# spent 2.48ms (30µs+2.45) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@24 which was called: # once (30µs+2.45ms) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 24
use Fcntl;
# spent 2.48ms making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@24 # spent 2.45ms making 1 call to Exporter::import
25
262426µs11.44ms
# spent 1.44ms (1.10+345µs) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@26 which was called: # once (1.10ms+345µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 26
use Mail::SpamAssassin::PersistentAddrList;
# spent 1.44ms making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@26
27291µs2296µs
# spent 166µs (35+131) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@27 which was called: # once (35µs+131µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 27
use Mail::SpamAssassin::Util qw(untaint_var);
# spent 166µs making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@27 # spent 131µs making 1 call to Exporter::import
2821.62ms2403µs
# spent 221µs (38+182) within Mail::SpamAssassin::DBBasedAddrList::BEGIN@28 which was called: # once (38µs+182µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 28
use Mail::SpamAssassin::Logger;
# spent 221µs making 1 call to Mail::SpamAssassin::DBBasedAddrList::BEGIN@28 # spent 182µs making 1 call to Exporter::import
29
30114µsour @ISA = qw(Mail::SpamAssassin::PersistentAddrList);
31
32###########################################################################
33
34
# spent 73µs (50+23) within Mail::SpamAssassin::DBBasedAddrList::new which was called: # once (50µs+23µs) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 2 of (eval 1135)[Mail/SpamAssassin/Plugin/TxRep.pm:1645]
sub new {
3512µs my $class = shift;
3612µs $class = ref($class) || $class;
37113µs123µs my $self = $class->SUPER::new(@_);
# spent 23µs making 1 call to Mail::SpamAssassin::PersistentAddrList::new
38114µs $self->{class} = $class;
3912µs bless ($self, $class);
40115µs $self;
41}
42
43###########################################################################
44
45
# spent 94562s (678ms+94561) within Mail::SpamAssassin::DBBasedAddrList::new_checker which was called 3216 times, avg 29.4s/call: # 3216 times (678ms+94561s) by Mail::SpamAssassin::Plugin::TxRep::open_storages at line 1654 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 29.4s/call
sub new_checker {
4632167.39ms my ($factory, $main) = @_;
47321612.5ms my $class = $factory->{class};
48
49321628.2ms my $self = {
50 'main' => $main,
51 'accum' => { },
52 'is_locked' => 0,
53 'locked_file' => ''
54 };
55
56321635.9ms my @order = split (' ', $main->{conf}->{auto_whitelist_db_modules});
57321634.1ms3216579ms untaint_var(\@order);
# spent 579ms making 3216 calls to Mail::SpamAssassin::Util::untaint_var, avg 180µs/call
58321632.3ms3216368ms my $dbm_module = Mail::SpamAssassin::Util::first_available_module (@order);
# spent 368ms making 3216 calls to Mail::SpamAssassin::Util::first_available_module, avg 114µs/call
5932166.61ms if (!$dbm_module) {
60 die "auto-whitelist: cannot find a usable DB package from auto_whitelist_db_modules: " .
61 $main->{conf}->{auto_whitelist_db_modules}."\n";
62 }
63
64321656.4ms321610.9ms my $umask = umask ~ (oct($main->{conf}->{auto_whitelist_file_mode}));
# spent 10.9ms making 3216 calls to Mail::SpamAssassin::DBBasedAddrList::CORE:umask, avg 3µs/call
65
66 # if undef then don't worry -- empty hash!
67321617.5ms if (defined($main->{conf}->{auto_whitelist_path})) {
68321636.8ms321662.1ms my $path = $main->sed_path($main->{conf}->{auto_whitelist_path});
# spent 62.1ms making 3216 calls to Mail::SpamAssassin::sed_path, avg 19µs/call
6932166.57ms my ($mod1, $mod2);
70
71321647.0ms321694559s if ($main->{locker}->safe_lock
# spent 94559s making 3216 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock, avg 29.4s/call
72 ($path, 30, $main->{conf}->{auto_whitelist_file_mode}))
73 {
74161981µs $self->{locked_file} = $path;
75161537µs $self->{is_locked} = 1;
76161633µs ($mod1, $mod2) = ('R/W', O_RDWR | O_CREAT);
77 }
78 else {
79305516.0ms $self->{is_locked} = 0;
80305513.5ms ($mod1, $mod2) = ('R/O', O_RDONLY);
81 }
82
83321635.9ms321625.1ms dbg("auto-whitelist: tie-ing to DB file of type $dbm_module $mod1 in $path");
# spent 25.1ms making 3216 calls to Mail::SpamAssassin::Logger::dbg, avg 8µs/call
84
8532169.80ms161185ms ($self->{is_locked} && $dbm_module eq 'DB_File') and
# spent 185ms making 161 calls to Mail::SpamAssassin::Util::avoid_db_file_locking_bug, avg 1.15ms/call
86 Mail::SpamAssassin::Util::avoid_db_file_locking_bug($path);
87
886432131ms3216774ms if (! tie %{ $self->{accum} }, $dbm_module, $path, $mod2,
# spent 774ms making 3216 calls to DB_File::TIEHASH, avg 241µs/call
89 oct($main->{conf}->{auto_whitelist_file_mode}) & 0666)
90 {
91 my $err = $!; # might get overwritten later
92 if ($self->{is_locked}) {
93 $self->{main}->{locker}->safe_unlock($self->{locked_file});
94 $self->{is_locked} = 0;
95 }
96 die "auto-whitelist: cannot open auto_whitelist_path $path: $err\n";
97 }
98 }
99321648.3ms321613.1ms umask $umask;
# spent 13.1ms making 3216 calls to Mail::SpamAssassin::DBBasedAddrList::CORE:umask, avg 4µs/call
100
101321613.0ms bless ($self, $class);
102321654.0ms return $self;
103}
104
105###########################################################################
106
107
# spent 1.02ms (55µs+960µs) within Mail::SpamAssassin::DBBasedAddrList::finish which was called: # once (55µs+960µs) by Mail::SpamAssassin::Plugin::TxRep::finish at line 1722 of Mail/SpamAssassin/Plugin/TxRep.pm
sub finish {
10812µs my $self = shift;
10918µs16µs dbg("auto-whitelist: DB addr list: untie-ing and unlocking");
# spent 6µs making 1 call to Mail::SpamAssassin::Logger::dbg
1102984µs1954µs untie %{$self->{accum}};
# spent 954µs making 1 call to DB_File::DESTROY
111114µs if ($self->{is_locked}) {
112 dbg("auto-whitelist: DB addr list: file locked, breaking lock");
113 $self->{main}->{locker}->safe_unlock ($self->{locked_file});
114 $self->{is_locked} = 0;
115 }
116 # TODO: untrap signals to unlock the db file here
117}
118
119###########################################################################
120
121
# spent 813ms (300+513) within Mail::SpamAssassin::DBBasedAddrList::get_addr_entry which was called 3220 times, avg 252µs/call: # 3216 times (299ms+513ms) by Mail::SpamAssassin::Plugin::TxRep::get_sender at line 1539 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 252µs/call # 2 times (176µs+314µs) by Mail::SpamAssassin::Plugin::TxRep::modify_reputation at line 1618 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 245µs/call # 2 times (159µs+268µs) by Mail::SpamAssassin::Plugin::TxRep::modify_reputation at line 1608 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 214µs/call
sub get_addr_entry {
122322015.2ms my ($self, $addr, $signedby) = @_;
123
124322023.7ms my $entry = {
125 addr => $addr,
126 };
127
1283220368ms3220266ms $entry->{count} = $self->{accum}->{$addr} || 0;
# spent 266ms making 3220 calls to DB_File::FETCH, avg 82µs/call
1293220279ms3220211ms $entry->{totscore} = $self->{accum}->{$addr.'|totscore'} || 0;
# spent 211ms making 3220 calls to DB_File::FETCH, avg 65µs/call
130
131322054.1ms322036.7ms dbg("auto-whitelist: db-based $addr scores ".$entry->{count}.'/'.$entry->{totscore});
# spent 36.7ms making 3220 calls to Mail::SpamAssassin::Logger::dbg, avg 11µs/call
132322042.9ms return $entry;
133}
134
135###########################################################################
136
137
# spent 303ms (244+59.5) within Mail::SpamAssassin::DBBasedAddrList::add_score which was called 2766 times, avg 110µs/call: # 1390 times (123ms+29.8ms) by Mail::SpamAssassin::Plugin::TxRep::add_score at line 1573 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 110µs/call # 1374 times (121ms+29.6ms) by Mail::SpamAssassin::Plugin::TxRep::remove_score at line 1596 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 109µs/call # 2 times (166µs+43µs) by Mail::SpamAssassin::Plugin::TxRep::modify_reputation at line 1619 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 105µs/call
sub add_score {
138276611.2ms my($self, $entry, $score) = @_;
139
14027668.55ms $entry->{count} ||= 0;
14127666.69ms $entry->{addr} ||= '';
142
14327667.73ms $entry->{count}++;
144276610.4ms $entry->{totscore} += $score;
145
146276640.5ms276620.9ms dbg("auto-whitelist: add_score: new count: ".$entry->{count}.", new totscore: ".$entry->{totscore});
# spent 20.9ms making 2766 calls to Mail::SpamAssassin::Logger::dbg, avg 8µs/call
147
148276680.0ms276621.7ms $self->{accum}->{$entry->{addr}} = $entry->{count};
# spent 21.7ms making 2766 calls to DB_File::STORE, avg 8µs/call
149276664.6ms276616.8ms $self->{accum}->{$entry->{addr}.'|totscore'} = $entry->{totscore};
# spent 16.8ms making 2766 calls to DB_File::STORE, avg 6µs/call
150276632.4ms return $entry;
151}
152
153###########################################################################
154
155
# spent 1761s (1125+636) within Mail::SpamAssassin::DBBasedAddrList::remove_entry which was called 470 times, avg 3.75s/call: # 234 times (562s+317s) by Mail::SpamAssassin::Plugin::TxRep::check_reputation at line 1509 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 3.76s/call # 234 times (559s+317s) by Mail::SpamAssassin::Plugin::TxRep::check_reputation at line 1500 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 3.74s/call # 2 times (4.37s+1.99s) by Mail::SpamAssassin::Plugin::TxRep::modify_reputation at line 1613 of Mail/SpamAssassin/Plugin/TxRep.pm, avg 3.18s/call
sub remove_entry {
1564701.10ms my ($self, $entry) = @_;
157
1584701.79ms my $addr = $entry->{addr};
15947021.7ms4703.31ms delete $self->{accum}->{$addr};
# spent 3.31ms making 470 calls to DB_File::DELETE, avg 7µs/call
1604709.65ms4702.33ms delete $self->{accum}->{$addr.'|totscore'};
# spent 2.33ms making 470 calls to DB_File::DELETE, avg 5µs/call
161
16247017.0ms4706.22ms if ($addr =~ /^(.*)\|ip=none$/) {
# spent 6.22ms making 470 calls to Mail::SpamAssassin::DBBasedAddrList::CORE:match, avg 13µs/call
163 # it doesn't have an IP attached.
164 # try to delete any per-IP entries for this addr as well.
165 # could be slow...
1664702.74ms my $mailaddr = $1;
167
168249737761241s49946142486s while (my ($key, $value) = each %{$self->{accum}}) {
# spent 265s making 24972836 calls to DB_File::FETCH, avg 11µs/call # spent 221s making 24972836 calls to DB_File::NEXTKEY, avg 9µs/call # spent 29.0ms making 470 calls to DB_File::FIRSTKEY, avg 62µs/call
169 # regex will catch both key and key|totscore entries and delete them
17024972836521s49945672151s if ($key =~ /^\Q${mailaddr}\E\|/) {
# spent 97.1s making 24972836 calls to Mail::SpamAssassin::DBBasedAddrList::CORE:regcomp, avg 4µs/call # spent 53.8s making 24972836 calls to Mail::SpamAssassin::DBBasedAddrList::CORE:match, avg 2µs/call
17189822.5ms8986.54ms delete $self->{accum}->{$key};
# spent 6.54ms making 898 calls to DB_File::DELETE, avg 7µs/call
172 }
173 }
174 }
175}
176
177###########################################################################
178
179110µs1;
 
# spent 53.8s within Mail::SpamAssassin::DBBasedAddrList::CORE:match which was called 24973306 times, avg 2µs/call: # 24972836 times (53.8s+0s) by Mail::SpamAssassin::DBBasedAddrList::remove_entry at line 170, avg 2µs/call # 470 times (6.22ms+0s) by Mail::SpamAssassin::DBBasedAddrList::remove_entry at line 162, avg 13µs/call
sub Mail::SpamAssassin::DBBasedAddrList::CORE:match; # opcode
# spent 97.1s within Mail::SpamAssassin::DBBasedAddrList::CORE:regcomp which was called 24972836 times, avg 4µs/call: # 24972836 times (97.1s+0s) by Mail::SpamAssassin::DBBasedAddrList::remove_entry at line 170, avg 4µs/call
sub Mail::SpamAssassin::DBBasedAddrList::CORE:regcomp; # opcode
# spent 24.0ms within Mail::SpamAssassin::DBBasedAddrList::CORE:umask which was called 6432 times, avg 4µs/call: # 3216 times (13.1ms+0s) by Mail::SpamAssassin::DBBasedAddrList::new_checker at line 99, avg 4µs/call # 3216 times (10.9ms+0s) by Mail::SpamAssassin::DBBasedAddrList::new_checker at line 64, avg 3µs/call
sub Mail::SpamAssassin::DBBasedAddrList::CORE:umask; # opcode
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.