log4perl-devel

[log4perl-devel] multiple process, permissions and missing log output

[Martin E. <mar...@ea...>]

Hi,

I've been using Log::Log4perl for ages now in a set of CPAN modules we 
wrote and internally in a project here. All has been ok, it works well - 
thank you.

This issue is mostly related to Log::Dispatch::FileRotate|File but I am 
posting here since I may need advice on an alternative.

Our log files are getting pretty large and after seeing a post on this 
list I decided to try Log::Dispatch::FileRotate. It seemed to work fine 
at first. The logging is in a single module, this module is used in 
multiple places/processes under different uids and we have a single 
config file. One of the places is code running under modperl, the other 
is a daemon in perl.

The first problem was due to umasks and first to start (the daemon or 
modperl) created the file and the other couldn't open it. I tried

log4perl.appender.X1.umask = sub { 0000 }

but it would seem Log::Dispatch::FileRotate does not know umask. I then 
discovered "permissions" so did:

log4perl.appender.X1.permissions = sub { 0666 }

and this appears to work until another uid comes along in which case you 
get:

Cannot chmod /tmp/dbix.log to 438: Operation not permitted at 
/usr/lib/perl5/site_perl/5.8.8/Log/Dispatch/File.pm line 96

I don't get this as Log::Dispatch::File says:

"If the file does not already exist, the permissions that it should be 
created with."

so I presume this is a bug.

Am I wasting my time here? Would I be better going back to 
Log::Log4perl::Appender::File, using ".umask" and some external file 
rotator? Any recommendations?

Martin
-- 
Martin J. Evans
Easysoft Limited
http://www.easysoft.com

Re: [log4perl-devel] multiple process, permissions and missing log output

[Martin E. <mar...@ea...>]

I forgot to say when I used "permissions" to set 0666 with 
Log::Dispatch::FileRotate I only ssaw the log output from the first process.

Martin
-- 
Martin J. Evans
Easysoft Limited
http://www.easysoft.com

Martin Evans wrote:
> Hi,
> 
> I've been using Log::Log4perl for ages now in a set of CPAN modules we 
> wrote and internally in a project here. All has been ok, it works well - 
> thank you.
> 
> This issue is mostly related to Log::Dispatch::FileRotate|File but I am 
> posting here since I may need advice on an alternative.
> 
> Our log files are getting pretty large and after seeing a post on this 
> list I decided to try Log::Dispatch::FileRotate. It seemed to work fine 
> at first. The logging is in a single module, this module is used in 
> multiple places/processes under different uids and we have a single 
> config file. One of the places is code running under modperl, the other 
> is a daemon in perl.
> 
> The first problem was due to umasks and first to start (the daemon or 
> modperl) created the file and the other couldn't open it. I tried
> 
> log4perl.appender.X1.umask = sub { 0000 }
> 
> but it would seem Log::Dispatch::FileRotate does not know umask. I then 
> discovered "permissions" so did:
> 
> log4perl.appender.X1.permissions = sub { 0666 }
> 
> and this appears to work until another uid comes along in which case you 
> get:
> 
> Cannot chmod /tmp/dbix.log to 438: Operation not permitted at 
> /usr/lib/perl5/site_perl/5.8.8/Log/Dispatch/File.pm line 96
> 
> I don't get this as Log::Dispatch::File says:
> 
> "If the file does not already exist, the permissions that it should be 
> created with."
> 
> so I presume this is a bug.
> 
> Am I wasting my time here? Would I be better going back to 
> Log::Log4perl::Appender::File, using ".umask" and some external file 
> rotator? Any recommendations?
> 
> Martin

Re: [log4perl-devel] multiple process, permissions and missing log output

[Mike S. <m...@pe...>]

On Fri, 23 Feb 2007, Martin Evans wrote:

> I've been using Log::Log4perl for ages now in a set of CPAN modules we
> wrote and internally in a project here. All has been ok, it works well -
> thank you.

Excellent, thanks for sharing!

> but it would seem Log::Dispatch::FileRotate does not know umask.

That's a feature that I think needs to be added to
Log::Dispatch::FileRotate, similar to what
Log::Log4perl::Appender::File does. FileRotate's author has been known
to read this mailing list, so maybe it'll come soon :).

That being said, there's situations where processes are running as
different users, and all of them are writing to the same logfile. To
avoid permission problems in this scenario (think about what happens
when one user triggers the rotation), I've found it easiest to use an
external rotator instead. Log::Logperl supports this as well:

    http://log4perl.sourceforge.net/d/Log/Log4perl/FAQ.html#2d0d0

-- Mike

Mike Schilli
m...@pe...

> I then
> discovered "permissions" so did:
>
> log4perl.appender.X1.permissions = sub { 0666 }
>
> and this appears to work until another uid comes along in which case you
> get:
>
> Cannot chmod /tmp/dbix.log to 438: Operation not permitted at
> /usr/lib/perl5/site_perl/5.8.8/Log/Dispatch/File.pm line 96
>
> I don't get this as Log::Dispatch::File says:
>
> "If the file does not already exist, the permissions that it should be
> created with."
>
> so I presume this is a bug.
>
> Am I wasting my time here? Would I be better going back to
> Log::Log4perl::Appender::File, using ".umask" and some external file
> rotator? Any recommendations?
>
> Martin
> --
> Martin J. Evans
> Easysoft Limited
> http://www.easysoft.com
>
> -------------------------------------------------------------------------
> Take Surveys. Earn Cash. Influence the Future of IT
> Join SourceForge.net's Techsay panel and you'll get the chance to share your
> opinions on IT & business topics through brief surveys-and earn cash
> http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV
> _______________________________________________
> log4perl-devel mailing list
> log...@li...
> https://lists.sourceforge.net/lists/listinfo/log4perl-devel
>

Re: [log4perl-devel] multiple process, permissions and missing log output

[John O. <joh...@o-...>]

Hi Martin,

I can't help but I'll be watching for answers because I'm seeing a 
possibly related problem when using FileRotate initialised from a config 
file called by Apache.

I have a mod_perl app which is loaded during Apache startup (while 
Apache is root) which calls init_and_watch.
If I have my FileRotate log going at startup, only the server startup 
messages get written because the child processes run as 'apache' which 
doesn't have permission to write to the file create by Apache while it 
was root.
As a workaround I have it commented out in my log4perl config on startup 
then I un-comment it and init_and_watch catches the change and starts 
writing.

Obviously there are a few solutions but I've yet to choose a 'neat' 
solution.

John

Martin Evans wrote:
> Hi,
>
> I've been using Log::Log4perl for ages now in a set of CPAN modules we 
> wrote and internally in a project here. All has been ok, it works well - 
> thank you.
>
> This issue is mostly related to Log::Dispatch::FileRotate|File but I am 
> posting here since I may need advice on an alternative.
>
> Our log files are getting pretty large and after seeing a post on this 
> list I decided to try Log::Dispatch::FileRotate. It seemed to work fine 
> at first. The logging is in a single module, this module is used in 
> multiple places/processes under different uids and we have a single 
> config file. One of the places is code running under modperl, the other 
> is a daemon in perl.
>
> The first problem was due to umasks and first to start (the daemon or 
> modperl) created the file and the other couldn't open it. I tried
>
> log4perl.appender.X1.umask = sub { 0000 }
>
> but it would seem Log::Dispatch::FileRotate does not know umask. I then 
> discovered "permissions" so did:
>
> log4perl.appender.X1.permissions = sub { 0666 }
>
> and this appears to work until another uid comes along in which case you 
> get:
>
> Cannot chmod /tmp/dbix.log to 438: Operation not permitted at 
> /usr/lib/perl5/site_perl/5.8.8/Log/Dispatch/File.pm line 96
>
> I don't get this as Log::Dispatch::File says:
>
> "If the file does not already exist, the permissions that it should be 
> created with."
>
> so I presume this is a bug.
>
> Am I wasting my time here? Would I be better going back to 
> Log::Log4perl::Appender::File, using ".umask" and some external file 
> rotator? Any recommendations?
>
> Martin
>   

Re: [log4perl-devel] multiple process, permissions and missing log output

[Kevin M. G. <cp...@go...>]

You're right, there are a bunch of different solutions to the  
problem, varying in "neatness" according to taste.  Here are a couple  
possibilities:

Assuming you're in a unix-y  environment and starting log4perl though  
a PerlRequire'd script, you could

a) after Log4perl::init(), loop through the directory and fix up the  
permissions to what they should be

b) something like this should work:

#change effective uid while we open the log files
{ local $> = getpwnam('nobody');  #or whoever owns them
   Log::Log4perl::init()
}


On Feb 23, 2007, at 1:23 PM, John ORourke wrote:

> Hi Martin,
>
> I can't help but I'll be watching for answers because I'm seeing a
> possibly related problem when using FileRotate initialised from a  
> config
> file called by Apache.
>
> I have a mod_perl app which is loaded during Apache startup (while
> Apache is root) which calls init_and_watch.
> If I have my FileRotate log going at startup, only the server startup
> messages get written because the child processes run as 'apache' which
> doesn't have permission to write to the file create by Apache while it
> was root.
> As a workaround I have it commented out in my log4perl config on  
> startup
> then I un-comment it and init_and_watch catches the change and starts
> writing.
>
> Obviously there are a few solutions but I've yet to choose a 'neat'
> solution.
>
> John

Re: [log4perl-devel] multiple process, permissions and missing log output

[John O. <joh...@o-...>]

Kevin M. Goess wrote:
> You're right, there are a bunch of different solutions to the problem, 
> varying in "neatness" according to taste.  Here are a couple 
> possibilities:
>
> b) something like this should work:
>
> #change effective uid while we open the log files
> { local $> = getpwnam('nobody');  #or whoever owns them
>   Log::Log4perl::init()
> }

Now that's the kind of 'neat' I like!  I may have thought of that 
eventually but so rarely play with active process permissions/users that 
it would've taken me a long time, many thanks.

Of course, for added karma I'll replace 'nobody' with something that 
fetches the configured apache user from the config tree :)

John

Re: [log4perl-devel] multiple process, permissions and missing log output

[Martin E. <mar...@ea...>]

Thank you to all who replied to my post. Apologies if winding my 
responses into a single email offends anyone, I am only attempting to 
save some bandwidth and the moderator some time. A few comments:

I think Log::Dispatch::FileRotate is unusable in a multi-process 
environment if the processes run as different uids. The reason is that 
you need to specify the permissions so that all uids can write to the 
file but when Log::Dispatch::FileRotate starts it attempts to do a chmod 
even if the permissions are already correct. This breaks since the file 
belongs to uid1 so the second process in as uid2 cannot do that.

Kevin Goess' suggestions:

 > a) after Log4perl::init(), loop through the directory and fix up the
 > permissions to what they should be
 >
 > b) something like this should work:
 >
 > #change effective uid while we open the log files
 > { local $> = getpwnam('nobody');  #or whoever owns them
 >    Log::Log4perl::init()
 >}

(a) works only if you remove the "permission" setting from FileRotate 
but of course falls down later when the files are automatically rotated 
because they are created afresh and now as you have not got "permission" 
set umask comes in to it. As I don't know when the files are rotated I 
cannot reapply the permission fixup, and I don't want to set umask 
process wide.

(b) similar issue to (a) when the files are rotated but not practical in 
my circumstances as the process cannot change effective uid. However, I 
guess this will work fine for John ORourke as he has Apache starting as 
root, loading his module at startup then writing to it as a "single" 
different user.

Mike Schilli said:

 > That's a feature that I think needs to be added to
 > Log::Dispatch::FileRotate, similar to what
 > Log::Log4perl::Appender::File does. FileRotate's author has been known
 > to read this mailing list, so maybe it'll come soon  :) .

A long with, don't attempt to change the permissions if they are already OK.

 > That being said, there's situations where processes are running as
 > different users, and all of them are writing to the same logfile. To
 > avoid permission problems in this scenario (think about what happens
 > when one user triggers the rotation), I've found it easiest to use an
 > external rotator instead. Log::Logperl supports this as well:
 >
 >    http://log4perl.sourceforge.net/d/Log/Log4perl/FAQ.html#2d0d0

Thanks, I read that and have tried it - it works. I was just not that 
happy about

a) sending/capturing a signal since I cannot be 100% sure what other 
modules and signals are being used. In particular one of the processes 
uses DBD::Oracle which uses the Oracle instant client and hence Net8 and 
OCI libs and these catch all sorts of signals.

b) I cannot afford to lose a single msg but also cannot afford to set 
recreate_check_interval = 0.

For the moment I've gone back to Log4perl's File Appender and set the 
"umask" setting. This at least allows me to have a single entry in the 
log4perl config file for my module and let multiple processes use my 
module. For now I've given up on automatic file rotation and I guess 
I'll have to run multiple log4perl configs and have the app stop 
log4perl logging, rename the file and start log4perl again :-(

Thanks again to all who replied.

Martin
-- 
Martin J. Evans
Easysoft Limited
http://www.easysoft.com

Martin Evans wrote:
> Hi,
> 
> I've been using Log::Log4perl for ages now in a set of CPAN modules we 
> wrote and internally in a project here. All has been ok, it works well - 
> thank you.
> 
> This issue is mostly related to Log::Dispatch::FileRotate|File but I am 
> posting here since I may need advice on an alternative.
> 
> Our log files are getting pretty large and after seeing a post on this 
> list I decided to try Log::Dispatch::FileRotate. It seemed to work fine 
> at first. The logging is in a single module, this module is used in 
> multiple places/processes under different uids and we have a single 
> config file. One of the places is code running under modperl, the other 
> is a daemon in perl.
> 
> The first problem was due to umasks and first to start (the daemon or 
> modperl) created the file and the other couldn't open it. I tried
> 
> log4perl.appender.X1.umask = sub { 0000 }
> 
> but it would seem Log::Dispatch::FileRotate does not know umask. I then 
> discovered "permissions" so did:
> 
> log4perl.appender.X1.permissions = sub { 0666 }
> 
> and this appears to work until another uid comes along in which case you 
> get:
> 
> Cannot chmod /tmp/dbix.log to 438: Operation not permitted at 
> /usr/lib/perl5/site_perl/5.8.8/Log/Dispatch/File.pm line 96
> 
> I don't get this as Log::Dispatch::File says:
> 
> "If the file does not already exist, the permissions that it should be 
> created with."
> 
> so I presume this is a bug.
> 
> Am I wasting my time here? Would I be better going back to 
> Log::Log4perl::Appender::File, using ".umask" and some external file 
> rotator? Any recommendations?
> 
> Martin

Re: [log4perl-devel] multiple process, permissions and missing log output

[Kevin M. G. <cp...@go...>]

Martin Evans wrote:
> I think Log::Dispatch::FileRotate is unusable in a multi-process 
> environment if the processes run as different uids. 

That's certainly not impossible.  In a situation like that, I'd
seriously think about talking to a logging daemon like syslog,
syslog-ng, or even something like Spread.  Syslog is *really* flexible,
and you can use Log::Dispatch::Syslog.

But one more suggestion that might help, did you try doing "chmod g+s"
on the directory that holds the log files? Then all files created in
that directory will belong to the group-owner of the directory. This
seems to work for me:

#here's the script:

kgoess@desoto:~ $ cat /tmp/test.pl
use Log::Log4perl;

my $testfile =  '/tmp/testlog/foo.log';

Log::Log4perl->init(\<<EOT);
log4perl.category = INFO, FileAppndr1
log4perl.appender.FileAppndr1          = Log::Dispatch::FileRotate
log4perl.appender.FileAppndr1.filename = $testfile
log4perl.appender.FileAppndr1.mode     = append
log4perl.appender.FileAppndr1.layout   = Log::Log4perl::Layout::SimpleLayout
log4perl.appender.FileAppndr1.size = 1
log4perl.appender.FileAppndr1.max = 6
EOT

my $log = Log::Log4perl::get_logger("");

for (1..1000){
    $log->info("Shu-wa-chi!"x100);
}

#running it produces these files, note the ownership
#and permissions on the directory are g+w and group is me2
kgoess@desoto:~ $ perl /tmp/test.pl
kgoess@desoto:~/temp $ ls -lFtra /tmp/testlog/
total 19
drwxrwxrwt 17 root   root 3072 Feb 28 09:12 ../
-rw-rw-r--  1 kgoess me2  1108 Feb 28 09:12 foo.log.6
-rw-rw-r--  1 kgoess me2  1108 Feb 28 09:12 foo.log.5
-rw-rw-r--  1 kgoess me2  1108 Feb 28 09:12 foo.log.4
-rw-rw-r--  1 kgoess me2  1108 Feb 28 09:12 foo.log.3
-rw-rw-r--  1 kgoess me2  1108 Feb 28 09:12 foo.log.2
-rw-rw-r--  1 kgoess me2  1108 Feb 28 09:12 foo.log.1
-rw-rw-r--  1 kgoess me2  1108 Feb 28 09:12 foo.log
drwxrwsr-x  2 kgoess me2  1024 Feb 28 09:12 ./

#be a different user
kgoess@desoto:~/temp $ sudo su - me2
Password:
[me2@desoto ~]$

#and run it as me2
[me2@desoto ~]$ perl /tmp/test.pl
[me2@desoto ~]$ ls -lFtra /tmp/testlog/
total 19
drwxrwxrwt 17 root   root 3072 Feb 28 09:12 ../
-rw-rw-r--  1 me2    me2  1108 Feb 28 09:15 foo.log.6
-rw-rw-r--  1 me2    me2  1108 Feb 28 09:15 foo.log.5
-rw-rw-r--  1 me2    me2  1108 Feb 28 09:15 foo.log.4
-rw-rw-r--  1 me2    me2  1108 Feb 28 09:15 foo.log.3
-rw-rw-r--  1 me2    me2  1108 Feb 28 09:15 foo.log.2
-rw-rw-r--  1 me2    me2  1108 Feb 28 09:15 foo.log.1
-rw-rw-r--  1 me2    me2  1108 Feb 28 09:15 foo.log
drwxrwsr-x  2 kgoess me2  1024 Feb 28 09:15 ./


The default umask on my machine is 0002, so files are group-writeable by
default.

-- 
Happy Trails . . .

Kevin M. Goess