← 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/Locker/UnixNFSSafe.pm
StatementsExecuted 1288077 statements in 31.9s
Subroutines
Calls P F Exclusive
Time
Inclusive
Time
Subroutine
32172214.7s94559sMail::SpamAssassin::Locker::UnixNFSSafe::::safe_lockMail::SpamAssassin::Locker::UnixNFSSafe::safe_lock
94106216.62s6.62sMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:printMail::SpamAssassin::Locker::UnixNFSSafe::CORE:print (opcode)
94105115.83s5.83sMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:linkMail::SpamAssassin::Locker::UnixNFSSafe::CORE:link (opcode)
188049413.95s3.95sMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:lstatMail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat (opcode)
321711615ms615msMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:openMail::SpamAssassin::Locker::UnixNFSSafe::CORE:open (opcode)
337831572ms572msMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:unlinkMail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink (opcode)
32182159.2ms59.2msMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:closeMail::SpamAssassin::Locker::UnixNFSSafe::CORE:close (opcode)
64342114.4ms14.4msMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:umaskMail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask (opcode)
111903µs2.59msMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@26Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@26
111206µs745µsMail::SpamAssassin::Locker::UnixNFSSafe::::safe_unlockMail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock
111156µs156µsMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:sysopenMail::SpamAssassin::Locker::UnixNFSSafe::CORE:sysopen (opcode)
11154µs66µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@20Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@20
11135µs102µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@23Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@23
11126µs62µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@21Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@21
11126µs132µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@30Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@30
11126µs84µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@27Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@27
11125µs148µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@28Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@28
11124µs31µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@22Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@22
11124µs39µsMail::SpamAssassin::Locker::UnixNFSSafe::::newMail::SpamAssassin::Locker::UnixNFSSafe::new
11124µs206µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@57Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@57
11120µs78µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@33Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@33
11120µs2.04msMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@31Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@31
11114µs14µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@29Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@29
11113µs13µsMail::SpamAssassin::Locker::UnixNFSSafe::::BEGIN@25Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@25
1118µs8µsMail::SpamAssassin::Locker::UnixNFSSafe::::CORE:statMail::SpamAssassin::Locker::UnixNFSSafe::CORE:stat (opcode)
0000s0sMail::SpamAssassin::Locker::UnixNFSSafe::::refresh_lockMail::SpamAssassin::Locker::UnixNFSSafe::refresh_lock
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::Locker::UnixNFSSafe;
19
20266µs278µs
# spent 66µs (54+12) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@20 which was called: # once (54µs+12µs) by Mail::SpamAssassin::BEGIN@2 at line 20
use strict;
# spent 66µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@20 # spent 12µs making 1 call to strict::import
21255µs298µs
# spent 62µs (26+36) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@21 which was called: # once (26µs+36µs) by Mail::SpamAssassin::BEGIN@2 at line 21
use warnings;
# spent 62µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@21 # spent 36µs making 1 call to warnings::import
22259µs238µs
# spent 31µs (24+7) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@22 which was called: # once (24µs+7µs) by Mail::SpamAssassin::BEGIN@2 at line 22
use bytes;
# spent 31µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@22 # spent 7µs making 1 call to bytes::import
23258µs2169µs
# spent 102µs (35+67) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@23 which was called: # once (35µs+67µs) by Mail::SpamAssassin::BEGIN@2 at line 23
use re 'taint';
# spent 102µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@23 # spent 67µs making 1 call to re::import
24
25249µs113µs
# spent 13µs within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@25 which was called: # once (13µs+0s) by Mail::SpamAssassin::BEGIN@2 at line 25
use Mail::SpamAssassin;
262284µs12.59ms
# spent 2.59ms (903µs+1.69) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@26 which was called: # once (903µs+1.69ms) by Mail::SpamAssassin::BEGIN@2 at line 26
use Mail::SpamAssassin::Locker;
27260µs2143µs
# spent 84µs (26+59) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@27 which was called: # once (26µs+59µs) by Mail::SpamAssassin::BEGIN@2 at line 27
use Mail::SpamAssassin::Util;
# spent 84µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@27 # spent 59µs making 1 call to Exporter::import
28257µs2270µs
# spent 148µs (25+122) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@28 which was called: # once (25µs+122µs) by Mail::SpamAssassin::BEGIN@2 at line 28
use Mail::SpamAssassin::Logger;
# spent 148µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@28 # spent 122µs making 1 call to Exporter::import
29249µs114µs
# spent 14µs within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@29 which was called: # once (14µs+0s) by Mail::SpamAssassin::BEGIN@2 at line 29
use File::Spec;
30263µs2238µs
# spent 132µs (26+106) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@30 which was called: # once (26µs+106µs) by Mail::SpamAssassin::BEGIN@2 at line 30
use Time::Local;
# spent 132µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@30 # spent 106µs making 1 call to Exporter::import
31268µs24.06ms
# spent 2.04ms (20µs+2.02) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@31 which was called: # once (20µs+2.02ms) by Mail::SpamAssassin::BEGIN@2 at line 31
use Fcntl qw(:DEFAULT :flock);
# spent 2.04ms making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@31 # spent 2.02ms making 1 call to Exporter::import
32
3312µs
# spent 78µs (20+58) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@33 which was called: # once (20µs+58µs) by Mail::SpamAssassin::BEGIN@2 at line 35
use vars qw{
34 @ISA
351155µs2136µs};
# spent 78µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@33 # spent 58µs making 1 call to vars::import
36
37116µs@ISA = qw(Mail::SpamAssassin::Locker);
38
39###########################################################################
40
41
# spent 39µs (24+14) within Mail::SpamAssassin::Locker::UnixNFSSafe::new which was called: # once (24µs+14µs) by Mail::SpamAssassin::create_locker at line 3 of (eval 33)[Mail/SpamAssassin.pm:475]
sub new {
4212µs my $class = shift;
43110µs114µs my $self = $class->SUPER::new(@_);
# spent 14µs making 1 call to Mail::SpamAssassin::Locker::new
4419µs $self;
45}
46
47###########################################################################
48# NFS-safe locking (I hope!):
49# Attempt to create a file lock, using NFS-safe locking techniques.
50#
51# Locking code adapted from code by Alexis Rosen <alexis@panix.com>
52# by Kelsey Cummings <kgc@sonic.net>, with mods by jm and quinlan
53#
54# A good implementation of Alexis' code, for reference, is here:
55# http://mail-index.netbsd.org/netbsd-bugs/1996/04/17/0002.html
56
5721.94ms2387µs
# spent 206µs (24+182) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@57 which was called: # once (24µs+182µs) by Mail::SpamAssassin::BEGIN@2 at line 57
use constant LOCK_MAX_AGE => 600; # seconds
# spent 206µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@57 # spent 182µs making 1 call to constant::import
58
59
# spent 94559s (14.7+94545) within Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock which was called 3217 times, avg 29.4s/call: # 3216 times (14.7s+94545s) by Mail::SpamAssassin::DBBasedAddrList::new_checker at line 71 of Mail/SpamAssassin/DBBasedAddrList.pm, avg 29.4s/call # once (215µs+720µs) by Mail::SpamAssassin::BayesStore::DBM::tie_db_writable at line 280 of Mail/SpamAssassin/BayesStore/DBM.pm
sub safe_lock {
60321711.2ms my ($self, $path, $max_retries, $mode) = @_;
6132177.43ms my $is_locked = 0;
6232176.91ms my @stat;
63
6432176.63ms $max_retries ||= 30;
6532176.24ms $mode ||= "0700";
66321710.6ms $mode = (oct $mode) & 0666;
67321728.2ms321723.2ms dbg ("locker: mode is $mode");
# spent 23.2ms making 3217 calls to Mail::SpamAssassin::Logger::dbg, avg 7µs/call
68
69321711.6ms my $lock_file = "$path.lock";
70321727.9ms321724.7ms my $hname = Mail::SpamAssassin::Util::fq_hostname();
# spent 24.7ms making 3217 calls to Mail::SpamAssassin::Util::fq_hostname, avg 8µs/call
71321745.0ms3217455ms my $lock_tmp = Mail::SpamAssassin::Util::untaint_file_path
# spent 455ms making 3217 calls to Mail::SpamAssassin::Util::untaint_file_path, avg 142µs/call
72 ($path.".lock.".$hname.".".$$);
73
74 # keep this for unlocking
75321711.0ms $self->{lock_tmp} = $lock_tmp;
76
77321758.8ms32176.52ms my $umask = umask(~$mode);
# spent 6.52ms making 3217 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask, avg 2µs/call
783217674ms3217615ms if (!open(LTMP, ">$lock_tmp")) {
# spent 615ms making 3217 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:open, avg 191µs/call
79 umask $umask; # just in case
80 die "locker: safe_lock: cannot create tmp lockfile $lock_tmp for $lock_file: $!\n";
81 }
82321727.4ms32177.86ms umask $umask;
# spent 7.86ms making 3217 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask, avg 2µs/call
83321745.8ms3217518ms autoflush LTMP 1;
# spent 518ms making 3217 calls to IO::Handle::autoflush, avg 161µs/call
84321726.6ms321729.4ms dbg("locker: safe_lock: created $lock_tmp");
# spent 29.4ms making 3217 calls to Mail::SpamAssassin::Logger::dbg, avg 9µs/call
85
863217495ms for (my $retries = 0; $retries < $max_retries; $retries++) {
871849931.55s9088894524s if ($retries > 0) { $self->jittery_one_second_sleep(); }
# spent 94524s making 90888 calls to Mail::SpamAssassin::Locker::jittery_one_second_sleep, avg 1.04s/call
88941059.25s941056.62s print LTMP "$hname.$$\n" or warn "Error writing to $lock_tmp: $!";
# spent 6.62s making 94105 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:print, avg 70µs/call
89941052.05s941052.04s dbg("locker: safe_lock: trying to get lock on $path with $retries retries");
# spent 2.04s making 94105 calls to Mail::SpamAssassin::Logger::dbg, avg 22µs/call
90941057.01s941055.83s if (link($lock_tmp, $lock_file)) {
# spent 5.83s making 94105 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:link, avg 62µs/call
911621.46ms1621.12ms dbg("locker: safe_lock: link to $lock_file: link ok");
# spent 1.12ms making 162 calls to Mail::SpamAssassin::Logger::dbg, avg 7µs/call
92162389µs $is_locked = 1;
93162769µs last;
94 }
95 # link _may_ return false even if the link _is_ created
96939434.21s939431.79s @stat = lstat($lock_tmp);
# spent 1.79s making 93943 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 19µs/call
9793943199ms @stat or warn "locker: error accessing $lock_tmp: $!";
9893943323ms if (defined $stat[3] && $stat[3] > 1) {
99 dbg("locker: safe_lock: link to $lock_file: stat ok");
100 $is_locked = 1;
101 last;
102 }
103 # check age of lockfile ctime
10493943516ms my $now = ($#stat < 11 ? undef : $stat[10]);
105939433.46s939432.16s @stat = lstat($lock_file);
# spent 2.16s making 93943 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 23µs/call
10693943206ms @stat or warn "locker: error accessing $lock_file: $!";
10793943312ms my $lock_age = ($#stat < 11 ? undef : $stat[10]);
10893943486ms if (defined($lock_age) && defined($now) && ($now - $lock_age) > LOCK_MAX_AGE)
109 {
110 # we got a stale lock, break it
1111602.00ms1601.09ms dbg("locker: safe_lock: breaking stale $lock_file: age=" .
# spent 1.09ms making 160 calls to Mail::SpamAssassin::Logger::dbg, avg 7µs/call
112 (defined $lock_age ? $lock_age : "undef") . " now=$now");
11316027.3ms16025.7ms unlink($lock_file)
# spent 25.7ms making 160 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink, avg 161µs/call
114 or warn "locker: safe_lock: unlink of lock file $lock_file failed: $!\n";
115 }
116 }
117
118321796.1ms321759.2ms close LTMP or die "error closing $lock_tmp: $!";
# spent 59.2ms making 3217 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:close, avg 18µs/call
1193217585ms3217546ms unlink($lock_tmp)
# spent 546ms making 3217 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink, avg 170µs/call
120 or warn "locker: safe_lock: unlink of temp lock $lock_tmp failed: $!\n";
121
122 # record this for safe unlocking
12332176.78ms if ($is_locked) {
1241627.83ms1624.61ms @stat = lstat($lock_file);
# spent 4.61ms making 162 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 28µs/call
125162346µs @stat or warn "locker: error accessing $lock_file: $!";
126162879µs my $lock_ctime = ($#stat < 11 ? undef : $stat[10]);
127
128162817µs $self->{lock_ctimes} ||= { };
129162661µs $self->{lock_ctimes}->{$path} = $lock_ctime;
130 }
131
132321764.8ms return $is_locked;
133}
134
135###########################################################################
136
137
# spent 745µs (206+539) within Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock which was called: # once (206µs+539µs) by Mail::SpamAssassin::BayesStore::DBM::untie_db at line 627 of Mail/SpamAssassin/BayesStore/DBM.pm
sub safe_unlock {
13813µs my ($self, $path) = @_;
139
14015µs my $lock_file = "$path.lock";
14114µs my $lock_tmp = $self->{lock_tmp};
14212µs if (!$lock_tmp) {
143 dbg("locker: safe_unlock: $path.lock never locked");
144 return;
145 }
146
147 # 1. Build a temp file and stat that to get an idea of what the server
148 # thinks the current time is (our_tmp.st_ctime). note: do not use time()
149 # directly because the server's clock may be out of sync with the client's.
150
15112µs my @stat_ourtmp;
1521176µs1156µs if (!defined sysopen(LTMP, $lock_tmp, O_CREAT|O_WRONLY|O_EXCL, 0700)) {
153 warn "locker: safe_unlock: failed to create lock tmpfile $lock_tmp: $!";
154 return;
155 } else {
156115µs1140µs autoflush LTMP 1;
# spent 140µs making 1 call to IO::Handle::autoflush
157168µs157µs print LTMP "\n" or warn "Error writing to $lock_tmp: $!";
158
159126µs18µs if (!(@stat_ourtmp = stat(LTMP)) || (scalar(@stat_ourtmp) < 11)) {
160 @stat_ourtmp or warn "locker: error accessing $lock_tmp: $!";
161 warn "locker: safe_unlock: failed to create lock tmpfile $lock_tmp";
162 close LTMP or die "error closing $lock_tmp: $!";
163 unlink($lock_tmp)
164 or warn "locker: safe_lock: unlink of lock file failed: $!\n";
165 return;
166 }
167 }
168
16912µs my $ourtmp_ctime = $stat_ourtmp[10]; # paranoia
17013µs if (!defined $ourtmp_ctime) {
171 die "locker: safe_unlock: stat failed on $lock_tmp";
172 }
173
174119µs19µs close LTMP or die "error closing $lock_tmp: $!";
1751136µs1124µs unlink($lock_tmp)
176 or warn "locker: safe_lock: unlink of lock file failed: $!\n";
177
178 # 2. If the ctime hasn't been modified, unlink the file and return. If the
179 # lock has expired, sleep the usual random interval before returning. If we
180 # didn't sleep, there could be a race if the caller immediately tries to
181 # relock the file.
182
18314µs my $lock_ctime = $self->{lock_ctimes}->{$path};
18412µs if (!defined $lock_ctime) {
185 warn "locker: safe_unlock: no ctime recorded for $lock_file";
186 return;
187 }
188
189158µs145µs my @stat_lock = lstat($lock_file);
190151µs @stat_lock or warn "locker: error accessing $lock_file: $!";
191
19212µs my $now_ctime = $stat_lock[10];
193
19412µs if (defined $now_ctime && $now_ctime == $lock_ctime)
195 {
196 # things are good: the ctimes match so it was our lock
197 unlink($lock_file)
198 or warn "locker: safe_unlock: unlink failed: $lock_file\n";
199 dbg("locker: safe_unlock: unlink $lock_file");
200
201 if ($ourtmp_ctime >= $lock_ctime + LOCK_MAX_AGE) {
202 # the lock has expired, so sleep a bit; use some randomness
203 # to avoid race conditions.
204 dbg("locker: safe_unlock: lock expired on $lock_file expired safely; sleeping");
205 my $i; for ($i = 0; $i < 5; $i++) {
206 $self->jittery_one_second_sleep();
207 }
208 }
209 return;
210 }
211
212 # 4. Either ctime has been modified, or the entire lock file is missing.
213 # If the lock should still be ours, based on the ctime of the temp
214 # file, warn it was stolen. If not, then our lock is expired and
215 # someone else has grabbed the file, so warn it was lost.
216118µs if ($ourtmp_ctime < $lock_ctime + LOCK_MAX_AGE) {
217 warn "locker: safe_unlock: lock on $lock_file was stolen";
218 } else {
21919µs warn "locker: safe_unlock: lock on $lock_file was lost due to expiry";
220 }
221}
222
223###########################################################################
224
225sub refresh_lock {
226 my($self, $path) = @_;
227
228 return unless $path;
229
230 # this could arguably read the lock and make sure the same process
231 # owns it, but this shouldn't, in theory, be an issue.
232 # TODO: in NFS, it definitely may be one :(
233
234 my $lock_file = "$path.lock";
235 utime time, time, $lock_file;
236
237 # update the lock_ctimes entry
238 my @stat = lstat($lock_file);
239 @stat or warn "locker: error accessing $lock_file: $!";
240
241 my $lock_ctime = ($#stat < 11 ? undef : $stat[10]);
242 $self->{lock_ctimes}->{$path} = $lock_ctime;
243
244 dbg("locker: refresh_lock: refresh $path.lock");
245}
246
247###########################################################################
248
24918µs1;
 
# spent 59.2ms within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:close which was called 3218 times, avg 18µs/call: # 3217 times (59.2ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 118, avg 18µs/call # once (9µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 174
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:close; # opcode
# spent 5.83s within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:link which was called 94105 times, avg 62µs/call: # 94105 times (5.83s+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 90, avg 62µs/call
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:link; # opcode
# spent 3.95s within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat which was called 188049 times, avg 21µs/call: # 93943 times (2.16s+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 105, avg 23µs/call # 93943 times (1.79s+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 96, avg 19µs/call # 162 times (4.61ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 124, avg 28µs/call # once (45µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 189
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat; # opcode
# spent 615ms within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:open which was called 3217 times, avg 191µs/call: # 3217 times (615ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 78, avg 191µs/call
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:open; # opcode
# spent 6.62s within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:print which was called 94106 times, avg 70µs/call: # 94105 times (6.62s+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 88, avg 70µs/call # once (57µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 157
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:print; # opcode
# spent 8µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:stat which was called: # once (8µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 159
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:stat; # opcode
# spent 156µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:sysopen which was called: # once (156µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 152
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:sysopen; # opcode
# spent 14.4ms within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask which was called 6434 times, avg 2µs/call: # 3217 times (7.86ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 82, avg 2µs/call # 3217 times (6.52ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 77, avg 2µs/call
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask; # opcode
# spent 572ms within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink which was called 3378 times, avg 169µs/call: # 3217 times (546ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 119, avg 170µs/call # 160 times (25.7ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 113, avg 161µs/call # once (124µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 175
sub Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink; # opcode