threads and logfile rotation

[Thomas Kratz]

I am a bit stumped with handling logfile rotation with a threaded app.
The below test script dies with "rename failed, Permission denied".
I assume this is because of the detached thread still referencing the
filehandle because it got copied at thread creation.

Moving the thread creation before creation of the file solves this, but
it is not really what I want. Ideally the thread should be able to log
as well to the copied handle.

Is there a way around this?

(perl 5.88 under Win23 with threads 1.64)

TIA
Thomas

use strict;
use warnings;

use threads;
use IO::File;

my $fn = 'log/test.log';
my $fh = IO::File->new($fn, '>') or die "open failed, $!";
$fh->autoflush(1);

threads->new(sub { while(1) { sleep(1) } } )->detach();

my $i = 1;
my $j = 1;
while (1) {
if ( $i % 10 == 0 ) {
$fh->close() or die "close failed, $!";
rename($fn, "$fn." . $j++) or die "rename failed, $!";
$fh = IO::File->new($fn, '>') or die "open failed, $!";
$fh->autoflush(1);
}
print $fh "sequence: ", $i++, "\n";
sleep(1);
}

--
$/=$,,$_=<DATA>,s,(.*),$1,see;__END__
s,^(.*\043),,mg,@_=map{[split'']}split;{#>J~.>_an~>>e~......>r~
$_=$_[$%][$"];y,<~>^,-++-,?{$/=--$|?'"':#..u.t.^.o.P.r.>ha~.e..
'%',s,(.),\$$/$1=1,,$;=$_}:/\w/?{y,_, ,,#..>s^~ht<._..._..c....
print}:y,.,,||last,,,,,,$_=$;;eval,redo}#.....>.e.r^.>l^..>k^.-

 

[zentara]

I am a bit stumped with handling logfile rotation with a threaded app.
The below test script dies with "rename failed, Permission denied".
I assume this is because of the detached thread still referencing the
filehandle because it got copied at thread creation.

Moving the thread creation before creation of the file solves this, but
it is not really what I want. Ideally the thread should be able to log
as well to the copied handle.

Is there a way around this?

(perl 5.88 under Win23 with threads 1.64)

I don't know how this will work on win32, but the preffered way
of having threads share a filehandle, is by passing in the fileno;
usually through a shared variable, but this passes it in directly.

You can go both ways with this. You can create the filehandle in the
thread and place it's fileno in a shared variable, and the main thread
can then access it.

#!/usr/bin/perl
use warnings;
use strict;
use threads;
use threads::shared;

# original idea from BrowserUK at
# http://perlmonks.org?node_id=493754

for my $file ( map{ glob $_ } @ARGV ) {
open my $fh, '<', $file or warn "$file : $!" and next;
printf "From main: %s", scalar <$fh> for 1 .. 10;
printf "Fileno:%d\n", fileno $fh;
threads->create( \&thread, fileno( $fh ) )->detach;
printf 'paused:';<STDIN>;
}

sub thread{
my( $fileno ) = @_;
open my $fh, "<&=$fileno" or warn $! and die;
printf "%d:%s", threads->self->tid, $_ while defined( $_ = <$fh> );
close $fh;
}
__END__


zentara

 

[Thomas Kratz]

I don't know how this will work on win32, but the preffered way
of having threads share a filehandle, is by passing in the fileno;
usually through a shared variable, but this passes it in directly.

Yes, that is the easy part
(works under Win32 as well, I am using this for sockets already)

But the problem remains how to get the filehandle closed again to be
able to rename it.
Signaling all the threads to close the filehandle and waiting for all of
them to signal back 'done' is more than ugly.

I think I'll have to change the logging mechanism. Perhaps it is better
to set up a queue for log messages and only the main thread logs them to
file. That way my existing logfile rotation can be used without changes.
But I'll have to change object initiation for my Win32 service as well
because the logfile gets created very early in the init stage of the
base object.....

Back to the drawing board!

Thanks,
Thomas

--
$/=$,,$_=<DATA>,s,(.*),$1,see;__END__
s,^(.*\043),,mg,@_=map{[split'']}split;{#>J~.>_an~>>e~......>r~
$_=$_[$%][$"];y,<~>^,-++-,?{$/=--$|?'"':#..u.t.^.o.P.r.>ha~.e..
'%',s,(.),\$$/$1=1,,$;=$_}:/\w/?{y,_, ,,#..>s^~ht<._..._..c....
print}:y,.,,||last,,,,,,$_=$;;eval,redo}#.....>.e.r^.>l^..>k^.-

 

[zentara]

zentara wrote:

Yes, that is the easy part
(works under Win32 as well, I am using this for sockets already)

But the problem remains how to get the filehandle closed again to be
able to rename it.
Signaling all the threads to close the filehandle and waiting for all of
them to signal back 'done' is more than ugly.

Back to the drawing board!
Thanks,
Thomas

I wouldn't give up too quickly on letting the threads close and
rename the file.

First, all threads share the same filehandles thru the filenos.

So, you can probably work out an elegant loop where you write
to the fileno, unless a shared flag is set. If that flag is set, you
last out of the write loop, back into the outer loop where you take care
of acquiring the new fileno, then renter the writing loop when the flag
is clear.

The main thread would be responsible for setting the flag, locking any
shared vars if needed, closing the file, opening the new file, and
placing the new fileno into the shared var, then unsetting the flag
to let the threads start writing.

Anyways, there probably is a neat solution to this.

Sometimes, it takes awhile for it to appear in your mind, but you may
be watching tv some Sunday night, and suddenly...... Eureka! You have
to scribble down a nested loop structure.

zentara

 

[Thomas Kratz]

I wouldn't give up too quickly on letting the threads close and
rename the file.

First, all threads share the same filehandles thru the filenos.

[snipped outline for shared writing to logfile]

Heureka!

My problem was not getting the logging sorted out. I didn't think that
you could close the filehandle from each thread. But one is actually
required to, before the file is free to rename. I should have tried it
before.

Thanks for your input!
Thomas

Here a small example that works as intended:

use strict;
use warnings;

use threads;
use Thread::Queue;

use IO::File;

my $q = Thread::Queue->new();

sub worker {
my $fh;
while (1) {
my $fno = $q->dequeue();
if ( $fno ) {
print "worker: opening fileno:$fno\n";
$fh = IO::File->new_from_fd($fno, '>') or die $!;
$fh->autoflush(1);
print $fh "worker was here\n";
} else {
$fh->close();
}
}
}

threads->new(\&worker)->detach();

my $fname = 'test.log';
my $fh;

$fh = IO::File->new($fname, '>') or die $!;
$fh->autoflush(1);
print $fh "main was here\n";
$q->enqueue($fh->fileno());
sleep 1;

$q->enqueue(0);
sleep 1;
$fh->close();
rename($fname, "$fname.1") or die $!;

$fh = IO::File->new($fname, '>') or die $!;
$fh->autoflush(1);
print $fh "main was here\n";
$q->enqueue($fh->fileno());
sleep 1;


--
$/=$,,$_=<DATA>,s,(.*),$1,see;__END__
s,^(.*\043),,mg,@_=map{[split'']}split;{#>J~.>_an~>>e~......>r~
$_=$_[$%][$"];y,<~>^,-++-,?{$/=--$|?'"':#..u.t.^.o.P.r.>ha~.e..
'%',s,(.),\$$/$1=1,,$;=$_}:/\w/?{y,_, ,,#..>s^~ht<._..._..c....
print}:y,.,,||last,,,,,,$_=$;;eval,redo}#.....>.e.r^.>l^..>k^.-

 

[Thomas Kratz]

Just for the records:

I finally redesigned the logfile handling so that no rename is needed. I
just open a logfile with a timestamp in the first place. The first
thread that discovers that rotation is needed, opens a new file and
stores the new fileno in a shared var.
When the other threads see the fileno change they simply switch over to
the new file.

Now reading the latest logfile requires sorting the files by name or
date, but that is tolerable.

Thomas

--
$/=$,,$_=<DATA>,s,(.*),$1,see;__END__
s,^(.*\043),,mg,@_=map{[split'']}split;{#>J~.>_an~>>e~......>r~
$_=$_[$%][$"];y,<~>^,-++-,?{$/=--$|?'"':#..u.t.^.o.P.r.>ha~.e..
'%',s,(.),\$$/$1=1,,$;=$_}:/\w/?{y,_, ,,#..>s^~ht<._..._..c....
print}:y,.,,||last,,,,,,$_=$;;eval,redo}#.....>.e.r^.>l^..>k^.-