Filename | /usr/local/lib/perl5/site_perl/Mail/SpamAssassin/Locker/UnixNFSSafe.pm |
Statements | Executed 244 statements in 12.3ms |
Calls | P | F | Exclusive Time |
Inclusive Time |
Subroutine |
---|---|---|---|---|---|
6 | 1 | 1 | 2.39ms | 2.39ms | CORE:link (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
3 | 2 | 2 | 2.20ms | 3.34s | safe_lock | Mail::SpamAssassin::Locker::UnixNFSSafe::
8 | 4 | 1 | 1.01ms | 1.01ms | CORE:unlink (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 983µs | 3.81ms | BEGIN@26 | Mail::SpamAssassin::Locker::UnixNFSSafe::
3 | 2 | 2 | 868µs | 5.47s | safe_unlock | Mail::SpamAssassin::Locker::UnixNFSSafe::
3 | 1 | 1 | 761µs | 761µs | CORE:sysopen (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
9 | 2 | 1 | 670µs | 670µs | CORE:print (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
3 | 1 | 1 | 585µs | 585µs | CORE:open (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
12 | 4 | 1 | 331µs | 331µs | CORE:lstat (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
6 | 2 | 1 | 102µs | 102µs | CORE:close (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 64µs | 74µs | BEGIN@20 | Mail::SpamAssassin::Locker::UnixNFSSafe::
3 | 1 | 1 | 47µs | 47µs | CORE:stat (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 37µs | 102µs | BEGIN@23 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 36µs | 59µs | new | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 35µs | 112µs | BEGIN@27 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 32µs | 62µs | BEGIN@21 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 31µs | 3.06ms | BEGIN@31 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 29µs | 108µs | BEGIN@33 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 29µs | 238µs | BEGIN@28 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 26µs | 39µs | BEGIN@22 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 26µs | 207µs | BEGIN@57 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 26µs | 196µs | BEGIN@30 | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 17µs | 17µs | BEGIN@25 | Mail::SpamAssassin::Locker::UnixNFSSafe::
6 | 2 | 1 | 17µs | 17µs | CORE:umask (opcode) | Mail::SpamAssassin::Locker::UnixNFSSafe::
1 | 1 | 1 | 14µs | 14µs | BEGIN@29 | 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 | 73µs | 2 | 85µs | # spent 74µs (64+11) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@20 which was called:
# once (64µs+11µs) by Mail::SpamAssassin::BEGIN@2 at line 20 # spent 74µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@20
# spent 11µs making 1 call to strict::import |
21 | 2 | 69µs | 2 | 92µs | # spent 62µs (32+30) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@21 which was called:
# once (32µs+30µs) by Mail::SpamAssassin::BEGIN@2 at line 21 # spent 62µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@21
# spent 30µs making 1 call to warnings::import |
22 | 2 | 72µs | 2 | 52µs | # spent 39µs (26+12) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@22 which was called:
# once (26µs+12µs) by Mail::SpamAssassin::BEGIN@2 at line 22 # spent 39µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@22
# spent 12µs making 1 call to bytes::import |
23 | 2 | 66µs | 2 | 166µs | # spent 102µs (37+64) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@23 which was called:
# once (37µs+64µs) by Mail::SpamAssassin::BEGIN@2 at line 23 # spent 102µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@23
# spent 64µs making 1 call to re::import |
24 | |||||
25 | 2 | 51µs | 1 | 17µs | # spent 17µs within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@25 which was called:
# once (17µs+0s) by Mail::SpamAssassin::BEGIN@2 at line 25 # spent 17µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@25 |
26 | 2 | 278µs | 1 | 3.81ms | # spent 3.81ms (983µs+2.83) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@26 which was called:
# once (983µs+2.83ms) by Mail::SpamAssassin::BEGIN@2 at line 26 # spent 3.81ms making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@26 |
27 | 2 | 73µs | 2 | 189µs | # spent 112µs (35+77) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@27 which was called:
# once (35µs+77µs) by Mail::SpamAssassin::BEGIN@2 at line 27 # spent 112µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@27
# spent 77µs making 1 call to Exporter::import |
28 | 2 | 67µs | 2 | 447µs | # spent 238µs (29+209) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@28 which was called:
# once (29µs+209µs) by Mail::SpamAssassin::BEGIN@2 at line 28 # spent 238µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@28
# spent 209µs making 1 call to Exporter::import |
29 | 2 | 58µ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 | 80µs | 2 | 367µs | # spent 196µs (26+170) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@30 which was called:
# once (26µs+170µs) by Mail::SpamAssassin::BEGIN@2 at line 30 # spent 196µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@30
# spent 170µs making 1 call to Exporter::import |
31 | 2 | 92µs | 2 | 6.10ms | # spent 3.06ms (31µs+3.03) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@31 which was called:
# once (31µs+3.03ms) by Mail::SpamAssassin::BEGIN@2 at line 31 # spent 3.06ms making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@31
# spent 3.03ms making 1 call to Exporter::import |
32 | |||||
33 | 1 | 2µs | # spent 108µs (29+79) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@33 which was called:
# once (29µs+79µs) by Mail::SpamAssassin::BEGIN@2 at line 35 | ||
34 | @ISA | ||||
35 | 1 | 167µs | 2 | 187µs | }; # spent 108µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@33
# spent 79µs making 1 call to vars::import |
36 | |||||
37 | 1 | 16µs | @ISA = qw(Mail::SpamAssassin::Locker); | ||
38 | |||||
39 | ########################################################################### | ||||
40 | |||||
41 | # spent 59µs (36+23) within Mail::SpamAssassin::Locker::UnixNFSSafe::new which was called:
# once (36µs+23µ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 | 15µs | 1 | 23µs | my $self = $class->SUPER::new(@_); # spent 23µs making 1 call to Mail::SpamAssassin::Locker::new |
44 | 1 | 15µ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 | 2.25ms | 2 | 387µs | # spent 207µs (26+180) within Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@57 which was called:
# once (26µs+180µs) by Mail::SpamAssassin::BEGIN@2 at line 57 # spent 207µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::BEGIN@57
# spent 180µs making 1 call to constant::import |
58 | |||||
59 | # spent 3.34s (2.20ms+3.34) within Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock which was called 3 times, avg 1.11s/call:
# 2 times (1.71ms+2.63s) by Mail::SpamAssassin::BayesStore::DBM::tie_db_writable at line 280 of Mail/SpamAssassin/BayesStore/DBM.pm, avg 1.32s/call
# once (489µs+705ms) by Mail::SpamAssassin::DBBasedAddrList::new_checker at line 71 of Mail/SpamAssassin/DBBasedAddrList.pm | ||||
60 | 3 | 12µs | my ($self, $path, $max_retries, $mode) = @_; | ||
61 | 3 | 7µs | my $is_locked = 0; | ||
62 | 3 | 7µs | my @stat; | ||
63 | |||||
64 | 3 | 6µs | $max_retries ||= 30; | ||
65 | 3 | 6µs | $mode ||= "0700"; | ||
66 | 3 | 13µs | $mode = (oct $mode) & 0666; | ||
67 | 3 | 32µs | 3 | 36µs | dbg ("locker: mode is $mode"); # spent 36µs making 3 calls to Mail::SpamAssassin::Logger::dbg, avg 12µs/call |
68 | |||||
69 | 3 | 11µs | my $lock_file = "$path.lock"; | ||
70 | 3 | 29µs | 3 | 368µs | my $hname = Mail::SpamAssassin::Util::fq_hostname(); # spent 368µs making 3 calls to Mail::SpamAssassin::Util::fq_hostname, avg 123µs/call |
71 | 3 | 47µs | 3 | 396µs | my $lock_tmp = Mail::SpamAssassin::Util::untaint_file_path # spent 396µs making 3 calls to Mail::SpamAssassin::Util::untaint_file_path, avg 132µs/call |
72 | ($path.".lock.".$hname.".".$$); | ||||
73 | |||||
74 | # keep this for unlocking | ||||
75 | 3 | 22µs | $self->{lock_tmp} = $lock_tmp; | ||
76 | |||||
77 | 3 | 46µs | 3 | 10µs | my $umask = umask(~$mode); # spent 10µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask, avg 3µs/call |
78 | 3 | 624µs | 3 | 585µs | if (!open(LTMP, ">$lock_tmp")) { # spent 585µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:open, avg 195µ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 | 3 | 28µs | 3 | 7µs | umask $umask; # spent 7µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask, avg 2µs/call |
83 | 3 | 52µs | 3 | 417µs | autoflush LTMP 1; # spent 417µs making 3 calls to IO::Handle::autoflush, avg 139µs/call |
84 | 3 | 30µs | 3 | 26µs | dbg("locker: safe_lock: created $lock_tmp"); # spent 26µs making 3 calls to Mail::SpamAssassin::Logger::dbg, avg 9µs/call |
85 | |||||
86 | 3 | 36µs | for (my $retries = 0; $retries < $max_retries; $retries++) { | ||
87 | 9 | 76µs | 3 | 3.33s | if ($retries > 0) { $self->jittery_one_second_sleep(); } # spent 3.33s making 3 calls to Mail::SpamAssassin::Locker::jittery_one_second_sleep, avg 1.11s/call |
88 | 6 | 1.31ms | 6 | 427µs | print LTMP "$hname.$$\n" or warn "Error writing to $lock_tmp: $!"; # spent 427µs making 6 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:print, avg 71µs/call |
89 | 6 | 123µs | 6 | 99µs | dbg("locker: safe_lock: trying to get lock on $path with $retries retries"); # spent 99µs making 6 calls to Mail::SpamAssassin::Logger::dbg, avg 16µs/call |
90 | 6 | 2.46ms | 6 | 2.39ms | if (link($lock_tmp, $lock_file)) { # spent 2.39ms making 6 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:link, avg 399µs/call |
91 | 3 | 27µs | 3 | 19µs | dbg("locker: safe_lock: link to $lock_file: link ok"); # spent 19µs making 3 calls to Mail::SpamAssassin::Logger::dbg, avg 6µs/call |
92 | 3 | 7µs | $is_locked = 1; | ||
93 | 3 | 13µs | last; | ||
94 | } | ||||
95 | # link _may_ return false even if the link _is_ created | ||||
96 | 3 | 123µs | 3 | 68µs | @stat = lstat($lock_tmp); # spent 68µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 23µs/call |
97 | 3 | 7µs | @stat or warn "locker: error accessing $lock_tmp: $!"; | ||
98 | 3 | 9µs | 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 | 3 | 13µs | my $now = ($#stat < 11 ? undef : $stat[10]); | ||
105 | 3 | 170µs | 3 | 94µs | @stat = lstat($lock_file); # spent 94µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 31µs/call |
106 | 3 | 8µs | @stat or warn "locker: error accessing $lock_file: $!"; | ||
107 | 3 | 14µs | my $lock_age = ($#stat < 11 ? undef : $stat[10]); | ||
108 | 3 | 20µs | if (defined($lock_age) && defined($now) && ($now - $lock_age) > LOCK_MAX_AGE) | ||
109 | { | ||||
110 | # we got a stale lock, break it | ||||
111 | 1 | 14µs | 1 | 6µs | dbg("locker: safe_lock: breaking stale $lock_file: age=" . # spent 6µs making 1 call to Mail::SpamAssassin::Logger::dbg |
112 | (defined $lock_age ? $lock_age : "undef") . " now=$now"); | ||||
113 | 1 | 179µs | 1 | 166µs | unlink($lock_file) # spent 166µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink |
114 | or warn "locker: safe_lock: unlink of lock file $lock_file failed: $!\n"; | ||||
115 | } | ||||
116 | } | ||||
117 | |||||
118 | 3 | 86µs | 3 | 52µs | close LTMP or die "error closing $lock_tmp: $!"; # spent 52µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:close, avg 17µs/call |
119 | 3 | 224µs | 3 | 197µs | unlink($lock_tmp) # spent 197µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink, avg 66µs/call |
120 | or warn "locker: safe_lock: unlink of temp lock $lock_tmp failed: $!\n"; | ||||
121 | |||||
122 | # record this for safe unlocking | ||||
123 | 3 | 12µs | if ($is_locked) { | ||
124 | 3 | 124µs | 3 | 78µs | @stat = lstat($lock_file); # spent 78µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 26µs/call |
125 | 3 | 7µs | @stat or warn "locker: error accessing $lock_file: $!"; | ||
126 | 3 | 13µs | my $lock_ctime = ($#stat < 11 ? undef : $stat[10]); | ||
127 | |||||
128 | 3 | 13µs | $self->{lock_ctimes} ||= { }; | ||
129 | 3 | 14µs | $self->{lock_ctimes}->{$path} = $lock_ctime; | ||
130 | } | ||||
131 | |||||
132 | 3 | 50µs | return $is_locked; | ||
133 | } | ||||
134 | |||||
135 | ########################################################################### | ||||
136 | |||||
137 | # spent 5.47s (868µs+5.47) within Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock which was called 3 times, avg 1.82s/call:
# 2 times (524µs+1.62ms) by Mail::SpamAssassin::BayesStore::DBM::untie_db at line 627 of Mail/SpamAssassin/BayesStore/DBM.pm, avg 1.07ms/call
# once (344µs+5.47s) by Mail::SpamAssassin::DBBasedAddrList::finish at line 113 of Mail/SpamAssassin/DBBasedAddrList.pm | ||||
138 | 3 | 10µs | my ($self, $path) = @_; | ||
139 | |||||
140 | 3 | 16µs | my $lock_file = "$path.lock"; | ||
141 | 3 | 14µs | my $lock_tmp = $self->{lock_tmp}; | ||
142 | 3 | 7µ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 | 3 | 8µs | my @stat_ourtmp; | ||
152 | 3 | 847µs | 3 | 761µs | if (!defined sysopen(LTMP, $lock_tmp, O_CREAT|O_WRONLY|O_EXCL, 0700)) { # spent 761µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:sysopen, avg 254µs/call |
153 | warn "locker: safe_unlock: failed to create lock tmpfile $lock_tmp: $!"; | ||||
154 | return; | ||||
155 | } else { | ||||
156 | 3 | 65µs | 3 | 582µs | autoflush LTMP 1; # spent 582µs making 3 calls to IO::Handle::autoflush, avg 194µs/call |
157 | 3 | 278µs | 3 | 243µs | print LTMP "\n" or warn "Error writing to $lock_tmp: $!"; # spent 243µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:print, avg 81µs/call |
158 | |||||
159 | 3 | 146µs | 3 | 47µs | if (!(@stat_ourtmp = stat(LTMP)) || (scalar(@stat_ourtmp) < 11)) { # spent 47µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:stat, avg 16µs/call |
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 | 3 | 7µs | my $ourtmp_ctime = $stat_ourtmp[10]; # paranoia | ||
170 | 3 | 7µs | if (!defined $ourtmp_ctime) { | ||
171 | die "locker: safe_unlock: stat failed on $lock_tmp"; | ||||
172 | } | ||||
173 | |||||
174 | 3 | 80µs | 3 | 49µs | close LTMP or die "error closing $lock_tmp: $!"; # spent 49µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:close, avg 16µs/call |
175 | 3 | 569µs | 3 | 526µs | unlink($lock_tmp) # spent 526µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink, avg 175µs/call |
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 | 3 | 17µs | my $lock_ctime = $self->{lock_ctimes}->{$path}; | ||
184 | 3 | 7µs | if (!defined $lock_ctime) { | ||
185 | warn "locker: safe_unlock: no ctime recorded for $lock_file"; | ||||
186 | return; | ||||
187 | } | ||||
188 | |||||
189 | 3 | 137µs | 3 | 91µs | my @stat_lock = lstat($lock_file); # spent 91µs making 3 calls to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat, avg 30µs/call |
190 | 3 | 55µs | @stat_lock or warn "locker: error accessing $lock_file: $!"; | ||
191 | |||||
192 | 3 | 7µs | my $now_ctime = $stat_lock[10]; | ||
193 | |||||
194 | 3 | 8µs | if (defined $now_ctime && $now_ctime == $lock_ctime) | ||
195 | { | ||||
196 | # things are good: the ctimes match so it was our lock | ||||
197 | 1 | 130µs | 1 | 118µs | unlink($lock_file) # spent 118µs making 1 call to Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink |
198 | or warn "locker: safe_unlock: unlink failed: $lock_file\n"; | ||||
199 | 1 | 10µs | 1 | 8µs | dbg("locker: safe_unlock: unlink $lock_file"); # spent 8µs making 1 call to Mail::SpamAssassin::Logger::dbg |
200 | |||||
201 | 1 | 6µs | 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 | 1 | 12µs | 1 | 6µs | dbg("locker: safe_unlock: lock expired on $lock_file expired safely; sleeping"); # spent 6µs making 1 call to Mail::SpamAssassin::Logger::dbg |
205 | 2 | 36µs | my $i; for ($i = 0; $i < 5; $i++) { | ||
206 | 5 | 69µs | 5 | 5.47s | $self->jittery_one_second_sleep(); # spent 5.47s making 5 calls to Mail::SpamAssassin::Locker::jittery_one_second_sleep, avg 1.09s/call |
207 | } | ||||
208 | } | ||||
209 | 1 | 46µs | 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 | 2 | 42µs | if ($ourtmp_ctime < $lock_ctime + LOCK_MAX_AGE) { | ||
217 | warn "locker: safe_unlock: lock on $lock_file was stolen"; | ||||
218 | } else { | ||||
219 | 2 | 56µ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 | 13µs | 1; | ||
# spent 102µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:close which was called 6 times, avg 17µs/call:
# 3 times (52µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 118, avg 17µs/call
# 3 times (49µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 174, avg 16µs/call | |||||
# spent 2.39ms within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:link which was called 6 times, avg 399µs/call:
# 6 times (2.39ms+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 90, avg 399µs/call | |||||
# spent 331µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:lstat which was called 12 times, avg 28µs/call:
# 3 times (94µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 105, avg 31µs/call
# 3 times (91µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 189, avg 30µs/call
# 3 times (78µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 124, avg 26µs/call
# 3 times (68µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 96, avg 23µs/call | |||||
# spent 585µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:open which was called 3 times, avg 195µs/call:
# 3 times (585µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 78, avg 195µs/call | |||||
# spent 670µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:print which was called 9 times, avg 74µs/call:
# 6 times (427µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 88, avg 71µs/call
# 3 times (243µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 157, avg 81µs/call | |||||
# spent 47µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:stat which was called 3 times, avg 16µs/call:
# 3 times (47µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 159, avg 16µs/call | |||||
# spent 761µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:sysopen which was called 3 times, avg 254µs/call:
# 3 times (761µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 152, avg 254µs/call | |||||
# spent 17µs within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:umask which was called 6 times, avg 3µs/call:
# 3 times (10µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 77, avg 3µs/call
# 3 times (7µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 82, avg 2µs/call | |||||
# spent 1.01ms within Mail::SpamAssassin::Locker::UnixNFSSafe::CORE:unlink which was called 8 times, avg 126µs/call:
# 3 times (526µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 175, avg 175µs/call
# 3 times (197µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 119, avg 66µs/call
# once (166µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_lock at line 113
# once (118µs+0s) by Mail::SpamAssassin::Locker::UnixNFSSafe::safe_unlock at line 197 |