Filename | /usr/local/lib/perl5/site_perl/Mail/SpamAssassin/PluginHandler.pm |
Statements | Executed 27260 statements in 129ms |
Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
---|---|---|---|---|---|
27 | 1 | 1 | 158ms | 549ms | load_plugin | Mail::SpamAssassin::PluginHandler::
1916 | 1 | 1 | 109ms | 1576s | callback (recurses: max depth 1, inclusive time 14.4s) | Mail::SpamAssassin::PluginHandler::
12 | 1 | 1 | 6.78ms | 9.45ms | have_callback | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 2.41ms | 3.00ms | BEGIN@27 | Mail::SpamAssassin::PluginHandler::
27 | 1 | 1 | 797µs | 797µs | register_plugin | Mail::SpamAssassin::PluginHandler::
12 | 1 | 1 | 53µs | 53µs | CORE:sort (opcode) | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 39µs | 39µs | BEGIN@26 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 34µs | 127µs | BEGIN@28 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 28µs | 28µs | new | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 28µs | 151µs | BEGIN@37 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 28µs | 101µs | BEGIN@34 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 24µs | 39µs | BEGIN@33 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 24µs | 39µs | BEGIN@31 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 22µs | 56µs | BEGIN@32 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 20µs | 216µs | BEGIN@29 | Mail::SpamAssassin::PluginHandler::
1 | 1 | 1 | 20µs | 20µs | BEGIN@35 | Mail::SpamAssassin::PluginHandler::
0 | 0 | 0 | 0s | 0s | finish | Mail::SpamAssassin::PluginHandler::
0 | 0 | 0 | 0s | 0s | get_loaded_plugins_list | Mail::SpamAssassin::PluginHandler::
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 | |||||
20 | Mail::SpamAssassin::PluginHandler - SpamAssassin plugin handler | ||||
21 | |||||
22 | =cut | ||||
23 | |||||
24 | package Mail::SpamAssassin::PluginHandler; | ||||
25 | |||||
26 | 2 | 63µs | 1 | 39µs | # spent 39µs within Mail::SpamAssassin::PluginHandler::BEGIN@26 which was called:
# once (39µs+0s) by Mail::SpamAssassin::BEGIN@76 at line 26 # spent 39µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@26 |
27 | 2 | 415µs | 1 | 3.00ms | # spent 3.00ms (2.41+592µs) within Mail::SpamAssassin::PluginHandler::BEGIN@27 which was called:
# once (2.41ms+592µs) by Mail::SpamAssassin::BEGIN@76 at line 27 # spent 3.00ms making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@27 |
28 | 2 | 71µs | 2 | 220µs | # spent 127µs (34+93) within Mail::SpamAssassin::PluginHandler::BEGIN@28 which was called:
# once (34µs+93µs) by Mail::SpamAssassin::BEGIN@76 at line 28 # spent 127µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@28
# spent 93µs making 1 call to Exporter::import |
29 | 2 | 64µs | 2 | 412µs | # spent 216µs (20+196) within Mail::SpamAssassin::PluginHandler::BEGIN@29 which was called:
# once (20µs+196µs) by Mail::SpamAssassin::BEGIN@76 at line 29 # spent 216µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@29
# spent 196µs making 1 call to Exporter::import |
30 | |||||
31 | 2 | 68µs | 2 | 54µs | # spent 39µs (24+15) within Mail::SpamAssassin::PluginHandler::BEGIN@31 which was called:
# once (24µs+15µs) by Mail::SpamAssassin::BEGIN@76 at line 31 # spent 39µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@31
# spent 15µs making 1 call to strict::import |
32 | 2 | 72µs | 2 | 90µs | # spent 56µs (22+34) within Mail::SpamAssassin::PluginHandler::BEGIN@32 which was called:
# once (22µs+34µs) by Mail::SpamAssassin::BEGIN@76 at line 32 # spent 56µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@32
# spent 34µs making 1 call to warnings::import |
33 | 2 | 69µs | 2 | 53µs | # spent 39µs (24+14) within Mail::SpamAssassin::PluginHandler::BEGIN@33 which was called:
# once (24µs+14µs) by Mail::SpamAssassin::BEGIN@76 at line 33 # spent 39µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@33
# spent 14µs making 1 call to bytes::import |
34 | 2 | 66µs | 2 | 174µs | # spent 101µs (28+73) within Mail::SpamAssassin::PluginHandler::BEGIN@34 which was called:
# once (28µs+73µs) by Mail::SpamAssassin::BEGIN@76 at line 34 # spent 101µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@34
# spent 73µs making 1 call to re::import |
35 | 2 | 79µs | 1 | 20µs | # spent 20µs within Mail::SpamAssassin::PluginHandler::BEGIN@35 which was called:
# once (20µs+0s) by Mail::SpamAssassin::BEGIN@76 at line 35 # spent 20µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@35 |
36 | |||||
37 | 1 | 2µs | # spent 151µs (28+124) within Mail::SpamAssassin::PluginHandler::BEGIN@37 which was called:
# once (28µs+124µs) by Mail::SpamAssassin::BEGIN@76 at line 39 | ||
38 | @ISA @CONFIG_TIME_HOOKS | ||||
39 | 1 | 1.87ms | 2 | 275µs | }; # spent 151µs making 1 call to Mail::SpamAssassin::PluginHandler::BEGIN@37
# spent 124µs making 1 call to vars::import |
40 | |||||
41 | 1 | 11µs | @ISA = qw(); | ||
42 | |||||
43 | #Removed $VERSION per BUG 6422 | ||||
44 | #$VERSION = 'bogus'; # avoid CPAN.pm picking up version strings later | ||||
45 | |||||
46 | # Normally, the list of active plugins that should be called for a given hook | ||||
47 | # method name is compiled and cached at runtime. This means that later calls | ||||
48 | # will not have to traverse the entire plugin list more than once, since the | ||||
49 | # list of plugins that implement that hook is already cached. | ||||
50 | # | ||||
51 | # However, some hooks should not receive this treatment. One of these is | ||||
52 | # parse_config, which may be compiled before all config files have been read; | ||||
53 | # if a plugin is loaded from a config file after this has been compiled, it | ||||
54 | # will not get callbacks. | ||||
55 | # | ||||
56 | # Any other such hooks that may be compiled at config-parse-time should be | ||||
57 | # listed here. | ||||
58 | |||||
59 | 1 | 2µs | @CONFIG_TIME_HOOKS = qw( parse_config ); | ||
60 | |||||
61 | ########################################################################### | ||||
62 | |||||
63 | # spent 28µs within Mail::SpamAssassin::PluginHandler::new which was called:
# once (28µs+0s) by Mail::SpamAssassin::new at line 433 of Mail/SpamAssassin.pm | ||||
64 | 1 | 3µs | my $class = shift; | ||
65 | 1 | 2µs | my $main = shift; | ||
66 | 1 | 3µs | $class = ref($class) || $class; | ||
67 | 1 | 8µs | my $self = { | ||
68 | plugins => [ ], | ||||
69 | cbs => { }, | ||||
70 | main => $main | ||||
71 | }; | ||||
72 | 1 | 3µs | bless ($self, $class); | ||
73 | 1 | 10µs | $self; | ||
74 | } | ||||
75 | |||||
76 | ########################################################################### | ||||
77 | |||||
78 | # spent 549ms (158+391) within Mail::SpamAssassin::PluginHandler::load_plugin which was called 27 times, avg 20.3ms/call:
# 27 times (158ms+391ms) by Mail::SpamAssassin::Conf::load_plugin at line 4949 of Mail/SpamAssassin/Conf.pm, avg 20.3ms/call | ||||
79 | 27 | 61µs | my ($self, $package, $path, $silent) = @_; | ||
80 | |||||
81 | # Don't load the same plugin twice! | ||||
82 | # Do this *before* calling ->new(), otherwise eval rules will be | ||||
83 | # registered on a nonexistent object | ||||
84 | 54 | 308µs | foreach my $old_plugin (@{$self->{plugins}}) { | ||
85 | 351 | 1.82ms | if (ref($old_plugin) eq $package) { | ||
86 | dbg("plugin: did not register $package, already registered"); | ||||
87 | return; | ||||
88 | } | ||||
89 | } | ||||
90 | |||||
91 | 27 | 44µs | my $ret; | ||
92 | 27 | 156µs | if ($path) { | ||
93 | # bug 3717: | ||||
94 | # At least Perl 5.8.0 seems to confuse $cwd internally at some point -- we | ||||
95 | # need to use an absolute path here else we get a "File not found" error. | ||||
96 | $path = Mail::SpamAssassin::Util::untaint_file_path( | ||||
97 | File::Spec->rel2abs($path) | ||||
98 | ); | ||||
99 | |||||
100 | # if (exists $INC{$path}) { | ||||
101 | # dbg("plugin: not loading $package from $path, already loaded"); | ||||
102 | # return; | ||||
103 | # } | ||||
104 | |||||
105 | dbg("plugin: loading $package from $path"); | ||||
106 | |||||
107 | # use require instead of "do", so we get built-in $INC{filename} | ||||
108 | # smarts | ||||
109 | $ret = eval { require $path; }; | ||||
110 | } | ||||
111 | else { | ||||
112 | 27 | 272µs | 27 | 266µs | dbg("plugin: loading $package from \@INC"); # spent 266µs making 27 calls to Mail::SpamAssassin::Logger::dbg, avg 10µs/call |
113 | 27 | 1.53ms | $ret = eval qq{ require $package; }; # spent 1.44ms executing statements in string eval
# spent 615µs executing statements in string eval
# spent 615µs executing statements in string eval
# spent 577µs executing statements in string eval
# spent 431µs executing statements in string eval
# spent 411µs executing statements in string eval
# spent 363µs executing statements in string eval
# spent 357µs executing statements in string eval
# spent 350µs executing statements in string eval
# spent 346µs executing statements in string eval
# spent 340µs executing statements in string eval
# spent 337µs executing statements in string eval
# spent 336µs executing statements in string eval
# spent 330µs executing statements in string eval
# spent 316µs executing statements in string eval
# spent 297µs executing statements in string eval
# spent 294µs executing statements in string eval
# spent 292µs executing statements in string eval
# spent 292µs executing statements in string eval
# spent 287µs executing statements in string eval
# spent 285µs executing statements in string eval
# spent 283µs executing statements in string eval
# spent 269µs executing statements in string eval
# spent 268µs executing statements in string eval
# spent 264µs executing statements in string eval
# spent 254µs executing statements in string eval
# spent 8µs executing statements in string eval | ||
114 | 27 | 138µs | $path = "(from \@INC)"; | ||
115 | } | ||||
116 | |||||
117 | 27 | 45µs | if (!$ret) { | ||
118 | if ($silent) { | ||||
119 | if ($@) { dbg("plugin: failed to parse tryplugin $path: $@\n"); } | ||||
120 | elsif ($!) { dbg("plugin: failed to load tryplugin $path: $!\n"); } | ||||
121 | } | ||||
122 | else { | ||||
123 | if ($@) { warn "plugin: failed to parse plugin $path: $@\n"; } | ||||
124 | elsif ($!) { warn "plugin: failed to load plugin $path: $!\n"; } | ||||
125 | } | ||||
126 | return; # failure! no point in continuing here | ||||
127 | } | ||||
128 | |||||
129 | 27 | 1.81ms | my $plugin = eval $package.q{->new ($self->{main}); }; # spent 24µs executing statements in string eval
# spent 20µs executing statements in string eval
# spent 20µs executing statements in string eval
# spent 18µs executing statements in string eval
# spent 18µs executing statements in string eval
# spent 18µs executing statements in string eval
# spent 17µs executing statements in string eval
# spent 16µs executing statements in string eval
# spent 16µs executing statements in string eval
# spent 16µs executing statements in string eval
# spent 16µs executing statements in string eval
# spent 16µs executing statements in string eval
# spent 16µs executing statements in string eval
# spent 15µs executing statements in string eval
# spent 15µs executing statements in string eval
# spent 15µs executing statements in string eval
# spent 15µs executing statements in string eval
# spent 15µs executing statements in string eval
# spent 15µs executing statements in string eval
# spent 14µs executing statements in string eval
# spent 14µs executing statements in string eval
# spent 14µs executing statements in string eval
# spent 14µs executing statements in string eval
# spent 14µs executing statements in string eval
# spent 14µs executing statements in string eval
# spent 14µs executing statements in string eval
# spent 14µs executing statements in string eval | ||
130 | |||||
131 | 27 | 127µs | if ($@ || !$plugin) { | ||
132 | warn "plugin: failed to create instance of plugin $package: $@\n"; | ||||
133 | } | ||||
134 | |||||
135 | 27 | 346µs | if ($plugin) { | ||
136 | 27 | 259µs | 27 | 797µs | $self->{main}->{plugins}->register_plugin ($plugin); # spent 797µs making 27 calls to Mail::SpamAssassin::PluginHandler::register_plugin, avg 30µs/call |
137 | 27 | 262µs | 27 | 360µs | $self->{main}->{conf}->load_plugin_succeeded ($plugin, $package, $path); # spent 360µs making 27 calls to Mail::SpamAssassin::Conf::load_plugin_succeeded, avg 13µs/call |
138 | } | ||||
139 | } | ||||
140 | |||||
141 | # spent 797µs within Mail::SpamAssassin::PluginHandler::register_plugin which was called 27 times, avg 30µs/call:
# 27 times (797µs+0s) by Mail::SpamAssassin::PluginHandler::load_plugin at line 136, avg 30µs/call | ||||
142 | 27 | 60µs | my ($self, $plugin) = @_; | ||
143 | 27 | 110µs | $plugin->{main} = $self->{main}; | ||
144 | 54 | 209µs | push (@{$self->{plugins}}, $plugin); | ||
145 | # dbg("plugin: registered $plugin"); | ||||
146 | |||||
147 | # invalidate cache entries for any configuration-time hooks, in case | ||||
148 | # one has already been built; this plugin may implement that hook! | ||||
149 | 27 | 388µs | foreach my $subname (@CONFIG_TIME_HOOKS) { | ||
150 | 27 | 117µs | delete $self->{cbs}->{$subname}; | ||
151 | } | ||||
152 | } | ||||
153 | |||||
154 | ########################################################################### | ||||
155 | |||||
156 | # spent 9.45ms (6.78+2.67) within Mail::SpamAssassin::PluginHandler::have_callback which was called 12 times, avg 787µs/call:
# 12 times (6.78ms+2.67ms) by Mail::SpamAssassin::PluginHandler::callback at line 195, avg 787µs/call | ||||
157 | 12 | 31µs | my ($self, $subname) = @_; | ||
158 | |||||
159 | # have we set up the cache entry for this callback type? | ||||
160 | 12 | 54µs | if (!exists $self->{cbs}->{$subname}) { | ||
161 | # nope. run through all registered plugins and see which ones | ||||
162 | # implement this type of callback. sort by priority | ||||
163 | |||||
164 | 12 | 26µs | my %subsbypri; | ||
165 | 24 | 130µs | foreach my $plugin (@{$self->{plugins}}) { | ||
166 | 324 | 5.44ms | 324 | 2.51ms | my $methodref = $plugin->can ($subname); # spent 2.51ms making 324 calls to UNIVERSAL::can, avg 8µs/call |
167 | 324 | 2.71ms | if (defined $methodref) { | ||
168 | 12 | 76µs | my $pri = $plugin->{method_priority}->{$subname} || 0; | ||
169 | |||||
170 | 12 | 44µs | $subsbypri{$pri} ||= []; | ||
171 | 24 | 121µs | push (@{$subsbypri{$pri}}, [ $plugin, $methodref ]); | ||
172 | |||||
173 | 12 | 143µs | 12 | 105µs | dbg("plugin: ${plugin} implements '$subname', priority $pri"); # spent 105µs making 12 calls to Mail::SpamAssassin::Logger::dbg, avg 9µs/call |
174 | } | ||||
175 | } | ||||
176 | |||||
177 | 12 | 23µs | my @subs; | ||
178 | 12 | 216µs | 12 | 53µs | foreach my $pri (sort { $a <=> $b } keys %subsbypri) { # spent 53µs making 12 calls to Mail::SpamAssassin::PluginHandler::CORE:sort, avg 4µs/call |
179 | 16 | 82µs | push @subs, @{$subsbypri{$pri}}; | ||
180 | } | ||||
181 | |||||
182 | 12 | 71µs | $self->{cbs}->{$subname} = \@subs; | ||
183 | } | ||||
184 | |||||
185 | 24 | 149µs | return scalar(@{$self->{cbs}->{$subname}}); | ||
186 | } | ||||
187 | |||||
188 | # spent 1576s (109ms+1576) within Mail::SpamAssassin::PluginHandler::callback which was called 1916 times, avg 822ms/call:
# 1916 times (109ms+1576s) by Mail::SpamAssassin::call_plugins at line 2131 of Mail/SpamAssassin.pm, avg 822ms/call | ||||
189 | 1916 | 3.67ms | my $self = shift; | ||
190 | 1916 | 4.12ms | my $subname = shift; | ||
191 | 1916 | 3.48ms | my ($ret, $overallret); | ||
192 | |||||
193 | # have we set up the cache entry for this callback type? | ||||
194 | 1916 | 8.60ms | if (!exists $self->{cbs}->{$subname}) { | ||
195 | 12 | 134µs | 12 | 9.45ms | return unless $self->have_callback($subname); # spent 9.45ms making 12 calls to Mail::SpamAssassin::PluginHandler::have_callback, avg 787µs/call |
196 | } | ||||
197 | |||||
198 | 3824 | 22.5ms | foreach my $cbpair (@{$self->{cbs}->{$subname}}) { | ||
199 | 1448 | 4.01ms | my ($plugin, $methodref) = @$cbpair; | ||
200 | |||||
201 | 1448 | 4.30ms | $plugin->{_inhibit_further_callbacks} = 0; | ||
202 | |||||
203 | eval { | ||||
204 | 1448 | 13.3ms | 1448 | 1590s | $ret = &$methodref ($plugin, @_); # spent 1520s making 235 calls to Mail::SpamAssassin::Plugin::TxRep::learn_message, avg 6.47s/call
# spent 50.0s making 235 calls to Mail::SpamAssassin::Plugin::Bayes::learn_message, avg 213ms/call
# spent 14.3s making 235 calls to Mail::SpamAssassin::Plugin::URIDNSBL::parsed_metadata, avg 60.8ms/call
# spent 5.48s making 1 call to Mail::SpamAssassin::Plugin::TxRep::learner_close
# spent 133ms making 1 call to Mail::SpamAssassin::Plugin::ReplaceTags::finish_parsing_end
# spent 115ms making 501 calls to Mail::SpamAssassin::Plugin::FreeMail::parse_config, avg 229µs/call
# spent 67.0ms making 235 calls to Mail::SpamAssassin::Plugin::AskDNS::extract_metadata, avg 285µs/call
# spent 33.4ms making 1 call to Mail::SpamAssassin::Plugin::Bayes::learner_new
# spent 2.20ms making 1 call to Mail::SpamAssassin::Plugin::FreeMail::finish_parsing_end
# spent 1.25ms making 1 call to Mail::SpamAssassin::Plugin::Bayes::learner_close
# spent 542µs making 1 call to Mail::SpamAssassin::Plugin::Bayes::learner_is_scan_available
# spent 16µs making 1 call to Mail::SpamAssassin::Plugin::TxRep::learner_new |
205 | 1448 | 3.45ms | 1; | ||
206 | 1448 | 5.69ms | } or do { | ||
207 | my $eval_stat = $@ ne '' ? $@ : "errno=$!"; chomp $eval_stat; | ||||
208 | warn "plugin: eval failed: $eval_stat\n"; | ||||
209 | }; | ||||
210 | |||||
211 | 1448 | 5.15ms | if (defined $ret) { | ||
212 | # dbg("plugin: ${plugin}->${methodref} => $ret"); | ||||
213 | # we are interested in defined but false results too | ||||
214 | 1447 | 3.38ms | $overallret = $ret if $ret || !defined $overallret; | ||
215 | } | ||||
216 | |||||
217 | 1448 | 6.56ms | if ($plugin->{_inhibit_further_callbacks}) { | ||
218 | # dbg("plugin: $plugin inhibited further callbacks"); | ||||
219 | 501 | 911µs | last; | ||
220 | } | ||||
221 | } | ||||
222 | |||||
223 | 1912 | 19.1ms | return $overallret; | ||
224 | } | ||||
225 | |||||
226 | ########################################################################### | ||||
227 | |||||
228 | sub get_loaded_plugins_list { | ||||
229 | my ($self) = @_; | ||||
230 | return @{$self->{plugins}}; | ||||
231 | } | ||||
232 | |||||
233 | ########################################################################### | ||||
234 | |||||
235 | sub finish { | ||||
236 | my $self = shift; | ||||
237 | delete $self->{cbs}; | ||||
238 | foreach my $plugin (@{$self->{plugins}}) { | ||||
239 | $plugin->finish(); | ||||
240 | delete $plugin->{main}; | ||||
241 | } | ||||
242 | delete $self->{plugins}; | ||||
243 | delete $self->{main}; | ||||
244 | } | ||||
245 | |||||
246 | ########################################################################### | ||||
247 | |||||
248 | 1 | 25µs | 1; | ||
# spent 53µs within Mail::SpamAssassin::PluginHandler::CORE:sort which was called 12 times, avg 4µs/call:
# 12 times (53µs+0s) by Mail::SpamAssassin::PluginHandler::have_callback at line 178, avg 4µs/call |