Filename | /usr/local/lib/perl5/site_perl/Mail/SpamAssassin/Locker/UnixNFSSafe.pm |
Statements | Executed 1288077 statements in 31.9s |
Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
---|---|---|---|---|---|
3217 | 2 | 2 | 14.7s | 94559s | safe_lock | Mail::SpamAssassin::Locker::UnixNFSSafe::
94106 | 2 | 1 | 6.62s | 6.62s | CORE:print (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
94105 | 1 | 1 | 5.83s | 5.83s | CORE:link (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
188049 | 4 | 1 | 3.95s | 3.95s | CORE:lstat (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
3217 | 1 | 1 | 615ms | 615ms | CORE:open (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
3378 | 3 | 1 | 572ms | 572ms | CORE:unlink (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
3218 | 2 | 1 | 59.2ms | 59.2ms | CORE:close (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
6434 | 2 | 1 | 14.4ms | 14.4ms | CORE:umask (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 903µs | 2.59ms | BEGIN@26 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 206µs | 745µs | safe_unlock | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 156µs | 156µs | CORE:sysopen (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 54µs | 66µs | BEGIN@20 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 35µs | 102µs | BEGIN@23 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 26µs | 62µs | BEGIN@21 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 26µs | 132µs | BEGIN@30 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 26µs | 84µs | BEGIN@27 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 25µs | 148µs | BEGIN@28 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 24µs | 31µs | BEGIN@22 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 24µs | 39µs | new | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 24µs | 206µs | BEGIN@57 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 20µs | 78µs | BEGIN@33 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 20µs | 2.04ms | BEGIN@31 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 14µs | 14µs | BEGIN@29 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 13µs | 13µs | BEGIN@25 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 8µs | 8µs | CORE:stat (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
0 | 0 | 0 | 0s | 0s | refresh_lock | Mail::SpamAssassin::Locker::UnixNFSSafe::
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 | package Mail::SpamAssassin::Locker::UnixNFSSafe; | ||||
19 | |||||
20 | 2 | 66µs | 2 | 78µ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 # spent 66µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@20
# spent 12µs making 1 call to strict::import |
21 | 2 | 55µs | 2 | 98µ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 # spent 62µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@21
# spent 36µs making 1 call to warnings::import |
22 | 2 | 59µs | 2 | 38µ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 # spent 31µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@22
# spent 7µs making 1 call to bytes::import |
23 | 2 | 58µs | 2 | 169µ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 # spent 102µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@23
# spent 67µs making 1 call to re::import |
24 | |||||
25 | 2 | 49µs | 1 | 13µ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 # spent 13µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@25 |
26 | 2 | 284µs | 1 | 2.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 # spent 2.59ms making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@26 |
27 | 2 | 60µs | 2 | 143µ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 # spent 84µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@27
# spent 59µs making 1 call to Exporter::import |
28 | 2 | 57µs | 2 | 270µ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 # spent 148µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@28
# spent 122µs making 1 call to Exporter::import |
29 | 2 | 49µs | 1 | 14µ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 # spent 14µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@29 |
30 | 2 | 63µs | 2 | 238µ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 # spent 132µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@30
# spent 106µs making 1 call to Exporter::import |
31 | 2 | 68µs | 2 | 4.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 # spent 2.04ms making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@31
# spent 2.02ms making 1 call to Exporter::import |
32 | |||||
33 | 1 | 2µ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 | ||
34 | @ISA | ||||
35 | 1 | 155µs | 2 | 136µs | }; # spent 78µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@33
# spent 58µs making 1 call to vars::import |
36 | |||||
37 | 1 | 16µ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] | ||||
42 | 1 | 2µs | my $class = shift; | ||
43 | 1 | 10µs | 1 | 14µs | my $self = $class->SUPER::new(@_); # spent 14µs making 1 call to Mail::SpamAssassin::Locker::new |
44 | 1 | 9µ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 | |||||
57 | 2 | 1.94ms | 2 | 387µ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 # 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 | ||||
60 | 3217 | 11.2ms | my ($self, $path, $max_retries, $mode) = @_; | ||
61 | 3217 | 7.43ms | my $is_locked = 0; | ||
62 | 3217 | 6.91ms | my @stat; | ||
63 | |||||
64 | 3217 | 6.63ms | $max_retries ||= 30; | ||
65 | 3217 | 6.24ms | $mode ||= "0700"; | ||
66 | 3217 | 10.6ms | $mode = (oct $mode) & 0666; | ||
67 | 3217 | 28.2ms | 3217 | 23.2ms | dbg ("locker: mode is $mode"); # spent 23.2ms making 3217 calls to Mail::SpamAssassin::Logger::dbg, avg 7µs/call |
68 | |||||
69 | 3217 | 11.6ms | my $lock_file = "$path.lock"; | ||
70 | 3217 | 27.9ms | 3217 | 24.7ms | my $hname = Mail::SpamAssassin::Util::fq_hostname(); # spent 24.7ms making 3217 calls to Mail::SpamAssassin::Util::fq_hostname, avg 8µs/call |
71 | 3217 | 45.0ms | 3217 | 455ms | 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 | ||||
75 | 3217 | 11.0ms | $self->{lock_tmp} = $lock_tmp; | ||
76 | |||||
77 | 3217 | 58.8ms | 3217 | 6.52ms | my $umask = umask(~$mode); # spent 6.52ms making 3217 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask, avg 2µs/call |
78 | 3217 | 674ms | 3217 | 615ms | 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 | } | ||||
82 | 3217 | 27.4ms | 3217 | 7.86ms | umask $umask; # spent 7.86ms making 3217 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask, avg 2µs/call |
83 | 3217 | 45.8ms | 3217 | 518ms | autoflush LTMP 1; # spent 518ms making 3217 calls to IO::Handle::autoflush, avg 161µs/call |
84 | 3217 | 26.6ms | 3217 | 29.4ms | dbg("locker: safe_lock: created $lock_tmp"); # spent 29.4ms making 3217 calls to Mail::SpamAssassin::Logger::dbg, avg 9µs/call |
85 | |||||
86 | 3217 | 495ms | for (my $retries = 0; $retries < $max_retries; $retries++) { | ||
87 | 184993 | 1.55s | 90888 | 94524s | 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 |
88 | 94105 | 9.25s | 94105 | 6.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 |
89 | 94105 | 2.05s | 94105 | 2.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 |
90 | 94105 | 7.01s | 94105 | 5.83s | if (link($lock_tmp, $lock_file)) { # spent 5.83s making 94105 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:link, avg 62µs/call |
91 | 162 | 1.46ms | 162 | 1.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 |
92 | 162 | 389µs | $is_locked = 1; | ||
93 | 162 | 769µs | last; | ||
94 | } | ||||
95 | # link _may_ return false even if the link _is_ created | ||||
96 | 93943 | 4.21s | 93943 | 1.79s | @stat = lstat($lock_tmp); # spent 1.79s making 93943 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 19µs/call |
97 | 93943 | 199ms | @stat or warn "locker: error accessing $lock_tmp: $!"; | ||
98 | 93943 | 323ms | 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 | ||||
104 | 93943 | 516ms | my $now = ($#stat < 11 ? undef : $stat[10]); | ||
105 | 93943 | 3.46s | 93943 | 2.16s | @stat = lstat($lock_file); # spent 2.16s making 93943 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 23µs/call |
106 | 93943 | 206ms | @stat or warn "locker: error accessing $lock_file: $!"; | ||
107 | 93943 | 312ms | my $lock_age = ($#stat < 11 ? undef : $stat[10]); | ||
108 | 93943 | 486ms | if (defined($lock_age) && defined($now) && ($now - $lock_age) > LOCK_MAX_AGE) | ||
109 | { | ||||
110 | # we got a stale lock, break it | ||||
111 | 160 | 2.00ms | 160 | 1.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"); | ||||
113 | 160 | 27.3ms | 160 | 25.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 | |||||
118 | 3217 | 96.1ms | 3217 | 59.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 |
119 | 3217 | 585ms | 3217 | 546ms | 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 | ||||
123 | 3217 | 6.78ms | if ($is_locked) { | ||
124 | 162 | 7.83ms | 162 | 4.61ms | @stat = lstat($lock_file); # spent 4.61ms making 162 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 28µs/call |
125 | 162 | 346µs | @stat or warn "locker: error accessing $lock_file: $!"; | ||
126 | 162 | 879µs | my $lock_ctime = ($#stat < 11 ? undef : $stat[10]); | ||
127 | |||||
128 | 162 | 817µs | $self->{lock_ctimes} ||= { }; | ||
129 | 162 | 661µs | $self->{lock_ctimes}->{$path} = $lock_ctime; | ||
130 | } | ||||
131 | |||||
132 | 3217 | 64.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 | ||||
138 | 1 | 3µs | my ($self, $path) = @_; | ||
139 | |||||
140 | 1 | 5µs | my $lock_file = "$path.lock"; | ||
141 | 1 | 4µs | my $lock_tmp = $self->{lock_tmp}; | ||
142 | 1 | 2µ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 | |||||
151 | 1 | 2µs | my @stat_ourtmp; | ||
152 | 1 | 176µs | 1 | 156µs | if (!defined sysopen(LTMP, $lock_tmp, O_CREAT|O_WRONLY|O_EXCL, 0700)) { # spent 156µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:sysopen |
153 | warn "locker: safe_unlock: failed to create lock tmpfile $lock_tmp: $!"; | ||||
154 | return; | ||||
155 | } else { | ||||
156 | 1 | 15µs | 1 | 140µs | autoflush LTMP 1; # spent 140µs making 1 call to IO::Handle::autoflush |
157 | 1 | 68µs | 1 | 57µs | print LTMP "\n" or warn "Error writing to $lock_tmp: $!"; # spent 57µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:print |
158 | |||||
159 | 1 | 26µs | 1 | 8µs | if (!(@stat_ourtmp = stat(LTMP)) || (scalar(@stat_ourtmp) < 11)) { # spent 8µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:stat |
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 | |||||
169 | 1 | 2µs | my $ourtmp_ctime = $stat_ourtmp[10]; # paranoia | ||
170 | 1 | 3µs | if (!defined $ourtmp_ctime) { | ||
171 | die "locker: safe_unlock: stat failed on $lock_tmp"; | ||||
172 | } | ||||
173 | |||||
174 | 1 | 19µs | 1 | 9µs | close LTMP or die "error closing $lock_tmp: $!"; # spent 9µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:close |
175 | 1 | 136µs | 1 | 124µs | unlink($lock_tmp) # spent 124µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink |
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 | |||||
183 | 1 | 4µs | my $lock_ctime = $self->{lock_ctimes}->{$path}; | ||
184 | 1 | 2µs | if (!defined $lock_ctime) { | ||
185 | warn "locker: safe_unlock: no ctime recorded for $lock_file"; | ||||
186 | return; | ||||
187 | } | ||||
188 | |||||
189 | 1 | 58µs | 1 | 45µs | my @stat_lock = lstat($lock_file); # spent 45µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat |
190 | 1 | 51µs | @stat_lock or warn "locker: error accessing $lock_file: $!"; | ||
191 | |||||
192 | 1 | 2µs | my $now_ctime = $stat_lock[10]; | ||
193 | |||||
194 | 1 | 2µ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. | ||||
216 | 1 | 18µs | if ($ourtmp_ctime < $lock_ctime + LOCK_MAX_AGE) { | ||
217 | warn "locker: safe_unlock: lock on $lock_file was stolen"; | ||||
218 | } else { | ||||
219 | 1 | 9µs | warn "locker: safe_unlock: lock on $lock_file was lost due to expiry"; | ||
220 | } | ||||
221 | } | ||||
222 | |||||
223 | ########################################################################### | ||||
224 | |||||
225 | sub 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 | |||||
249 | 1 | 8µs | 1; | ||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 | |||||
# 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 |