experimental move to non-blocking reads in ReadChannel; fix log bugs; annotate fixes...
[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 );
6 use Moo;
7
8 # this is ro because we only actually set it using local in sub run
9
10 has is_running => (is => 'ro', clearer => 'stop');
11
12 has _read_watches => (is => 'ro', default => sub { {} });
13 has _read_select => (is => 'ro', default => sub { IO::Select->new });
14
15 has _write_watches => (is => 'ro', default => sub { {} });
16 has _write_select => (is => 'ro', default => sub { IO::Select->new });
17
18 has _timers => (is => 'ro', default => sub { [] });
19
20 sub pass_watches_to {
21   my ($self, $new_loop) = @_;
22   log_debug { "passing watches to new run loop" };
23   foreach my $fh ($self->_read_select->handles) {
24     $new_loop->watch_io(
25       handle => $fh,
26       on_read_ready => $self->_read_watches->{$fh}
27     );
28   }
29   foreach my $fh ($self->_write_select->handles) {
30     $new_loop->watch_io(
31       handle => $fh,
32       on_write_ready => $self->_write_watches->{$fh}
33     );
34   }
35 }
36
37 sub watch_io {
38   my ($self, %watch) = @_;
39   my $fh = $watch{handle};
40   Dlog_debug { "Adding IO watch for $_" } $fh;
41
42   #TODO if this works out non-blocking support
43   #will need to be integrated in a way that
44   #is compatible with Windows which has no
45   #non-blocking support
46   Dlog_warn { "setting file handle to be non-blocking: " } $fh;
47   use Fcntl qw(F_GETFL F_SETFL O_NONBLOCK);
48   my $flags = fcntl($fh, F_GETFL, 0)
49     or die "Can't get flags for the socket: $!\n";
50   $flags = fcntl($fh, F_SETFL, $flags | O_NONBLOCK)
51     or die "Can't set flags for the socket: $!\n";
52
53   if (my $cb = $watch{on_read_ready}) {
54     log_trace { "IO watcher is registering with select for reading" };
55     $self->_read_select->add($fh);
56     $self->_read_watches->{$fh} = $cb;
57   }
58   if (my $cb = $watch{on_write_ready}) {
59     log_trace { "IO watcher is registering with select for writing" };
60     $self->_write_select->add($fh);
61     $self->_write_watches->{$fh} = $cb;
62   }
63   return;
64 }
65
66 sub unwatch_io {
67   my ($self, %watch) = @_;
68   my $fh = $watch{handle};
69   Dlog_debug { "Removing IO watch for $_" } $fh;
70   if ($watch{on_read_ready}) {
71     log_trace { "IO watcher is removing read from select()" };
72     $self->_read_select->remove($fh);
73     delete $self->_read_watches->{$fh};
74   }
75   if ($watch{on_write_ready}) {
76     log_trace { "IO watcher is removing write from select()" };
77     $self->_write_select->remove($fh);
78     delete $self->_write_watches->{$fh};
79   }
80   return;
81 }
82
83 sub watch_time {
84   my ($self, %watch) = @_;
85   my $at = $watch{at} || do {
86     die "watch_time requires at or after" unless my $after = $watch{after};
87     time() + $after;
88   };
89   die "watch_time requires code" unless my $code = $watch{code};
90   my $timers = $self->_timers;
91   my $new = [ $at => $code ];
92   @{$timers} = sort { $a->[0] <=> $b->[0] } @{$timers}, $new;
93   log_debug { "Created new timer that expires at '$at'" };
94   return "$new";
95 }
96
97 sub unwatch_time {
98   my ($self, $id) = @_;
99   log_debug { "Removing timer with id of '$id'" };
100   @$_ = grep !($_ eq $id), @$_ for $self->_timers;
101   return;
102 }
103
104 sub _next_timer_expires_delay {
105   my ($self) = @_;
106   my $timers = $self->_timers;
107   #undef means no timeout, select only returns
108   #when data is ready - when the system
109   #deadlocks the chatter from the timeout in
110   #select clogs up the logs
111   #TODO should make this an attribute
112   my $delay_max = undef;
113     
114   return $delay_max unless @$timers;
115   my $duration = $timers->[0]->[0] - time;
116
117   log_trace { "next timer fires in '$duration' seconds " };
118   
119   if ($duration < 0) {
120     $duration = 0; 
121   } elsif (defined $delay_max && $duration > $delay_max) {
122     $duration = $delay_max;
123   }
124   
125   #uncomment for original behavior
126   #return .5;    
127   return $duration; 
128 }
129
130 sub loop_once {
131   my ($self) = @_;
132   my $read = $self->_read_watches;
133   my $write = $self->_write_watches;
134   my $read_count = 0;
135   my $write_count = 0; 
136   my @c = caller;
137   my $wait_time = $self->_next_timer_expires_delay;
138   log_debug {  sprintf("Run loop: loop_once() has been invoked by $c[1]:$c[2] with read:%i write:%i select timeout:%s",
139       scalar(keys(%$read)), scalar(keys(%$write)), defined $wait_time ? $wait_time : 'indefinite' ) };
140   #TODO The docs state that select() in some instances can return a socket as ready to
141   #read data even if reading from it would block and the recomendation is to set
142   #handles used with select() as non-blocking but Perl on Windows can not set a 
143   #handle to use non-blocking IO - If Windows is not one of the operating
144   #systems where select() returns a handle that could block it would work to
145   #enable non-blocking mode only under Posix - the non-blocking sysread()
146   #logic would work unmodified for both blocking and non-blocking handles
147   #under Posix and Windows.
148   my ($readable, $writeable) = IO::Select->select(
149     #TODO how come select() isn't used to identify handles with errors on them?
150     #TODO is there a specific reason for a half second maximum wait duration?
151     #The two places I've found for the runloop to be invoked don't return control
152     #to the caller until a controlling variable interrupts the loop that invokes
153     #loop_once() - is this to allow that variable to be polled and exit the
154     #run loop? If so why isn't that behavior event driven and causes select() to
155     #return? 
156     $self->_read_select, $self->_write_select, undef, $wait_time
157   ); 
158   log_debug { 
159     my $readable_count = defined $readable ? scalar(@$readable) : 0;
160     my $writable_count = defined $writeable ? scalar(@$writeable) : 0;
161     "Run loop: select returned readable:$readable_count writeable:$writable_count";
162   };
163   # I would love to trap errors in the select call but IO::Select doesn't
164   # differentiate between an error and a timeout.
165   #   -- no, love, mst.
166   log_trace { "Reading from all ready filehandles" };
167   foreach my $fh (@$readable) {
168     next unless $read->{$fh};
169     $read_count++;
170     $read->{$fh}();
171 #    $read->{$fh}() if $read->{$fh};
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 #    $write->{$fh}() if $write->{$fh};
179   }
180   log_trace { "Read from $read_count filehandles; wrote to $write_count filehandles" };
181   my $timers = $self->_timers;
182   my $now = time();
183   log_trace { "Checking timers" };
184   while (@$timers and $timers->[0][0] <= $now) {
185     Dlog_debug { "Found timer that needs to be executed: $_" } $timers->[0];
186     (shift @$timers)->[1]->();
187   }
188   log_debug { "Run loop: single loop is completed" };
189   return;
190 }
191
192 #::Node and ::ConnectionServer use the want_run() / want_stop()
193 #counter to cause a run-loop to execute while something is active;
194 #the futures do this via a different mechanism
195 sub want_run {
196   my ($self) = @_;
197   Dlog_debug { "Run loop: Incrimenting want_running, is now $_" }
198     ++$self->{want_running};
199 }
200
201 sub run_while_wanted {
202   my ($self) = @_;
203   log_debug { my $wr = $self->{want_running}; "Run loop: run_while_wanted() invoked; want_running: $wr" };
204   $self->loop_once while $self->{want_running};
205   log_debug { "Run loop: run_while_wanted() completed" };
206   return;
207 }
208
209 sub want_stop {
210   my ($self) = @_;
211   if (! $self->{want_running}) {
212     log_debug { "Run loop: want_stop() was called but want_running was not true" };
213     return; 
214   }
215   Dlog_debug { "Run loop: decrimenting want_running, is now $_" }
216     --$self->{want_running};
217 }
218
219 #TODO Hypothesis: Futures invoke run() which gives that future
220 #it's own localized is_running attribute - any adjustment to the
221 #is_running attribute outside of that future will not effect that
222 #future so each future winds up able to call run() and stop() at 
223 #will with out interfering with each other 
224 sub run {
225   my ($self) = @_;
226   log_info { "Run loop: run() invoked" };
227   local $self->{is_running} = 1;
228   while ($self->is_running) {
229     $self->loop_once;
230   }
231   log_info { "Run loop: run() completed" };
232   return;
233 }
234
235 1;