line |
stmt |
bran |
cond |
sub |
pod |
time |
code |
1
|
|
|
|
|
|
|
package Object::Remote::MiniLoop; |
2
|
|
|
|
|
|
|
|
3
|
13
|
|
|
13
|
|
5025
|
use IO::Select; |
|
13
|
|
|
|
|
17505
|
|
|
13
|
|
|
|
|
530
|
|
4
|
13
|
|
|
13
|
|
4735
|
use Time::HiRes qw(time); |
|
13
|
|
|
|
|
12879
|
|
|
13
|
|
|
|
|
51
|
|
5
|
13
|
|
|
13
|
|
6044
|
use Object::Remote::Logging qw( :log :dlog router ); |
|
13
|
|
|
|
|
33
|
|
|
13
|
|
|
|
|
61
|
|
6
|
13
|
|
|
13
|
|
83
|
use Moo; |
|
13
|
|
|
|
|
39
|
|
|
13
|
|
|
|
|
63
|
|
7
|
|
|
|
|
|
|
|
8
|
|
|
|
|
|
|
BEGIN { |
9
|
13
|
|
|
13
|
|
6081
|
$SIG{PIPE} = sub { log_debug { "Got a PIPE signal" } }; |
|
0
|
|
|
|
|
0
|
|
|
0
|
|
|
|
|
0
|
|
10
|
|
|
|
|
|
|
|
11
|
13
|
|
|
|
|
63
|
router()->exclude_forwarding |
12
|
|
|
|
|
|
|
} |
13
|
|
|
|
|
|
|
|
14
|
|
|
|
|
|
|
# this is ro because we only actually set it using local in sub run |
15
|
|
|
|
|
|
|
has is_running => (is => 'ro', clearer => 'stop'); |
16
|
|
|
|
|
|
|
#maximum duration that select() will block - undef means indefinite, |
17
|
|
|
|
|
|
|
#0 means no blocking, otherwise maximum time in seconds |
18
|
|
|
|
|
|
|
has block_duration => ( is => 'rw' ); |
19
|
|
|
|
|
|
|
|
20
|
|
|
|
|
|
|
has _read_watches => (is => 'ro', default => sub { {} }); |
21
|
|
|
|
|
|
|
has _read_select => (is => 'ro', default => sub { IO::Select->new }); |
22
|
|
|
|
|
|
|
|
23
|
|
|
|
|
|
|
has _write_watches => (is => 'ro', default => sub { {} }); |
24
|
|
|
|
|
|
|
has _write_select => (is => 'ro', default => sub { IO::Select->new }); |
25
|
|
|
|
|
|
|
|
26
|
|
|
|
|
|
|
has _timers => (is => 'ro', default => sub { [] }); |
27
|
|
|
|
|
|
|
|
28
|
|
|
|
|
|
|
sub pass_watches_to { |
29
|
0
|
|
|
0
|
0
|
0
|
my ($self, $new_loop) = @_; |
30
|
0
|
|
|
0
|
|
0
|
log_debug { "passing watches to new run loop" }; |
|
0
|
|
|
|
|
0
|
|
31
|
0
|
|
|
|
|
0
|
foreach my $fh ($self->_read_select->handles) { |
32
|
|
|
|
|
|
|
$new_loop->watch_io( |
33
|
|
|
|
|
|
|
handle => $fh, |
34
|
0
|
|
|
|
|
0
|
on_read_ready => $self->_read_watches->{$fh} |
35
|
|
|
|
|
|
|
); |
36
|
|
|
|
|
|
|
} |
37
|
0
|
|
|
|
|
0
|
foreach my $fh ($self->_write_select->handles) { |
38
|
|
|
|
|
|
|
$new_loop->watch_io( |
39
|
|
|
|
|
|
|
handle => $fh, |
40
|
0
|
|
|
|
|
0
|
on_write_ready => $self->_write_watches->{$fh} |
41
|
|
|
|
|
|
|
); |
42
|
|
|
|
|
|
|
} |
43
|
|
|
|
|
|
|
} |
44
|
|
|
|
|
|
|
|
45
|
|
|
|
|
|
|
sub watch_io { |
46
|
40
|
|
|
40
|
0
|
624
|
my ($self, %watch) = @_; |
47
|
40
|
|
|
|
|
154
|
my $fh = $watch{handle}; |
48
|
40
|
|
|
0
|
|
523
|
Dlog_debug { "Adding IO watch for $_" } $fh; |
|
0
|
|
|
|
|
0
|
|
49
|
|
|
|
|
|
|
|
50
|
40
|
100
|
|
|
|
635
|
if (my $cb = $watch{on_read_ready}) { |
51
|
20
|
|
|
0
|
|
249
|
log_trace { "IO watcher is registering with select for reading" }; |
|
0
|
|
|
|
|
0
|
|
52
|
20
|
|
|
|
|
286
|
$self->_read_select->add($fh); |
53
|
20
|
|
|
|
|
894
|
$self->_read_watches->{$fh} = $cb; |
54
|
|
|
|
|
|
|
} |
55
|
40
|
100
|
|
|
|
258
|
if (my $cb = $watch{on_write_ready}) { |
56
|
20
|
|
|
0
|
|
246
|
log_trace { "IO watcher is registering with select for writing" }; |
|
0
|
|
|
|
|
0
|
|
57
|
20
|
|
|
|
|
464
|
$self->_write_select->add($fh); |
58
|
20
|
|
|
|
|
1819
|
$self->_write_watches->{$fh} = $cb; |
59
|
|
|
|
|
|
|
} |
60
|
40
|
|
|
|
|
569
|
return; |
61
|
|
|
|
|
|
|
} |
62
|
|
|
|
|
|
|
|
63
|
|
|
|
|
|
|
sub unwatch_io { |
64
|
21
|
|
|
21
|
0
|
125
|
my ($self, %watch) = @_; |
65
|
21
|
|
|
|
|
57
|
my $fh = $watch{handle}; |
66
|
21
|
|
|
0
|
|
257
|
Dlog_debug { "Removing IO watch for $_" } $fh; |
|
0
|
|
|
|
|
0
|
|
67
|
21
|
100
|
|
|
|
328
|
if ($watch{on_read_ready}) { |
68
|
2
|
|
|
0
|
|
19
|
log_trace { "IO watcher is removing read from select()" }; |
|
0
|
|
|
|
|
0
|
|
69
|
2
|
|
|
|
|
29
|
$self->_read_select->remove($fh); |
70
|
2
|
|
|
|
|
113
|
delete $self->_read_watches->{$fh}; |
71
|
|
|
|
|
|
|
} |
72
|
21
|
100
|
|
|
|
89
|
if ($watch{on_write_ready}) { |
73
|
19
|
|
|
0
|
|
140
|
log_trace { "IO watcher is removing write from select()" }; |
|
0
|
|
|
|
|
0
|
|
74
|
19
|
|
|
|
|
294
|
$self->_write_select->remove($fh); |
75
|
19
|
|
|
|
|
1002
|
delete $self->_write_watches->{$fh}; |
76
|
|
|
|
|
|
|
} |
77
|
21
|
|
|
|
|
1053
|
return; |
78
|
|
|
|
|
|
|
} |
79
|
|
|
|
|
|
|
|
80
|
|
|
|
|
|
|
sub _sort_timers { |
81
|
25
|
|
|
25
|
|
103
|
my ($self, @new) = @_; |
82
|
25
|
|
|
|
|
84
|
my $timers = $self->_timers; |
83
|
|
|
|
|
|
|
|
84
|
25
|
|
|
0
|
|
204
|
log_trace { "Sorting timers" }; |
|
0
|
|
|
|
|
0
|
|
85
|
|
|
|
|
|
|
|
86
|
25
|
|
|
|
|
228
|
@{$timers} = sort { $a->[0] <=> $b->[0] } @{$timers}, @new; |
|
25
|
|
|
|
|
119
|
|
|
36
|
|
|
|
|
164
|
|
|
25
|
|
|
|
|
209
|
|
87
|
25
|
|
|
|
|
84
|
return; |
88
|
|
|
|
|
|
|
} |
89
|
|
|
|
|
|
|
|
90
|
|
|
|
|
|
|
sub watch_time { |
91
|
23
|
|
|
23
|
0
|
242
|
my ($self, %watch) = @_; |
92
|
23
|
|
|
|
|
74
|
my $at; |
93
|
|
|
|
|
|
|
|
94
|
23
|
|
|
0
|
|
329
|
Dlog_trace { "watch_time() invoked with $_" } \%watch; |
|
0
|
|
|
|
|
0
|
|
95
|
|
|
|
|
|
|
|
96
|
23
|
100
|
|
|
|
337
|
if (exists($watch{every})) { |
|
|
50
|
|
|
|
|
|
|
|
0
|
|
|
|
|
|
97
|
1
|
|
|
|
|
6
|
$at = time() + $watch{every}; |
98
|
|
|
|
|
|
|
} elsif (exists($watch{after})) { |
99
|
22
|
|
|
|
|
134
|
$at = time() + $watch{after}; |
100
|
|
|
|
|
|
|
} elsif (exists($watch{at})) { |
101
|
0
|
|
|
|
|
0
|
$at = $watch{at}; |
102
|
|
|
|
|
|
|
} else { |
103
|
0
|
|
|
|
|
0
|
die "watch_time requires every, after or at"; |
104
|
|
|
|
|
|
|
} |
105
|
|
|
|
|
|
|
|
106
|
23
|
50
|
|
|
|
143
|
die "watch_time requires code" unless my $code = $watch{code}; |
107
|
23
|
|
|
|
|
164
|
my $timers = $self->_timers; |
108
|
23
|
|
|
|
|
74
|
my $new = [ $at => $code, $watch{every} ]; |
109
|
23
|
|
|
|
|
129
|
$self->_sort_timers($new); |
110
|
23
|
|
|
0
|
|
304
|
log_debug { "Created new timer with id '$new' that expires at '$at'" }; |
|
0
|
|
|
|
|
0
|
|
111
|
23
|
|
|
|
|
316
|
return "$new"; |
112
|
|
|
|
|
|
|
} |
113
|
|
|
|
|
|
|
|
114
|
|
|
|
|
|
|
sub unwatch_time { |
115
|
1
|
|
|
1
|
0
|
3
|
my ($self, $id) = @_; |
116
|
1
|
|
|
0
|
|
15
|
log_trace { "Removing timer with id of '$id'" }; |
|
0
|
|
|
|
|
0
|
|
117
|
1
|
|
|
|
|
25
|
@$_ = grep !($_ eq $id), @$_ for $self->_timers; |
118
|
1
|
|
|
|
|
4
|
return; |
119
|
|
|
|
|
|
|
} |
120
|
|
|
|
|
|
|
|
121
|
|
|
|
|
|
|
sub _next_timer_expires_delay { |
122
|
732
|
|
|
732
|
|
1084
|
my ($self) = @_; |
123
|
732
|
|
|
|
|
1197
|
my $timers = $self->_timers; |
124
|
732
|
|
|
|
|
1216
|
my $delay_max = $self->block_duration; |
125
|
|
|
|
|
|
|
|
126
|
732
|
50
|
|
|
|
1440
|
return $delay_max unless @$timers; |
127
|
732
|
|
|
|
|
1919
|
my $duration = $timers->[0]->[0] - time; |
128
|
|
|
|
|
|
|
|
129
|
732
|
|
|
0
|
|
3003
|
log_trace { "next timer fires in '$duration' seconds" }; |
|
0
|
|
|
|
|
0
|
|
130
|
|
|
|
|
|
|
|
131
|
732
|
50
|
33
|
|
|
7760
|
if ($duration < 0) { |
|
|
50
|
|
|
|
|
|
132
|
0
|
|
|
|
|
0
|
$duration = 0; |
133
|
|
|
|
|
|
|
} elsif (defined $delay_max && $duration > $delay_max) { |
134
|
0
|
|
|
|
|
0
|
$duration = $delay_max; |
135
|
|
|
|
|
|
|
} |
136
|
|
|
|
|
|
|
|
137
|
732
|
|
|
|
|
1405
|
return $duration; |
138
|
|
|
|
|
|
|
} |
139
|
|
|
|
|
|
|
|
140
|
|
|
|
|
|
|
sub loop_once { |
141
|
732
|
|
|
732
|
0
|
1233
|
my ($self) = @_; |
142
|
732
|
|
|
|
|
1345
|
my $read = $self->_read_watches; |
143
|
732
|
|
|
|
|
1264
|
my $write = $self->_write_watches; |
144
|
732
|
|
|
|
|
949
|
my $read_count = 0; |
145
|
732
|
|
|
|
|
874
|
my $write_count = 0; |
146
|
732
|
|
|
|
|
1768
|
my @c = caller; |
147
|
732
|
|
|
|
|
1531
|
my $wait_time = $self->_next_timer_expires_delay; |
148
|
|
|
|
|
|
|
log_trace { |
149
|
0
|
0
|
|
0
|
|
0
|
sprintf("Run loop: loop_once() has been invoked by $c[1]:$c[2] with read:%i write:%i select timeout:%s", |
150
|
|
|
|
|
|
|
scalar(keys(%$read)), scalar(keys(%$write)), defined $wait_time ? $wait_time : 'indefinite' ) |
151
|
732
|
|
|
|
|
3376
|
}; |
152
|
732
|
|
|
|
|
8828
|
my ($readable, $writeable) = IO::Select->select( |
153
|
|
|
|
|
|
|
$self->_read_select, $self->_write_select, undef, $wait_time |
154
|
|
|
|
|
|
|
); |
155
|
|
|
|
|
|
|
log_trace { |
156
|
0
|
0
|
|
0
|
|
0
|
my $readable_count = defined $readable ? scalar(@$readable) : 0; |
157
|
0
|
0
|
|
|
|
0
|
my $writable_count = defined $writeable ? scalar(@$writeable) : 0; |
158
|
0
|
|
|
|
|
0
|
"Run loop: select returned readable:$readable_count writeable:$writable_count"; |
159
|
732
|
|
|
|
|
6799455
|
}; |
160
|
|
|
|
|
|
|
# I would love to trap errors in the select call but IO::Select doesn't |
161
|
|
|
|
|
|
|
# differentiate between an error and a timeout. |
162
|
|
|
|
|
|
|
# -- no, love, mst. |
163
|
|
|
|
|
|
|
|
164
|
732
|
|
|
0
|
|
9102
|
log_trace { "Reading from ready filehandles" }; |
|
0
|
|
|
|
|
0
|
|
165
|
732
|
|
|
|
|
6404
|
foreach my $fh (@$readable) { |
166
|
193
|
50
|
|
|
|
801
|
next unless $read->{$fh}; |
167
|
193
|
|
|
|
|
340
|
$read_count++; |
168
|
193
|
|
|
|
|
792
|
$read->{$fh}(); |
169
|
|
|
|
|
|
|
#FIXME this is a rough workaround for race conditions that can cause deadlocks |
170
|
|
|
|
|
|
|
#under load |
171
|
193
|
|
|
|
|
565
|
last; |
172
|
|
|
|
|
|
|
} |
173
|
732
|
|
|
0
|
|
3025
|
log_trace { "Writing to ready filehandles" }; |
|
0
|
|
|
|
|
0
|
|
174
|
732
|
|
|
|
|
6209
|
foreach my $fh (@$writeable) { |
175
|
534
|
50
|
|
|
|
1460
|
next unless $write->{$fh}; |
176
|
534
|
|
|
|
|
715
|
$write_count++; |
177
|
534
|
|
|
|
|
1601
|
$write->{$fh}(); |
178
|
|
|
|
|
|
|
#FIXME this is a rough workaround for race conditions that can cause deadlocks |
179
|
|
|
|
|
|
|
#under load |
180
|
534
|
|
|
|
|
4678
|
last; |
181
|
|
|
|
|
|
|
} |
182
|
|
|
|
|
|
|
|
183
|
|
|
|
|
|
|
#moving the timers above the read() section exposes a deadlock |
184
|
732
|
|
|
0
|
|
3409
|
log_trace { "Read from $read_count filehandles; wrote to $write_count filehandles" }; |
|
0
|
|
|
|
|
0
|
|
185
|
732
|
|
|
|
|
6665
|
my $timers = $self->_timers; |
186
|
732
|
|
|
|
|
1827
|
my $now = time(); |
187
|
732
|
|
|
0
|
|
2711
|
log_trace { "Checking timers" }; |
|
0
|
|
|
|
|
0
|
|
188
|
732
|
|
100
|
|
|
8319
|
while (@$timers and $timers->[0][0] <= $now) { |
189
|
5
|
|
|
|
|
15
|
my $active = $timers->[0]; |
190
|
5
|
|
|
0
|
|
38
|
Dlog_trace { "Found timer that needs to be executed: '$active'" }; |
|
0
|
|
|
|
|
0
|
|
191
|
|
|
|
|
|
|
|
192
|
5
|
100
|
|
|
|
72
|
if (defined($active->[2])) { |
193
|
|
|
|
|
|
|
#handle the case of an 'every' timer |
194
|
2
|
|
|
|
|
9
|
$active->[0] = time() + $active->[2]; |
195
|
2
|
|
|
0
|
|
11
|
Dlog_trace { "scheduling timer for repeat execution at $_"} $active->[0]; |
|
0
|
|
|
|
|
0
|
|
196
|
2
|
|
|
|
|
24
|
$self->_sort_timers; |
197
|
|
|
|
|
|
|
} else { |
198
|
|
|
|
|
|
|
#it doesn't repeat again so get rid of it |
199
|
3
|
|
|
|
|
9
|
shift(@$timers); |
200
|
|
|
|
|
|
|
} |
201
|
|
|
|
|
|
|
|
202
|
|
|
|
|
|
|
#execute the timer |
203
|
5
|
|
|
|
|
42
|
$active->[1]->(); |
204
|
|
|
|
|
|
|
} |
205
|
|
|
|
|
|
|
|
206
|
732
|
|
|
0
|
|
2973
|
log_trace { "Run loop: single loop is completed" }; |
|
0
|
|
|
|
|
0
|
|
207
|
732
|
|
|
|
|
7668
|
return; |
208
|
|
|
|
|
|
|
} |
209
|
|
|
|
|
|
|
|
210
|
|
|
|
|
|
|
sub want_run { |
211
|
0
|
|
|
0
|
0
|
0
|
my ($self) = @_; |
212
|
0
|
|
|
0
|
|
0
|
Dlog_debug { "Run loop: Incremeting want_running, is now $_" } |
213
|
0
|
|
|
|
|
0
|
++$self->{want_running}; |
214
|
|
|
|
|
|
|
} |
215
|
|
|
|
|
|
|
|
216
|
|
|
|
|
|
|
sub run_while_wanted { |
217
|
0
|
|
|
0
|
0
|
0
|
my ($self) = @_; |
218
|
0
|
|
|
0
|
|
0
|
log_debug { my $wr = $self->{want_running}; "Run loop: run_while_wanted() invoked; want_running: $wr" }; |
|
0
|
|
|
|
|
0
|
|
|
0
|
|
|
|
|
0
|
|
219
|
0
|
|
|
|
|
0
|
$self->loop_once while $self->{want_running}; |
220
|
0
|
|
|
0
|
|
0
|
log_debug { "Run loop: run_while_wanted() completed" }; |
|
0
|
|
|
|
|
0
|
|
221
|
0
|
|
|
|
|
0
|
return; |
222
|
|
|
|
|
|
|
} |
223
|
|
|
|
|
|
|
|
224
|
|
|
|
|
|
|
sub want_stop { |
225
|
0
|
|
|
0
|
0
|
0
|
my ($self) = @_; |
226
|
0
|
0
|
|
|
|
0
|
if (! $self->{want_running}) { |
227
|
0
|
|
|
0
|
|
0
|
log_debug { "Run loop: want_stop() was called but want_running was not true" }; |
|
0
|
|
|
|
|
0
|
|
228
|
0
|
|
|
|
|
0
|
return; |
229
|
|
|
|
|
|
|
} |
230
|
0
|
|
|
0
|
|
0
|
Dlog_debug { "Run loop: decrimenting want_running, is now $_" } |
231
|
0
|
|
|
|
|
0
|
--$self->{want_running}; |
232
|
|
|
|
|
|
|
} |
233
|
|
|
|
|
|
|
|
234
|
|
|
|
|
|
|
sub run { |
235
|
175
|
|
|
175
|
0
|
386
|
my ($self) = @_; |
236
|
175
|
|
|
0
|
|
877
|
log_trace { "Run loop: run() invoked" }; |
|
0
|
|
|
|
|
0
|
|
237
|
175
|
|
|
|
|
1662
|
local $self->{is_running} = 1; |
238
|
175
|
|
|
|
|
600
|
while ($self->is_running) { |
239
|
732
|
|
|
|
|
1608
|
$self->loop_once; |
240
|
|
|
|
|
|
|
} |
241
|
175
|
|
|
0
|
|
826
|
log_trace { "Run loop: run() completed" }; |
|
0
|
|
|
|
|
0
|
|
242
|
175
|
|
|
|
|
1649
|
return; |
243
|
|
|
|
|
|
|
} |
244
|
|
|
|
|
|
|
|
245
|
|
|
|
|
|
|
1; |