make note about deadlock when moving position of timer execution
[scpubgit/Object-Remote.git] / lib / Object / Remote / MiniLoop.pm
1 package Object::Remote::MiniLoop;
2
3 use IO::Select;
4 use Time::HiRes qw(time);
5 use Object::Remote::Logging qw( :log :dlog router );
6 use Moo;
7
8 BEGIN { 
9   $SIG{PIPE} = sub { log_debug { "Got a PIPE signal" } };
10   
11   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   my ($self, $new_loop) = @_;
30   log_debug { "passing watches to new run loop" };
31   foreach my $fh ($self->_read_select->handles) {
32     $new_loop->watch_io(
33       handle => $fh,
34       on_read_ready => $self->_read_watches->{$fh}
35     );
36   }
37   foreach my $fh ($self->_write_select->handles) {
38     $new_loop->watch_io(
39       handle => $fh,
40       on_write_ready => $self->_write_watches->{$fh}
41     );
42   }
43 }
44
45 sub watch_io {
46   my ($self, %watch) = @_;
47   my $fh = $watch{handle};
48   Dlog_debug { "Adding IO watch for $_" } $fh;
49   
50   if (my $cb = $watch{on_read_ready}) {
51     log_trace { "IO watcher is registering with select for reading" };
52     $self->_read_select->add($fh);
53     $self->_read_watches->{$fh} = $cb;
54   }
55   if (my $cb = $watch{on_write_ready}) {
56     log_trace { "IO watcher is registering with select for writing" };
57     $self->_write_select->add($fh);
58     $self->_write_watches->{$fh} = $cb;
59   }
60   return;
61 }
62
63 sub unwatch_io {
64   my ($self, %watch) = @_;
65   my $fh = $watch{handle};
66   Dlog_debug { "Removing IO watch for $_" } $fh;
67   if ($watch{on_read_ready}) {
68     log_trace { "IO watcher is removing read from select()" };
69     $self->_read_select->remove($fh);
70     delete $self->_read_watches->{$fh};
71   }
72   if ($watch{on_write_ready}) {
73     log_trace { "IO watcher is removing write from select()" };
74     $self->_write_select->remove($fh);
75     delete $self->_write_watches->{$fh};
76   }
77   return;
78 }
79
80 sub _sort_timers {
81   my ($self, @new) = @_;
82   my $timers = $self->_timers; 
83   
84   log_trace { "Sorting timers" };
85   
86   @{$timers} = sort { $a->[0] <=> $b->[0] } @{$timers}, @new;
87   return;   
88 }
89
90 sub watch_time {
91   my ($self, %watch) = @_;
92   my $at; 
93   
94   Dlog_trace { "watch_time() invoked with $_" } \%watch;
95  
96   if (exists($watch{every})) {
97     $at = time() + $watch{every};
98   } elsif (exists($watch{after})) {
99     $at = time() + $watch{after}; 
100   } elsif (exists($watch{at})) {
101     $at = $watch{at}; 
102   } else {
103     die "watch_time requires every, after or at";
104   }
105   
106   die "watch_time requires code" unless my $code = $watch{code};
107   my $timers = $self->_timers;
108   my $new = [ $at => $code, $watch{every} ];
109   $self->_sort_timers($new); 
110   log_debug { "Created new timer with id '$new' that expires at '$at'" };
111   return "$new";
112 }
113
114 sub unwatch_time {
115   my ($self, $id) = @_;
116   log_trace { "Removing timer with id of '$id'" };
117   @$_ = grep !($_ eq $id), @$_ for $self->_timers;
118   return;
119 }
120
121 sub _next_timer_expires_delay {
122   my ($self) = @_;
123   my $timers = $self->_timers;
124   my $delay_max = $self->block_duration;
125     
126   return $delay_max unless @$timers;
127   my $duration = $timers->[0]->[0] - time;
128
129   log_trace { "next timer fires in '$duration' seconds " };
130   
131   if ($duration < 0) {
132     $duration = 0; 
133   } elsif (defined $delay_max && $duration > $delay_max) {
134     $duration = $delay_max;
135   }
136   
137   return $duration; 
138 }
139
140 sub loop_once {
141   my ($self) = @_;
142   my $read = $self->_read_watches;
143   my $write = $self->_write_watches;
144   my $read_count = 0;
145   my $write_count = 0; 
146   my @c = caller;
147   my $wait_time = $self->_next_timer_expires_delay;
148   log_trace {
149     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   };
152   my ($readable, $writeable) = IO::Select->select(
153     $self->_read_select, $self->_write_select, undef, $wait_time
154   ); 
155   log_trace { 
156     my $readable_count = defined $readable ? scalar(@$readable) : 0;
157     my $writable_count = defined $writeable ? scalar(@$writeable) : 0;
158     "Run loop: select returned readable:$readable_count writeable:$writable_count";
159   };
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   log_trace { "Reading from all ready filehandles" };
165   foreach my $fh (@$readable) {
166     next unless $read->{$fh};
167     $read_count++;
168     $read->{$fh}();
169     #FIXME this is a rough workaround for race conditions that can cause deadlocks
170     #under load
171     last;
172   }
173   log_trace { "Writing to all ready filehandles" };
174   foreach my $fh (@$writeable) {
175     next unless $write->{$fh};
176     $write_count++;
177     $write->{$fh}();
178     #FIXME this is a rough workaround for race conditions that can cause deadlocks
179     #under load
180     last;
181   }
182   
183   #moving the timers above the read() section exposes a deadlock
184   log_trace { "Read from $read_count filehandles; wrote to $write_count filehandles" };
185   my $timers = $self->_timers;
186   my $now = time();
187   log_trace { "Checking timers" };
188   while (@$timers and $timers->[0][0] <= $now) {
189     my $active = $timers->[0]; 
190     Dlog_trace { "Found timer that needs to be executed: '$active'" };
191      
192     if (defined($active->[2])) {
193       #handle the case of an 'every' timer
194       $active->[0] = time() + $active->[2];
195       Dlog_trace { "scheduling timer for repeat execution at $_"} $active->[0];
196       $self->_sort_timers;
197     } else {
198       #it doesn't repeat again so get rid of it  
199       shift(@$timers);
200     }
201
202     #execute the timer
203     $active->[1]->();
204   }
205   
206   log_trace { "Run loop: single loop is completed" };
207   return;
208 }
209
210 sub want_run {
211   my ($self) = @_;
212   Dlog_debug { "Run loop: Incremeting want_running, is now $_" }
213     ++$self->{want_running};
214 }
215
216 sub run_while_wanted {
217   my ($self) = @_;
218   log_debug { my $wr = $self->{want_running}; "Run loop: run_while_wanted() invoked; want_running: $wr" };
219   $self->loop_once while $self->{want_running};
220   log_debug { "Run loop: run_while_wanted() completed" };
221   return;
222 }
223
224 sub want_stop {
225   my ($self) = @_;
226   if (! $self->{want_running}) {
227     log_debug { "Run loop: want_stop() was called but want_running was not true" };
228     return; 
229   }
230   Dlog_debug { "Run loop: decrimenting want_running, is now $_" }
231     --$self->{want_running};
232 }
233
234 sub run {
235   my ($self) = @_;
236   log_trace { "Run loop: run() invoked" };
237   local $self->{is_running} = 1;
238   while ($self->is_running) {
239     $self->loop_once;
240   }
241   log_trace { "Run loop: run() completed" };
242   return;
243 }
244
245 1;