Subject: | Infinite loop bug on daylight savings time end |
At the first 1:00 AM when transitioning from CDT to CST, Schedule::Cron enters an infinite
loop. This loop effectively ends when the clock rolls over to 1:00:01 AM.
With a hourly schedule like '0 * * * *', the entry is run at 1:00:00 AM, then _update_queue
puts the next execution time onto the queue. If the current time is still 1:00:00 AM, this next
execution time is put onto the front of the queue and run immediately. This chain of events
(running, calculating next execution time, putting on front of queue) continues until the clock
rolls over to 1:00:01 AM.
The looping stops at 1:00:01 because the check in sub _update_queue, which checks if
$new_time < $now, adds an hour to the next execution time when $now becomes 1:00:01.
This code allows a 1 second window for which to keep adding execution times at the current
time.
To fix this bug, the check should be the following:
my $now = time;
if ($new_time <= $now) {
dbg "Adjusting time calculation because of DST back flip (new_time - now = ",$new_time
- $now,")";
# We are adding hours as long as our target time is in the future
while ($new_time <= $now) {
$new_time += 3600;
}
}
diff:
86 $ diff Cron.pm ~/perl/Schedule-Cron-1.00/lib/Schedule/Cron.pm
1168c1168
< if ($new_time <= $now) {
---
Show quoted text
> if ($new_time < $now) {
1171c1171
< while ($new_time <= $now) {
---
Show quoted text> while ($new_time < $now) {
I tested this by adjusting the system clock on my Mac. The broken.txt file contains the output
from my test script, test.pl, and Schedule::Cron with $DEBUG=1. The fixed.txt file contains
the output after I applied the change to sub _update_queue.
Distribution: Schedule-Cron-1.00
Perl version: 5.10.0
OS: Darwin Kernel Version 10.5.0: Fri Nov 5 23:20:39 PDT 2010;
root:xnu-1504.9.17~1/RELEASE_I386 i386
Subject: | fixed.txt |
00:58:21 [ Schedule::Cron 1210] Parsing 0:59:21 2010/11/7
00:58:21 [ Schedule::Cron 1210] Parsing 1:0:21 2010/11/7
00:58:21 [ Schedule::Cron 1386] Next execution time: 01:00:00 2010/11/07 Sunday
00:58:21 [ Schedule::Cron 1176] Updating Queue: Sun Nov 7 01:00:00 2010
00:58:21 [ Schedule::Cron 794] R: sleep = 99 | Sun Nov 7 01:00:00 2010 (Sun Nov 7 00:58:21 2010)
$job_count = 1
01:00:00 [ Schedule::Cron 1210] Parsing 1:1:0 2010/11/7
01:00:00 [ Schedule::Cron 1210] Parsing 1:0:0 2010/11/7
01:00:00 [ Schedule::Cron 1386] Next execution time: 01:00:00 2010/11/07 Sunday
01:00:00 [ Schedule::Cron 1169] Adjusting time calculation because of DST back flip (new_time - now = 0)
01:00:00 [ Schedule::Cron 1176] Updating Queue: Sun Nov 7 01:00:00 2010
01:00:00 [ Schedule::Cron 794] R: sleep = 3600 | Sun Nov 7 01:00:00 2010 (Sun Nov 7 01:00:00 2010)
Subject: | test.pl |
#!/usr/bin/perl
use strict;
use warnings;
use POSIX qw( :signal_h :sys_wait_h );
use Schedule::Cron;
$SIG{ CHLD } = \&reaper;
sub reaper { 1 until waitpid( -1, POSIX::WNOHANG ) == -1 }
my $job_count = 0;
my $maximum_allowed_job_count = 5;
my $cron = new Schedule::Cron( \&dispatcher, 'nofork' => 1, 'processprefix' => 'test.pl' );
$cron->add_entry( '0 * * * *', \&dispatcher ); # every hour
$cron->run();
exit;
sub dispatcher {
local $_;
$job_count++;
print STDERR "\$job_count = $job_count", "\n";
my $pid;
if ( $job_count > $maximum_allowed_job_count ) {
print STDERR "The job count ($job_count) is greater than the maximum allowed job count ($maximum_allowed_job_count).", "\n";
return;
}
FORK:
{
if ( $pid = fork ) {
return 1;
}
elsif ( defined $pid ) {
exit 0;
}
elsif ( $! =~ /No more process/ ) {
# EAGAIN, supposedly recoverable fork error
sleep 5;
redo FORK;
}
else {
# weird fork error
print STDERR "Can not fork. $!", "\n";
return;
}
}
}
Subject: | broken.txt |
Message body is not shown because it is too large.