Time::Local busted?

Time::Local busted?

am 24.04.2008 15:00:45 von Mark Seger

I have a script that tails a file and on a SIGTERM I want it to exit.
Sounds simple enough. It traps the signal, executes an 'exit', and then
hangs! The real odd thing is one of the modules I'm 'using' is
Time::Local. If I comment it out the script exits on SIGTERM and if it
leave it in it doesn't. The only way I was able to figure this out was
methodically removing pieces of code until it worked correctly and as
you might guess, the last thing I thought of was removing some of the
'use' statements. Anyhow this leads to a few questions:

- does anyone have a clue what this is breaking things?
- how would you have tracked down this problem with the Time module
- how can I make this work correctly AND use Time?

Anyhow, here's a pretty small piece of code that fails! Just comment
out the 'use Time' and it works...

#!/usr/bin/perl -w

use strict;
use Time::Local;

print "PID: $$\n";
$SIG{"TERM"}=\&sigTerm; # default kill command
while(1) {
open TAIL, "tail -f /var/log/aggregate|" or die;
while (my $line=) {
my $x=1;
}
}

sub sigTerm {
print "SIGTERM\n";
exit(1);
}

here's what I see when I execute a 'kill' from another window:
[root@cag-dl380-01 tmp]# ./test9.pl
PID: 13796
SIGTERM

and it's hung... Now if I comment out Time:
[root@cag-dl380-01 tmp]# ./test9.pl
PID: 13799
SIGTERM
[root@cag-dl380-01 tmp]#

-mark

Re: Time::Local busted?

am 24.04.2008 16:20:57 von smallpond

On Apr 24, 9:00 am, Mark Seger wrote:
> I have a script that tails a file and on a SIGTERM I want it to exit.
> Sounds simple enough. It traps the signal, executes an 'exit', and then
> hangs! The real odd thing is one of the modules I'm 'using' is
> Time::Local. If I comment it out the script exits on SIGTERM and if it
> leave it in it doesn't. The only way I was able to figure this out was
> methodically removing pieces of code until it worked correctly and as
> you might guess, the last thing I thought of was removing some of the
> 'use' statements. Anyhow this leads to a few questions:
>
> - does anyone have a clue what this is breaking things?
> - how would you have tracked down this problem with the Time module
> - how can I make this work correctly AND use Time?
>
> Anyhow, here's a pretty small piece of code that fails! Just comment
> out the 'use Time' and it works...
>
> #!/usr/bin/perl -w
>
> use strict;
> use Time::Local;
>
> print "PID: $$\n";
> $SIG{"TERM"}=\&sigTerm; # default kill command
> while(1) {
> open TAIL, "tail -f /var/log/aggregate|" or die;
> while (my $line=) {
> my $x=1;
> }
>
> }
>
> sub sigTerm {
> print "SIGTERM\n";
> exit(1);
>
> }
>
> here's what I see when I execute a 'kill' from another window:
> [root@cag-dl380-01 tmp]# ./test9.pl
> PID: 13796
> SIGTERM
>
> and it's hung... Now if I comment out Time:
> [root@cag-dl380-01 tmp]# ./test9.pl
> PID: 13799
> SIGTERM
> [root@cag-dl380-01 tmp]#
>
> -mark


Why do you think this has anything to do with Time::Local?
What happens when you change that line to:
use Config;

You have an I/O running in a child process 'tail', and the
system is waiting for it to complete before ending the process.
--S

Re: Time::Local busted?

am 24.04.2008 16:46:47 von xhoster

Mark Seger wrote:
> I have a script that tails a file and on a SIGTERM I want it to exit.
> Sounds simple enough. It traps the signal, executes an 'exit', and then
> hangs! The real odd thing is one of the modules I'm 'using' is
> Time::Local. If I comment it out the script exits on SIGTERM and if it
> leave it in it doesn't. The only way I was able to figure this out was
> methodically removing pieces of code until it worked correctly and as
> you might guess, the last thing I thought of was removing some of the
> 'use' statements. Anyhow this leads to a few questions:
>
> - does anyone have a clue what this is breaking things?
> - how would you have tracked down this problem with the Time module

The hang is because upon the clean up done at exit, the program is calling
waitpid to wait for the "tail -f ..." process.

Why Time::Local causes it to decide to clean up this process while
commenting out the Time::Local causes it to not clean it up is still a
mystery to me. The two behaviors are inconsistent, but it isn't clear to me
which one, if any, is the "more correct" behavior. The one without the
Time::Local silently leaves tail -f processes hanging around the system's
process table, which certainly isn't desirable.


> - how can I make this work correctly AND use Time?

Kill the tail, as shown below:

>
> Anyhow, here's a pretty small piece of code that fails! Just comment
> out the 'use Time' and it works...
>
> #!/usr/bin/perl -w
>
> use strict;
> use Time::Local;
>
> print "PID: $$\n";

my $kid_pid; #needs to be in scope of both open and sig_handler

> $SIG{"TERM"}=\&sigTerm; # default kill command
> while(1) {
> open TAIL, "tail -f /var/log/aggregate|" or die;

$kid_pid=open TAIL, "tail -f /var/log/aggregate|" or die;

> while (my $line=) {
> my $x=1;
> }
> }
>
> sub sigTerm {
> print "SIGTERM\n";

kill 15, $kid_pid;

> exit(1);
> }


Xho

--
-------------------- http://NewsReader.Com/ --------------------
The costs of publication of this article were defrayed in part by the
payment of page charges. This article must therefore be hereby marked
advertisement in accordance with 18 U.S.C. Section 1734 solely to indicate
this fact.

Re: Time::Local busted?

am 24.04.2008 16:52:54 von Ben Morrow

Quoth Mark Seger :
> I have a script that tails a file and on a SIGTERM I want it to exit.
> Sounds simple enough. It traps the signal, executes an 'exit', and then
> hangs! The real odd thing is one of the modules I'm 'using' is
> Time::Local. If I comment it out the script exits on SIGTERM and if it
> leave it in it doesn't. The only way I was able to figure this out was
> methodically removing pieces of code until it worked correctly and as
> you might guess, the last thing I thought of was removing some of the
> 'use' statements. Anyhow this leads to a few questions:
>
> - does anyone have a clue what this is breaking things?

This is... odd. Time::Local isn't actually necessary; all that is needed
is Config, which is pulled in by Time::Local.

The program is hanging in exit because it is trying to wait(2) for tail,
which of course hasn't exitted yet. Perl closes its end of the pipe, and
expects tail to exit (possibly with SIGPIPE) as a result of that; but
because tail is not writing at the moment, it never realises the pipe
has closed. Presumably when tail had read another bufferfull of data
from /var/log/aggregate and actually got to the point of calling
write(2) on the pipe, it would have exitted; at which point perl's exit
would also complete properly.

What I don't understand is why this doesn't happen if Config isn't
loaded. Maybe something in Config defeats perl's usual 'Oh, I'm
exitting, so I'll just drop everything on the floor and let the OS clean
up' approach (which is usually a good idea on OSen that do clean up
properly, as the OS can do it much faster than perl can).

> - how would you have tracked down this problem with the Time module

Exactly as you did :). When a program's behaviour makes no sense, keep
cutting things out until you get the smallest possible case with the
same behaviour. At that point, you'll either be able to see what's going
on, or you'll have a perfect test case for a bug report :).

I would generally start by removing as many modules as possible, though.
There's a lot of code in there, and you don't know what it's doing. It's
easier to see what's going on if it's not there.

> - how can I make this work correctly AND use Time?

One way that works is to remember the pid of the tail process (open
returns it) and pass the SIGTERM on. Then tail exits in a timely
fashion, so perl can finish its exit.

Another way that works is to use POSIX::_exit instead of exit, as this
doesn't try to close filehandles and flush buffers but just exits
directly. The problem here is that if there is unwritten data in output
buffers somewhere you will lose it.

Ben

--
If you put all the prophets, | You'd have so much more reason
Mystics and saints | Than ever was born
In one room together, | Out of all of the conflicts of time.
ben@morrow.me.uk The Levellers, 'Believers'

Re: Time::Local busted?

am 24.04.2008 17:06:31 von smallpond

On Apr 24, 10:46 am, xhos...@gmail.com wrote:
> Mark Seger wrote:
> > I have a script that tails a file and on a SIGTERM I want it to exit.
> > Sounds simple enough. It traps the signal, executes an 'exit', and then
> > hangs! The real odd thing is one of the modules I'm 'using' is
> > Time::Local. If I comment it out the script exits on SIGTERM and if it
> > leave it in it doesn't. The only way I was able to figure this out was
> > methodically removing pieces of code until it worked correctly and as
> > you might guess, the last thing I thought of was removing some of the
> > 'use' statements. Anyhow this leads to a few questions:
>
> > - does anyone have a clue what this is breaking things?
> > - how would you have tracked down this problem with the Time module
>
> The hang is because upon the clean up done at exit, the program is calling
> waitpid to wait for the "tail -f ..." process.
>
> Why Time::Local causes it to decide to clean up this process while
> commenting out the Time::Local causes it to not clean it up is still a
> mystery to me. The two behaviors are inconsistent, but it isn't clear to me
> which one, if any, is the "more correct" behavior. The one without the
> Time::Local silently leaves tail -f processes hanging around the system's
> process table, which certainly isn't desirable.
>
> > - how can I make this work correctly AND use Time?
>
> Kill the tail, as shown below:
>
>
>
> > Anyhow, here's a pretty small piece of code that fails! Just comment
> > out the 'use Time' and it works...
>
> > #!/usr/bin/perl -w
>
> > use strict;
> > use Time::Local;
>
> > print "PID: $$\n";
>
> my $kid_pid; #needs to be in scope of both open and sig_handler
>
> > $SIG{"TERM"}=\&sigTerm; # default kill command
> > while(1) {
> > open TAIL, "tail -f /var/log/aggregate|" or die;
>
> $kid_pid=open TAIL, "tail -f /var/log/aggregate|" or die;
>
> > while (my $line=) {
> > my $x=1;
> > }
> > }
>
> > sub sigTerm {
> > print "SIGTERM\n";
>
> kill 15, $kid_pid;
>
> > exit(1);
> > }
>
> Xho
>


It might be better not to start a child process in
the first place. How to tail a file in perl is a FAQ.

perldoc -f tail