
mmartinec at apache
Nov 24, 2009, 2:51 AM
Post #1 of 1
(177 views)
Permalink
|
|
svn commit: r883650 - in /spamassassin/trunk: lib/Mail/SpamAssassin/Timeout.pm t/timeout.t
|
|
Author: mmartinec Date: Tue Nov 24 10:51:24 2009 New Revision: 883650 URL: http://svn.apache.org/viewvc?rev=883650&view=rev Log: Bug 6238: run_and_catch failed to catch a non-timed run; M::S::Timeout::reset() should have accounted for time already spent; signal produced by kill('ALRM',0) does not behave like a signal from alarm() - just use Time::HiRes::alarm(0.01) instead; added timing tests t/timeout.t Added: spamassassin/trunk/t/timeout.t (with props) Modified: spamassassin/trunk/lib/Mail/SpamAssassin/Timeout.pm Modified: spamassassin/trunk/lib/Mail/SpamAssassin/Timeout.pm URL: http://svn.apache.org/viewvc/spamassassin/trunk/lib/Mail/SpamAssassin/Timeout.pm?rev=883650&r1=883649&r2=883650&view=diff ============================================================================== --- spamassassin/trunk/lib/Mail/SpamAssassin/Timeout.pm (original) +++ spamassassin/trunk/lib/Mail/SpamAssassin/Timeout.pm Tue Nov 24 10:51:24 2009 @@ -141,6 +141,7 @@ delete $self->{timed_out}; + my $id = $self->{id}; my $secs = $self->{secs}; my $deadline = $self->{deadline}; @@ -149,29 +150,34 @@ die "Mail::SpamAssassin::Timeout: oops? neg value for 'secs': $secs"; } + my $start_time = time; if (defined $deadline) { - my $dt = $deadline - time; + my $dt = $deadline - $start_time; $secs = $dt if !defined $secs || $dt < $secs; } - if (!defined $secs) { # no timeout! just call the sub and return. - return &$sub; - } - - my $id = $self->{id}; - my $ret; - my $oldalarm = alarm(0); # remaining time, 0 when disarmed, undef on error - my $start_time = time; - # bug 4699: under heavy load, an alarm may fire while $@ will contain "", # which isn't very useful. this flag works around it safely, since # it will not require malloc() be called if it fires my $timedout = 0; - my $eval_stat; + my($oldalarm, $handler); + if (defined $secs) { + $oldalarm = alarm(0); # remaining time, 0 when disarmed, undef on error + $self->{end_time} = $start_time + $secs; # needed by reset() + $handler = sub { $timedout = 1; die "__alarm__ignore__($id)\n" }; + } + + my($ret, $eval_stat); eval { - if ($secs <= 0) { - die "__alarm__ignore__($id) (pre-expired)\n"; + local $SIG{__DIE__}; # bug 4631 + + if (!defined $secs) { # no timeout, just call the sub + $ret = &$sub; + + } elsif ($secs <= 0) { + $self->{timed_out} = 1; + &$handler; } elsif ($oldalarm && $oldalarm < $secs) { # just restore outer timer, a timeout signal will be handled there @@ -179,10 +185,7 @@ $ret = &$sub; } else { - # note use of local to ensure closed scope here - local $SIG{ALRM} = sub { $timedout = 1; die "__alarm__ignore__($id)\n" }; - local $SIG{__DIE__}; # bug 4631 - + local $SIG{ALRM} = $handler; # ensure closed scope here my $isecs = int($secs); $isecs++ if $secs > int($isecs); # ceiling alarm($isecs); @@ -206,6 +209,8 @@ alarm(0); # in case we popped out for some other reason }; + delete $self->{end_time}; # reset() is only applicable within a &$sub + # catch timedout return: # 0 0 $ret # 0 1 undef @@ -214,17 +219,18 @@ # my $return = $and_catch ? $eval_stat : $ret; - if (defined $eval_stat) { - if ($eval_stat =~ /__alarm__ignore__\Q($id)\E/) { - undef $return; $self->{timed_out} = 1; - } + if (defined $eval_stat && $eval_stat =~ /__alarm__ignore__\Q($id)\E/) { + $self->{timed_out} = 1; } elsif ($timedout) { # this happens occasionally; haven't figured out why. seems # harmless in effect, though, so just issue a warning and carry on... warn "timeout with empty eval status\n"; - undef $return; $self->{timed_out} = 1; + $self->{timed_out} = 1; } + # covers all cases, including where $self->{timed_out} is flagged by reset() + undef $return if $self->{timed_out}; + my $remaining_time; if ($oldalarm) { $remaining_time = $start_time + $oldalarm - time; @@ -243,7 +249,11 @@ die "Timeout::_run: $eval_stat\n"; } if (defined $remaining_time) { - kill('ALRM',0); # previous timer expired meanwhile, re-signal right away + $self->{timed_out} = 1; + # previous timer expired meanwhile, re-signal right away + # somehow the kill('ALRM',0) does not behave like alarm does + # kill('ALRM',0) == 1 or die "Cannot send SIGALRM to myself [$$]"; + Time::HiRes::alarm(0.01); } return $return; } @@ -266,30 +276,28 @@ =item $t->reset() -If called within a C<run()> code reference, causes the current alarm timer to -be reset to its starting value. +If called within a C<run()> code reference, causes the current alarm timer +to be restored to its original setting (useful after our alarm setting was +clobbered by some underlying module). =cut sub reset { my ($self) = @_; - my $secs = $self->{secs}; - my $deadline = $self->{deadline}; - - if (defined $deadline) { - my $dt = $deadline - time; - $secs = $dt if !defined $secs || $dt < $secs; - } + return if !defined $self->{end_time}; - if (!defined $secs) { - # not timed - } elsif ($secs > 0) { + my $secs = $self->{end_time} - time; + if ($secs > 0) { my $isecs = int($secs); $isecs++ if $secs > int($isecs); # ceiling alarm($isecs); } else { - kill('ALRM',0); # previous timer expired meanwhile, re-signal right away + $self->{timed_out} = 1; + # time interval expired meanwhile, re-signal right away + # somehow the kill('ALRM',0) does not behave like alarm does + # kill('ALRM',0) == 1 or die "Cannot send SIGALRM to myself [$$]"; + Time::HiRes::alarm(0.01); } } Added: spamassassin/trunk/t/timeout.t URL: http://svn.apache.org/viewvc/spamassassin/trunk/t/timeout.t?rev=883650&view=auto ============================================================================== --- spamassassin/trunk/t/timeout.t (added) +++ spamassassin/trunk/t/timeout.t Tue Nov 24 10:51:24 2009 @@ -0,0 +1,133 @@ +#!/usr/bin/perl + +BEGIN { + if (-e 't/test_dir') { # if we are running "t/rule_tests.t", kluge around ... + chdir 't'; + } + + if (-e 'test_dir') { # running from test directory, not .. + unshift(@INC, '../blib/lib'); + unshift(@INC, '../lib'); + } +} + +my $prefix = '.'; +if (-e 'test_dir') { # running from test directory, not .. + $prefix = '..'; +} + +use lib '.'; use lib 't'; +use SATest; sa_t_init("timeout"); +use Test; BEGIN { plan tests => 27 }; + +use strict; +use Time::HiRes qw(time sleep); + +require Mail::SpamAssassin::Timeout; +# require Mail::SpamAssassin::Logger; +# Mail::SpamAssassin::Logger::add_facilities('all'); + +# attempt to circumvent an advice not to mix alarm() with sleep(); +# interaction between alarms and sleeps is unspecified +# +sub mysleep($) { + my($dt) = @_; + sleep(0.1) for 1..int(10*$dt); +} + +my($r,$t,$t1,$t2); + +$t = Mail::SpamAssassin::Timeout->new; +$r = $t->run(sub { mysleep 1; 42 }); +ok(!$t->timed_out && $r == 42); + +$t = Mail::SpamAssassin::Timeout->new({ }); +$r = $t->run(sub { mysleep 1; 42 }); +ok(!$t->timed_out && $r == 42); + +$t = Mail::SpamAssassin::Timeout->new; +$r = $t->run_and_catch(sub { mysleep 1; die "run_and_catch test1\n" }); +ok(!$t->timed_out && $r =~ /^run_and_catch test1/); + +my $caught = 0; +$t = Mail::SpamAssassin::Timeout->new; +eval { + $r = $t->run(sub { mysleep 1; die "run_and_catch test2\n" }); 1; +} or do { + $caught = 1 if $@ =~ /run_and_catch test2/; +}; +ok(!$t->timed_out && $caught); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 2 }); +$r = $t->run(sub { mysleep 3; 42 }); +ok($t->timed_out && !defined $r); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 2 }); +$r = $t->run(sub { mysleep 1; 42 }); +ok(!$t->timed_out && $r == 42); + +$t = Mail::SpamAssassin::Timeout->new({ deadline => time+2 }); +$r = $t->run(sub { mysleep 3; 42 }); +ok($t->timed_out && !defined $r); + +$t = Mail::SpamAssassin::Timeout->new({ deadline => time+2 }); +$r = $t->run(sub { mysleep 1; 42 }); +ok(!$t->timed_out && $r == 42); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 2, deadline => time+5 }); +$r = $t->run(sub { mysleep 3; 42 }); +ok($t->timed_out && !defined $r); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 2, deadline => time+5 }); +$r = $t->run(sub { mysleep 1; 42 }); +ok(!$t->timed_out && $r == 42); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 9, deadline => time+2 }); +$r = $t->run(sub { mysleep 3; 42 }); +ok($t->timed_out && !defined $r); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 9, deadline => time+2 }); +$r = $t->run(sub { mysleep 1; 42 }); +ok(!$t->timed_out && $r == 42); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 2 }); +$r = $t->run(sub { alarm 0; mysleep 1; $t->reset; mysleep 2; 42 }); +ok($t->timed_out && !defined $r); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 3 }); +$r = $t->run(sub { alarm 0; mysleep 1; $t->reset; mysleep 1; 42 }); +ok(!$t->timed_out && $r == 42); + +$t = Mail::SpamAssassin::Timeout->new({ secs => 2 }); +$r = $t->run(sub { alarm 0; mysleep 3; $t->reset; 42 }); +ok($t->timed_out && !defined $r); + +$t1 = Mail::SpamAssassin::Timeout->new({ secs => 1 }); +$t2 = Mail::SpamAssassin::Timeout->new({ secs => 2 }); +$r = $t1->run(sub { $t2->run(sub { mysleep 3; 43 }); 42 }); +ok($t1->timed_out); +ok(!$t2->timed_out); +ok(!defined $r); + +$t1 = Mail::SpamAssassin::Timeout->new({ secs => 2 }); +$t2 = Mail::SpamAssassin::Timeout->new({ secs => 1 }); +$r = $t1->run(sub { $t2->run(sub { mysleep 3; 43 }); 42 }); +ok(!$t1->timed_out); +ok($t2->timed_out); +ok($r == 42); + +$t1 = Mail::SpamAssassin::Timeout->new({ secs => 2 }); +$t2 = Mail::SpamAssassin::Timeout->new({ secs => 1 }); +$r = $t1->run(sub { $t2->run(sub { mysleep 3; 43 }); mysleep 3; 42 }); +ok($t1->timed_out); +ok($t2->timed_out); +ok(!defined $r); + +$t1 = Mail::SpamAssassin::Timeout->new({ secs => 1 }); +$t2 = Mail::SpamAssassin::Timeout->new({ secs => 1 }); +$r = $t1->run(sub { $t2->run(sub { mysleep 3; 43 }); mysleep 3; 42 }); +ok($t1->timed_out); +ok($t2->timed_out); +ok(!defined $r); + +1; Propchange: spamassassin/trunk/t/timeout.t ------------------------------------------------------------------------------ svn:eol-style = native
|