log4perl-devel — Ongoing log4perl development

[log4perl-devel] SV (Scalar Variable) error in log4perl

[Gil V. <gil...@po...>]

Kevin, We're using log4perl in the Perl Object Environment (POE) running on
Perl 5.8.7 on Red Hat Linux servers. POE is a state machine in a
multi-tasking environment. (see poe.perl.org). Unfortunately, the error is
random, but we are narrowing it down.

I updated to log4perl 1.04 and the problem persists, so I commented out line
217 below (it's line 239 in 1.04). Now my application is dying on "if
(Log::Log4perl::Level::isGreaterOrEqual($level..." with the same
unreferenced SV error as before.

 foreach my $levelname (keys %priority){

        if (Log::Log4perl::Level::isGreaterOrEqual($level,
                                                   $priority{$levelname}
                                                   )) {
            print "  ($priority{$levelname} <= $level)\n"
                  if _INTERNAL_DEBUG;
            $self->{$levelname}      = $coderef;
            $self->{"is_$levelname"} = generate_is_xxx_coderef("1");
            #$self->{"is_$levelname"} = sub { 1 };
        }else{
            print "  ($priority{$levelname} > $level)\n" if _INTERNAL_DEBUG;
            $self->{$levelname}      = $noop;
            $self->{"is_$levelname"} = generate_is_xxx_coderef("0");
            #$self->{"is_$levelname"} = sub { 0 };
        }
=cut
        print("  Setting [$self] $self->{category}.$levelname to ",
              ($self->{$levelname} == $noop ? "NOOP" :
              ("Coderef [$coderef]: " . scalar @appenders . " appenders")),
              "\n") if _INTERNAL_DEBUG;
=cut
    }	


I'm not farmilar with Logger.pm code, but it seems that "sub
set_output_methods" is being called by init_and_watch, so I'm updating all
calls to logger to use the standard init and avoid the "init_and_watch".

#use Log::Log4perl;
Log::Log4perl->init_and_watch('/usr/local/xray/log4perl.conf',600); my $log
= Log::Log4perl->get_logger('Compiler');
use Log::Log4perl; Log::Log4perl->init('/usr/local/xray/log4perl.conf'); my
$log = Log::Log4perl->get_logger('Compiler');

Perhaps the state machine doesn't play well with the dynamic component of
init_and_watch, which obviously has to check to see if a file has changed
every so often. In a sense "init_and_watch" is kind of a state machine that
is triggered by a file change. Since POE is a state machine too, there could
be a clash?

I would appreciate any other suggestions to solve this problem.

Gil...@Po...
Position Research, Inc.
Search engine results by research
tel: (760) 480-8291 fax: (760) 480-8271
www.PositionResearch.com





-----Original Message-----
From: Kevin M. Goess [mailto:ke...@go...] 
Sent: Wednesday, April 12, 2006 9:10 AM
To: Gil Vidals
Cc: log...@li...
Subject: Re: [log4perl-devel] SV (Scalar Variable) error in log4perl

Gil Vidals wrote:
> We have four servers running an application which has incorporated 
> log4perl verion 1.02. We are running into a peculiar error, which 
> crashes our application;
>  
> Attempt to free unreferenced scalar: SV 0x9edad98 at 
> /usr/local/lib/perl5/site_perl/5.8.7/Log/Log4perl/Logger.pm line 217.
> 
> Line 217 from Logger.pm
>  print("  Setting [$self] $self->{category}.$levelname to ",
>               ($self->{$levelname} == $noop ? "NOOP" :
>               ("Coderef [$coderef]: " . scalar @appenders . "
appenders")),
>               "\n") if _INTERNAL_DEBUG;

Gil, this could shouldn't even get compiled, much less run, unless you've
turned _INTERNAL_DEBUG on.  Did you turn it on?  Does the error still happen
if you turn it off?  Does the error still happen if you remove that line of
code?

When you say servers, are you talking about standalone perl applications or
web servers or what?  If they're web servers, are they running with
mod_perl, Catalyst, Mason, or what?  Can you give us more details on the
what this is running in?

What sort of conditions lead to the error? Can you reproduce it at will? 
  Or is it intermittent and seemingly random?

Lastly, but best of all, can you take everything out of the application
except for the absolute minimum amount of code required to produce the
error?  And then could we see the little bit of code that's left?

Re: [log4perl-devel] SV (Scalar Variable) error in log4perl

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

Gil Vidals wrote:
> We have four servers running an application which has incorporated log4perl
> verion 1.02. We are running into a peculiar error, which crashes our
> application;
>  
> Attempt to free unreferenced scalar: SV 0x9edad98 at
> /usr/local/lib/perl5/site_perl/5.8.7/Log/Log4perl/Logger.pm line 217.
> 
> Line 217 from Logger.pm
>  print("  Setting [$self] $self->{category}.$levelname to ",
>               ($self->{$levelname} == $noop ? "NOOP" :
>               ("Coderef [$coderef]: " . scalar @appenders . " appenders")),
>               "\n") if _INTERNAL_DEBUG;

Gil, this could shouldn't even get compiled, much less run, unless 
you've turned _INTERNAL_DEBUG on.  Did you turn it on?  Does the error 
still happen if you turn it off?  Does the error still happen if you 
remove that line of code?

When you say servers, are you talking about standalone perl applications 
or web servers or what?  If they're web servers, are they running with 
mod_perl, Catalyst, Mason, or what?  Can you give us more details on the 
what this is running in?

What sort of conditions lead to the error? Can you reproduce it at will? 
  Or is it intermittent and seemingly random?

Lastly, but best of all, can you take everything out of the application 
except for the absolute minimum amount of code required to produce the 
error?  And then could we see the little bit of code that's left?

[log4perl-devel] SV (Scalar Variable) error in log4perl

[Gil V. <gil...@po...>]

We have four servers running an application which has incorporated log4perl
verion 1.02. We are running into a peculiar error, which crashes our
application;
 
Attempt to free unreferenced scalar: SV 0x9edad98 at
/usr/local/lib/perl5/site_perl/5.8.7/Log/Log4perl/Logger.pm line 217.

Line 217 from Logger.pm
 print("  Setting [$self] $self->{category}.$levelname to ",
              ($self->{$levelname} == $noop ? "NOOP" :
              ("Coderef [$coderef]: " . scalar @appenders . " appenders")),
              "\n") if _INTERNAL_DEBUG;

It's always line 217 that is causing the problem. Doing some googling, I
found what causes the SV error, but have no idea how to fix it:

CAUSE OF ERROR according to this source from perl bugs:
attempt to free unreferenced scalar (W internal) Perl went to decrement the
reference count of a scalar to see if it would go to 0, and discovered that
it had already gone to 0
earlier, and should have been freed, and in fact, probably was freed.
This could indicate that SvREFCNT_dec() was called too many times, or
that SvREFCNT_inc() was called too few times, or that the SV was
mortalized when it shouldn't have been, or that memory has been
corrupted.

How can I prevent log4perl from causing this problem and crashing our
application?


Gil...@Po...
Position Research, Inc.
Search engine results by research
tel: (760) 480-8291 fax: (760) 480-8271
www.PositionResearch.com

Re: [log4perl-devel] Log4perl Appender runs into problems when Devel::SmallProf, Devel::DProf are used

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

On Thu, 23 Mar 2006, Sripathi Raj wrote:

>  When I used Devel::DProf or Devel::SmallProf, my script crashes.
> ERROR : Got a die signal The following parameter was passed in the call to
> Log::Dispatch::Output::log but was not listed in the validation options:
> log4p_level
>  at C:/Perl/site/lib/Log/Log4perl/Appender.pm line 189

    # test.pl
    use strict;
    use Log::Log4perl qw(:easy);

    Log::Log4perl->easy_init($DEBUG);
    DEBUG "foo";

and then call

    $ perl -d:DProf t
    2006/03/24 08:59:40 foo

    $ ls -l tmon.out
    -rw-rw-r--  10781 Mar 24 09:01 tmon.out

Works ok for me - could this be a general problem with DProf on your
platform?

-- Mike

Mike Schilli
m...@pe...

> $ = main::clean_up called from file `extract.pl' line 472
> $ = main::die_handler called from file `C:/Perl/lib/Carp.pm' line 269
> $ = Carp::croak() called from file `C:/Perl/site/lib/Log/Dispatch/Output.pm'
> line 32
> $ = Log::Dispatch::Output::log called from file
> `C:/Perl/site/lib/Log/Log4perl/Appender.pm' line 189
> $ = Log::Log4perl::Appender::log called from file `(eval 65)' line 41
> $ = Log::Log4perl::Logger::__ANON__() called from file
> `C:/Perl/site/lib/Log/Log4perl/Logger.pm' line 648
> $ = Log::Log4perl::Logger::log called from file
> `D:/srctree/reporting/src/tools/lds/extraction/../commonlib/Logger.pm' line
> 130
> $ = Logger::_log called from file
> `D:/srctree/reporting/src/tools/lds/extraction/../commonlib/Logger.pm' line
> 160
>
> I'm not sure where this is a bug or where I should find help.  Please let me
> know where the problem lies.
>
> Thanks,
>
> Raj
>

Re: [log4perl-devel] Log4perl Appender runs into problems when Devel::SmallProf, Devel::DProf are used

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

On Thu, 23 Mar 2006, Sripathi Raj wrote:

>  When I used Devel::DProf or Devel::SmallProf, my script crashes.

Can you provide a sample script?

-- Mike

Mike Schilli
m...@pe...

>
> ERROR : Got a die signal The following parameter was passed in the call to
> Log::Dispatch::Output::log but was not listed in the validation options:
> log4p_level
>  at C:/Perl/site/lib/Log/Log4perl/Appender.pm line 189
>
>
> $ = main::clean_up called from file `extract.pl' line 472
> $ = main::die_handler called from file `C:/Perl/lib/Carp.pm' line 269
> $ = Carp::croak() called from file `C:/Perl/site/lib/Log/Dispatch/Output.pm'
> line 32
> $ = Log::Dispatch::Output::log called from file
> `C:/Perl/site/lib/Log/Log4perl/Appender.pm' line 189
> $ = Log::Log4perl::Appender::log called from file `(eval 65)' line 41
> $ = Log::Log4perl::Logger::__ANON__() called from file
> `C:/Perl/site/lib/Log/Log4perl/Logger.pm' line 648
> $ = Log::Log4perl::Logger::log called from file
> `D:/srctree/reporting/src/tools/lds/extraction/../commonlib/Logger.pm' line
> 130
> $ = Logger::_log called from file
> `D:/srctree/reporting/src/tools/lds/extraction/../commonlib/Logger.pm' line
> 160
>
> I'm not sure where this is a bug or where I should find help.  Please let me
> know where the problem lies.
>
> Thanks,
>
> Raj
>

[log4perl-devel] Log4perl Appender runs into problems when Devel::SmallProf, Devel::DProf are used

[Sripathi R. <shr...@gm...>]

Hi,

 When I used Devel::DProf or Devel::SmallProf, my script crashes.

ERROR : Got a die signal The following parameter was passed in the call to
Log::Dispatch::Output::log but was not listed in the validation options:
log4p_level
 at C:/Perl/site/lib/Log/Log4perl/Appender.pm line 189


$ =3D main::clean_up called from file `extract.pl' line 472
$ =3D main::die_handler called from file `C:/Perl/lib/Carp.pm' line 269
$ =3D Carp::croak() called from file `C:/Perl/site/lib/Log/Dispatch/Output.=
pm'
line 32
$ =3D Log::Dispatch::Output::log called from file
`C:/Perl/site/lib/Log/Log4perl/Appender.pm' line 189
$ =3D Log::Log4perl::Appender::log called from file `(eval 65)' line 41
$ =3D Log::Log4perl::Logger::__ANON__() called from file
`C:/Perl/site/lib/Log/Log4perl/Logger.pm' line 648
$ =3D Log::Log4perl::Logger::log called from file
`D:/srctree/reporting/src/tools/lds/extraction/../commonlib/Logger.pm' line
130
$ =3D Logger::_log called from file
`D:/srctree/reporting/src/tools/lds/extraction/../commonlib/Logger.pm' line
160

I'm not sure where this is a bug or where I should find help.  Please let m=
e
know where the problem lies.

Thanks,

Raj

Re: [log4perl-devel] open files when running init_and_watch

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

> The standard Log::Log4perl::Appender::File appender in Log4perl opens
> its files at init() because it's usually not a problem having a handful
> of files open, even if they're not written to. Alternatively, it could
> open the files at log() time, which would impose a small penalty on
> the appenders with every log().

There's also the matter of reliability.  It would be pretty annoying to
have your program run for an hour, die of a fatal error, and then have
the error message vanish into the ether because the program didn't have
permissions to write to the log file.

By opening the files at the beginning, log4perl ensures that it will
actually be able to write to each file if it every needs to.


-- 
Happy Trails . . .

Kevin M. Goess

Re: [log4perl-devel] open files when running init_and_watch

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

On Mon, 6 Mar 2006, Martin J. Evans wrote:

> I thought calling get_logger would actually open the file
> and init_and_watch would simply parse the conf file, check it
> was OK and watch the conf file.
>
> If I'd called get_logger(x::y::z) then I could understand
> the log file associated with x::y::z and x::y being opened
> but If I call get_logger(x::y) then why would the log
> file associated with x::y::z be opened.

Loggers and appenders are orthogonal concepts in Log4perl. If you get
a logger, nothing happens with the appender. Only when the logger decides
to fire, the appender comes into play (according to the configuration).

The standard Log::Log4perl::Appender::File appender in Log4perl opens
its files at init() because it's usually not a problem having a handful
of files open, even if they're not written to. Alternatively, it could
open the files at log() time, which would impose a small penalty on
the appenders with every log().

> > I wonder how it is possible to run out of file descriptors with only
> > three open files per process, though. Are you running hundreds of
> > daemons simultaneously?
>
> Perhaps I should have been clearer. I am running out of file descriptors
> (but within a single process, not system wide) and it was that
> which prompted me to look at what files I've got open. By the
> time you add a file descriptor for the perl binary and every module
> you've "use"ed, then every shared object you need it amounts to quite a
> bit (easily more than 64).

64 file descriptors per process sounds really low. On my linux box at home it
is

    $ ulimit -n
    1024

> I don't want files created and opened which I'm not going to log to.
> In my mind if I've not called get_logger("x::y") then I'm
> not going to log to the file that is defined by x::y (unless I've
> called get_logger(x::y::z). I will look
> at Appender but it seems to get ONLY the files opened which I'm
> actually going to use in the current process I need a separate
> conf file for each process which only defines the appenders
> I intend using this time around. If that is the way it is
> - fair enough - I can live with that.

If you really need to save those 3 file descriptors, I'd recommend writing
your own file appender that opens the file at log() time, on demand. It's really
a 20-liner.

-- Mike

Mike Schilli
m...@pe...

> As I said, perhaps I've misunderstood appenders and the conf file
> but I'm "currently" at a loss to understand why a file is created
> and opened when there is no likelihood of anything being written
> to it. Perhaps you could put me right on any misunderstanding
> I have.
>
> Martin
>
> >>This may
> >>be my misunderstanding of the way log4perl works but it is
> >>undesirable for me so I wondered if either a) these log files should
> >>not be open or b) if my conf file was wrong. Given:
> >>
> >>log4perl.logger.Server = WARN
> >>log4perl.logger.Server.Markets.Close = DEBUG, A1
> >>log4perl.appender.A1=Log::Dispatch::File
> >>log4perl.appender.A1.filename=/tmp/markets_close.log
> >>log4perl.appender.A1.mode=append
> >>log4perl.appender.A1.layout=Log::Log4perl::Layout::PatternLayout
> >>log4perl.appender.A1.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
> >>log4perl.appender.A1.Threshold=INFO
> >>
> >>log4perl.logger.Server.CGI.Post = DEBUG, A3
> >>log4perl.appender.A3=Log::Dispatch::File
> >>log4perl.appender.A3.filename=/tmp/cgi_post.log
> >>log4perl.appender.A3.mode=append
> >>log4perl.appender.A3.layout=Log::Log4perl::Layout::PatternLayout
> >>log4perl.appender.A3.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
> >>
> >>log4perl.logger.Server.Queued = DEBUG, A5
> >>log4perl.appender.A5=Log::Dispatch::File
> >>log4perl.appender.A5.filename=/tmp/queued.log
> >>log4perl.appender.A5.mode=append
> >>log4perl.appender.A5.layout=Log::Log4perl::Layout::PatternLayout
> >>log4perl.appender.A5.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
> >>
> >>why are A1.filename, A3.filename and A5.filename all created and open when I
> >>run the above Perl. I would have expected A5.filename to be opened when I did
> >>get_logger("Server::Queued") but no files other than log4.conf to be open when
> >>all I've done is init_and_watch.
> >>
> >>Any ideas.
> >>
> >>Martin
>
>
>
> -------------------------------------------------------
> This SF.Net email is sponsored by xPML, a groundbreaking scripting language
> that extends applications into web and mobile media. Attend the live webcast
> and join the prime developer group breaking into this new coding territory!
> http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642
> _______________________________________________
> log4perl-devel mailing list
> log...@li...
> https://lists.sourceforge.net/lists/listinfo/log4perl-devel
>

Re: [log4perl-devel] open files when running init_and_watch

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

Mike,

Thanks for the reply
see below:

Mike Schilli wrote:
> On Fri, 3 Mar 2006, Martin J. Evans wrote:
> 
> 
>>I was surprised to see every log file named in my log4.conf file
>>under "appender.XX.filename" had been created and was open.
> 
> 
> That's exactly how Log::Log4perl's file appender works. It opens all
> log files at init(), not when you obtain a logger.

why?

Perhaps this highlights my misunderstanding then.

I don't understand why it does this.

I thought calling get_logger would actually open the file
and init_and_watch would simply parse the conf file, check it
was OK and watch the conf file.

If I'd called get_logger(x::y::z) then I could understand
the log file associated with x::y::z and x::y being opened
but If I call get_logger(x::y) then why would the log
file associated with x::y::z be opened.

> I wonder how it is possible to run out of file descriptors with only
> three open files per process, though. Are you running hundreds of
> daemons simultaneously?

Perhaps I should have been clearer. I am running out of file descriptors
(but within a single process, not system wide) and it was that
which prompted me to look at what files I've got open. By the
time you add a file descriptor for the perl binary and every module
you've "use"ed, then every shared object you need it amounts to quite a 
bit (easily more than 64).

I did not expect log4perl to have created and opened the files I have 
not called get_logger for (or at least those below it). I wasn't
saying the 3 that log4perl open are the one and only cause of my
problem but they do include 2 I did not expect to be created
and opened.

> If opening the log files at startup imposes a problem, you could write
> your own log file appender that opens files at log() instead. If you
> look at the implementation of Log::Log4perl::Appender::File you'll see
> that it's actually quite simple.

I don't want files created and opened which I'm not going to log to.
In my mind if I've not called get_logger("x::y") then I'm
not going to log to the file that is defined by x::y (unless I've
called get_logger(x::y::z). I will look
at Appender but it seems to get ONLY the files opened which I'm
actually going to use in the current process I need a separate
conf file for each process which only defines the appenders
I intend using this time around. If that is the way it is
- fair enough - I can live with that.

As I said, perhaps I've misunderstood appenders and the conf file
but I'm "currently" at a loss to understand why a file is created
and opened when there is no likelihood of anything being written
to it. Perhaps you could put me right on any misunderstanding
I have.

Martin

>>This may
>>be my misunderstanding of the way log4perl works but it is
>>undesirable for me so I wondered if either a) these log files should
>>not be open or b) if my conf file was wrong. Given:
>>
>>log4perl.logger.Server = WARN
>>log4perl.logger.Server.Markets.Close = DEBUG, A1
>>log4perl.appender.A1=Log::Dispatch::File
>>log4perl.appender.A1.filename=/tmp/markets_close.log
>>log4perl.appender.A1.mode=append
>>log4perl.appender.A1.layout=Log::Log4perl::Layout::PatternLayout
>>log4perl.appender.A1.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
>>log4perl.appender.A1.Threshold=INFO
>>
>>log4perl.logger.Server.CGI.Post = DEBUG, A3
>>log4perl.appender.A3=Log::Dispatch::File
>>log4perl.appender.A3.filename=/tmp/cgi_post.log
>>log4perl.appender.A3.mode=append
>>log4perl.appender.A3.layout=Log::Log4perl::Layout::PatternLayout
>>log4perl.appender.A3.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
>>
>>log4perl.logger.Server.Queued = DEBUG, A5
>>log4perl.appender.A5=Log::Dispatch::File
>>log4perl.appender.A5.filename=/tmp/queued.log
>>log4perl.appender.A5.mode=append
>>log4perl.appender.A5.layout=Log::Log4perl::Layout::PatternLayout
>>log4perl.appender.A5.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
>>
>>why are A1.filename, A3.filename and A5.filename all created and open when I
>>run the above Perl. I would have expected A5.filename to be opened when I did
>>get_logger("Server::Queued") but no files other than log4.conf to be open when
>>all I've done is init_and_watch.
>>
>>Any ideas.
>>
>>Martin

Re: [log4perl-devel] open files when running init_and_watch

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

On Fri, 3 Mar 2006, Martin J. Evans wrote:

> I was surprised to see every log file named in my log4.conf file
> under "appender.XX.filename" had been created and was open.

That's exactly how Log::Log4perl's file appender works. It opens all
log files at init(), not when you obtain a logger.

I wonder how it is possible to run out of file descriptors with only
three open files per process, though. Are you running hundreds of
daemons simultaneously?

If opening the log files at startup imposes a problem, you could write
your own log file appender that opens files at log() instead. If you
look at the implementation of Log::Log4perl::Appender::File you'll see
that it's actually quite simple.

-- Mike

Mike Schilli
m...@pe...

> This may
> be my misunderstanding of the way log4perl works but it is
> undesirable for me so I wondered if either a) these log files should
> not be open or b) if my conf file was wrong. Given:
>
> log4perl.logger.Server = WARN
> log4perl.logger.Server.Markets.Close = DEBUG, A1
> log4perl.appender.A1=Log::Dispatch::File
> log4perl.appender.A1.filename=/tmp/markets_close.log
> log4perl.appender.A1.mode=append
> log4perl.appender.A1.layout=Log::Log4perl::Layout::PatternLayout
> log4perl.appender.A1.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
> log4perl.appender.A1.Threshold=INFO
>
> log4perl.logger.Server.CGI.Post = DEBUG, A3
> log4perl.appender.A3=Log::Dispatch::File
> log4perl.appender.A3.filename=/tmp/cgi_post.log
> log4perl.appender.A3.mode=append
> log4perl.appender.A3.layout=Log::Log4perl::Layout::PatternLayout
> log4perl.appender.A3.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
>
> log4perl.logger.Server.Queued = DEBUG, A5
> log4perl.appender.A5=Log::Dispatch::File
> log4perl.appender.A5.filename=/tmp/queued.log
> log4perl.appender.A5.mode=append
> log4perl.appender.A5.layout=Log::Log4perl::Layout::PatternLayout
> log4perl.appender.A5.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
>
> why are A1.filename, A3.filename and A5.filename all created and open when I
> run the above Perl. I would have expected A5.filename to be opened when I did
> get_logger("Server::Queued") but no files other than log4.conf to be open when
> all I've done is init_and_watch.
>
> Any ideas.
>
> Martin
> --
> Martin J. Evans
> Easysoft Ltd, UK
> http://www.easysoft.com
>
>
>
> -------------------------------------------------------
> This SF.Net email is sponsored by xPML, a groundbreaking scripting language
> that extends applications into web and mobile media. Attend the live webcast
> and join the prime developer group breaking into this new coding territory!
> http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642
> _______________________________________________
> log4perl-devel mailing list
> log...@li...
> https://lists.sourceforge.net/lists/listinfo/log4perl-devel
>

[log4perl-devel] open files when running init_and_watch

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

Hi,

I am using log4perl extensively in a number of daemon processes and running out
of file descriptors. To investigate I ran:

perl -e 'use Log::Log4perl qw(get_logger
:levels);Log::Log4perl->init_and_watch("/etc/log4.conf", 10);sleep 600;'

and then ran lsof to see what open files there were in this process. I was
surprised to see every log file named in my log4.conf file under
"appender.XX.filename" had been created and was open. This may be my
misunderstanding of the way log4perl works but it is undesirable for me so I
wondered if either a) these log files should not be open or b) if my conf file
was wrong. Given:

log4perl.logger.Server = WARN
log4perl.logger.Server.Markets.Close = DEBUG, A1
log4perl.appender.A1=Log::Dispatch::File
log4perl.appender.A1.filename=/tmp/markets_close.log
log4perl.appender.A1.mode=append
log4perl.appender.A1.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.A1.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n
log4perl.appender.A1.Threshold=INFO

log4perl.logger.Server.CGI.Post = DEBUG, A3
log4perl.appender.A3=Log::Dispatch::File
log4perl.appender.A3.filename=/tmp/cgi_post.log
log4perl.appender.A3.mode=append
log4perl.appender.A3.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.A3.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n

log4perl.logger.Server.Queued = DEBUG, A5
log4perl.appender.A5=Log::Dispatch::File
log4perl.appender.A5.filename=/tmp/queued.log
log4perl.appender.A5.mode=append
log4perl.appender.A5.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.A5.layout.ConversionPattern=%d %p> %F{1}:%L %M - %m%n

why are A1.filename, A3.filename and A5.filename all created and open when I
run the above Perl. I would have expected A5.filename to be opened when I did
get_logger("Server::Queued") but no files other than log4.conf to be open when
all I've done is init_and_watch.

Any ideas.

Martin
--
Martin J. Evans
Easysoft Ltd, UK
http://www.easysoft.com

Re: [log4perl-devel] log file permissions issues, pls advise

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

On Sun, 26 Feb 2006, Hugh Esco wrote:

> Mike Schilli:
> May I be so bold as to suggest the addition
> of this suggestion below in the perldoc?

You could be even bolder and write up a FAQ, which could then be
included in Log4perl's FAQ page!

-- Mike

Mike Schilli
m...@pe...

>
> Thank you Kevin.  That is exactly
> what I was looking for.
>
> -- Hugh
>
> On Fri, 24 Feb 2006 09:39:09 -0800
> Kevin Goess <cp...@go...> wrote:
>
> > Hugh Esco wrote:
> > > That reminder of the need for apache to be able to write to the log's parent directory
> > > got me moving again.  I put the log in /tmp and everything started working.
> > >
> > > And as a security precaution, I'm wondering if it is possible to move this log out of
> > > /tmp, without risking some other file system heirarchy to the risks of letting apache write to it?
> > > Any ideas on this one?
> >
> > I would not recommend writing log files to /tmp.  Here's the common
> > solution:
> >
> > - create a directory in /var/log/, for instance /var/log/escosapp/
> >
> >     $ mkdir /var/log/escosapp
> >
> > - make it owned by the www-data user and only writeable by that user:
> >
> >     $ chown www-data /var/log/escosapp/
> >     $ chmod 0755 /var/log/escosapp/
> >
> > The reason you can't write to /var/log/apache-ssl/ but apache can is
> > that apache starts its logging process under the root user before it
> > starts forking children and changing to the less-priviledged user.  Your
> >  log4perl logs are written from the less-priviledged child processes
> > running as the www-data user, so they can't write to the
> > root-writeable-only apache log directory.
> >
> >
> > --
> > Happy Trails . . .
> >
> > Kevin M. Goess
> >
> >
> > -------------------------------------------------------
> > This SF.Net email is sponsored by xPML, a groundbreaking scripting language
> > that extends applications into web and mobile media. Attend the live webcast
> > and join the prime developer group breaking into this new coding territory!
> > http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642
> > _______________________________________________
> > log4perl-devel mailing list
> > log...@li...
> > https://lists.sourceforge.net/lists/listinfo/log4perl-devel
> >
> >
>
>
> --
> --
> Hugh Esco
> 250-352-9361
> he...@re...
> RCK Computer Services
> http://reclaimedcomputers.ca/
>
>
>
> -------------------------------------------------------
> This SF.Net email is sponsored by xPML, a groundbreaking scripting language
> that extends applications into web and mobile media. Attend the live webcast
> and join the prime developer group breaking into this new coding territory!
> http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642
> _______________________________________________
> log4perl-devel mailing list
> log...@li...
> https://lists.sourceforge.net/lists/listinfo/log4perl-devel
>

Re: [log4perl-devel] log file permissions issues, pls advise

[Hugh E. <he...@re...>]

Mike Schilli:  

May I be so bold as to suggest the addition 
of this suggestion below in the perldoc?

Thank you Kevin.  That is exactly 
what I was looking for.  

-- Hugh

On Fri, 24 Feb 2006 09:39:09 -0800
Kevin Goess <cp...@go...> wrote:

> Hugh Esco wrote:
> > That reminder of the need for apache to be able to write to the log's parent directory 
> > got me moving again.  I put the log in /tmp and everything started working.  
> > 
> > And as a security precaution, I'm wondering if it is possible to move this log out of 
> > /tmp, without risking some other file system heirarchy to the risks of letting apache write to it?  
> > Any ideas on this one?  
> 
> I would not recommend writing log files to /tmp.  Here's the common
> solution:
> 
> - create a directory in /var/log/, for instance /var/log/escosapp/
> 
> 	$ mkdir /var/log/escosapp
> 
> - make it owned by the www-data user and only writeable by that user:
> 
> 	$ chown www-data /var/log/escosapp/
> 	$ chmod 0755 /var/log/escosapp/
> 
> The reason you can't write to /var/log/apache-ssl/ but apache can is
> that apache starts its logging process under the root user before it
> starts forking children and changing to the less-priviledged user.  Your
>  log4perl logs are written from the less-priviledged child processes
> running as the www-data user, so they can't write to the
> root-writeable-only apache log directory.
> 
> 
> -- 
> Happy Trails . . .
> 
> Kevin M. Goess
> 
> 
> -------------------------------------------------------
> This SF.Net email is sponsored by xPML, a groundbreaking scripting language
> that extends applications into web and mobile media. Attend the live webcast
> and join the prime developer group breaking into this new coding territory!
> http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642
> _______________________________________________
> log4perl-devel mailing list
> log...@li...
> https://lists.sourceforge.net/lists/listinfo/log4perl-devel
> 
> 


-- 
--
Hugh Esco 
250-352-9361
he...@re...
RCK Computer Services 
http://reclaimedcomputers.ca/

[log4perl-devel] Log-Log4perl-1.04 released

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

Hi all,

just submitted the 1.04 maintenance release to log4perl.sf.net, with
the following changes:

1.04 2006/02/26
    *  (ms) If a conversion pattern was specified twice in a config
            file, the output was "ARRAY(0x804da00)" (bug reported by
            Bill Mason). Now, gobbling up property configurator values
            into an array is limited to appender properties and
            excludes the conversion pattern.
    *  (ms) Multiple calls to import (usually happens if 'use L4p' gets
            called twice within the same namespace) caused nasty warnings,
            bug reported by Greg Olszewski. Fixed by ignoring subsequent
            calls from the same package to import().
    *  (ms) Changed rendering of logdie/warn/cluck/croak/... messages
            to fix a bug reported by Martin J. Evans.
    *  (ms) Added a L4p::Appender::String appender to handle the
            rendering internally.
    *  (ms) Documentation patch by Matisse Enzer on increased/
            decreased log levels.
    *  (ms) Fixed stack trace level of logcarp()
    *  (ms) Carl Franks reported that the test suite failed on WinXP SP2
            because of a hardcoded /tmp - fixed by File::Spec->tempdir().
    *  (ms) Added reconnect_attempts and reconnect_sleep parameters to
            DBI appender.

If all goes well, it'll be on CPAN in a couple of days. Enjoy!

-- Mike

Mike Schilli
m...@pe...

Re: [log4perl-devel] log file permissions issues, pls advise

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

Hugh Esco wrote:
> That reminder of the need for apache to be able to write to the log's parent directory 
> got me moving again.  I put the log in /tmp and everything started working.  
> 
> And as a security precaution, I'm wondering if it is possible to move this log out of 
> /tmp, without risking some other file system heirarchy to the risks of letting apache write to it?  
> Any ideas on this one?  

I would not recommend writing log files to /tmp.  Here's the common
solution:

- create a directory in /var/log/, for instance /var/log/escosapp/

	$ mkdir /var/log/escosapp

- make it owned by the www-data user and only writeable by that user:

	$ chown www-data /var/log/escosapp/
	$ chmod 0755 /var/log/escosapp/

The reason you can't write to /var/log/apache-ssl/ but apache can is
that apache starts its logging process under the root user before it
starts forking children and changing to the less-priviledged user.  Your
 log4perl logs are written from the less-priviledged child processes
running as the www-data user, so they can't write to the
root-writeable-only apache log directory.


-- 
Happy Trails . . .

Kevin M. Goess

Re: [log4perl-devel] log file permissions issues, pls advise

[Hugh E. <he...@re...>]

Thank you sir.  That worked and I just sang your praises as a "responsive" package maintainer on perlmonks.org/.  

That reminder of the need for apache to be able to write to the log's parent directory got me moving again.  I put the log in /tmp and everything started working.  

And as a security precaution, I'm wondering if it is possible to move this log out of /tmp, without risking some other file system heirarchy to the risks of letting apache write to it?  Any ideas on this one?  

-- Hugh 

On Thu, 23 Feb 2006 09:55:17 -0800 (PST)
Mike Schilli <m...@pe...> wrote:

> On Thu, 23 Feb 2006, Hugh Esco wrote:
> 
> > Hello folks. This looks like a great tool. But I'm stumped out the
> > outset here by some permission issues I've been unable to track
> > down. Using Log::Log4perl, I'm getting errors in the browser looking
> > like this:
> >
> >       There has been an error: Cannot write to '/var/log/apache-ssl/dpr.log':
> >       Permission denied at /usr/local/share/perl/5.8.7/Log/Dispatch/File.pm line 86.
> >
> > Although, when I su - www-data (my apache user), I am able to update
> > the last modification date with the touch command and use vim to
> > edit the log file, as well.
> >
> > Can anyone here please advise why my log file would be inaccessible
> > to this web application? Thank you for your time.
> 
> "touch" doesn't require write permissions on the file, appending does:
> 
> $ touch file
> $ chmod -w file
> $ touch file
> $ echo foo >>file
> bash: file: Permission denied
> 
> So, what you need are write permissions on your /var/log/apache-ssl/dpr.log file,
> either for the owner or the group.
> 
> By the way, the file appender will create the file according to the
> specified umask settings if it doesn't exist yet. In this case, it
> requires write permissions on the directory the file will be
> located in.
> 
> -- Mike
> 
> Mike Schilli
> m...@pe...
> 
> 
> -------------------------------------------------------
> This SF.Net email is sponsored by xPML, a groundbreaking scripting language
> that extends applications into web and mobile media. Attend the live webcast
> and join the prime developer group breaking into this new coding territory!
> http://sel.as-us.falkag.net/sel?cmd=lnk&kid=110944&bid=241720&dat=121642
> _______________________________________________
> log4perl-devel mailing list
> log...@li...
> https://lists.sourceforge.net/lists/listinfo/log4perl-devel
> 
> 


-- 
--
Hugh Esco 
250-352-9361
he...@re...
RCK Computer Services 
http://reclaimedcomputers.ca/

Re: [log4perl-devel] log file permissions issues, pls advise

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

On Thu, 23 Feb 2006, Hugh Esco wrote:

> Hello folks. This looks like a great tool. But I'm stumped out the
> outset here by some permission issues I've been unable to track
> down. Using Log::Log4perl, I'm getting errors in the browser looking
> like this:
>
>       There has been an error: Cannot write to '/var/log/apache-ssl/dpr.log':
>       Permission denied at /usr/local/share/perl/5.8.7/Log/Dispatch/File.pm line 86.
>
> Although, when I su - www-data (my apache user), I am able to update
> the last modification date with the touch command and use vim to
> edit the log file, as well.
>
> Can anyone here please advise why my log file would be inaccessible
> to this web application? Thank you for your time.

"touch" doesn't require write permissions on the file, appending does:

$ touch file
$ chmod -w file
$ touch file
$ echo foo >>file
bash: file: Permission denied

So, what you need are write permissions on your /var/log/apache-ssl/dpr.log file,
either for the owner or the group.

By the way, the file appender will create the file according to the
specified umask settings if it doesn't exist yet. In this case, it
requires write permissions on the directory the file will be
located in.

-- Mike

Mike Schilli
m...@pe...

[log4perl-devel] log file permissions issues, pls advise

[Hugh E. <he...@re...>]

Hello folks.  This looks like a great tool.  But I'm stumped out the outset here by some permission issues I've been unable to track down.  Using Log::Log4perl, I'm getting errors in the browser looking like this:

	There has been an error: Cannot write to '/var/log/apache-ssl/dpr.log': 
	Permission denied at /usr/local/share/perl/5.8.7/Log/Dispatch/File.pm line 86.

Although, when I su - www-data (my apache user), I am able to update the last modification date with the touch command and use vim to edit the log file, as well.

Can anyone here please advise why my log file would be inaccessible to this web application?  Thank you for your time.  

-- Hugh

-- 
RCK Computer Services 
http://reclaimedcomputers.ca/

Re: [log4perl-devel] log4perl and Exception

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

On Thu, 16 Feb 2006, Alexander wrote:
> It's my code and why it's do not work? (see comments)
> Log::Log4perl version 1.03

You didn't include init().

-- Mike

Mike Schilli
m...@pe...

>
> > use Data::Dumper;
> > use Proc::Daemon;
> > use Getopt::Long;
> > use Config::General;
> > use Log::Log4perl;
> > use Log::Log4perl::Level;
> > use Exception qw(:try);
> >
> > main();
> >
> > sub main
> > {
> >     print "start\n"; # work
> >     my $params = init();
> >     log_info(" -=== Start ===- "); # work
> >     log_err("test"); # work
> >
> >     my $err;
> >     my $logger = Log::Log4perl->get_logger("ant-daemon");
> >     try
> >     {
> >         log_err("in try"); # work
> >         # some my code
> >     }
> >     except
> >     {
> >         my $error=shift;
> >         my $id = $error->id;
> >         my $text = $error->stringify;
> >         chomp($text);
> >         $err = "Error id = \"$id\", message = \"$text\"\n";
> >         print $err; # work
> > 	log_err($err); # do not work!
> >     };
> >
> >
> >     print "Hey!!\n"; # work
> >     $logger->log($INFO, "it's test"); #  do not work!
> >     $logger->error("it's test");  #  do not work!
> >     log_err("it's test");  #  do not work!
> >     if($err)
> >     {
> >         log_err("fuck");  #  do not work!
> > 	print $err; # work
> >     }
> > }
> >
> > sub logmsg
> > {
> >     my $type = shift;
> >     my @what = @_;
> >     my $logger = Log::Log4perl->get_logger("ant-daemon");
> >
> >     if(defined($type) && scalar(@what) > 0)
> >         { $logger->log($type, @what); }
> >     else
> >     {
> >         $logger->log($ERROR, "error in log sub");
> >         return 0;
> >     }
> >
> >     return 1;
> > }
> >
> > sub log_fatal
> > { return logmsg($FATAL, @_); }
> >
> > sub log_err
> > { return logmsg($ERROR, @_); }
> >
> > sub log_warn
> > { return logmsg($WARN, @_); }
> >
> > sub log_info
> > { return logmsg($INFO, @_); }
> >
> > sub log_debug
> > { return logmsg($DEBUG, @_); }
>
> Alexander Magola
>
>
> -------------------------------------------------------
> This SF.net email is sponsored by: Splunk Inc. Do you grep through log files
> for problems?  Stop!  Download the new AJAX search engine that makes
> searching your log files as easy as surfing the  web.  DOWNLOAD SPLUNK!
> http://sel.as-us.falkag.net/sel?cmd=lnk&kid=103432&bid=230486&dat=121642
> _______________________________________________
> log4perl-devel mailing list
> log...@li...
> https://lists.sourceforge.net/lists/listinfo/log4perl-devel
>

[log4perl-devel] log4perl and Exception

[Alexander <pus...@gm...>]

Hello!
Sorry for my english.

It's my code and why it's do not work? (see comments)
Log::Log4perl version 1.03

> use Data::Dumper;
> use Proc::Daemon;
> use Getopt::Long;
> use Config::General;
> use Log::Log4perl;
> use Log::Log4perl::Level;
> use Exception qw(:try);
> 
> main();
> 
> sub main
> {
>     print "start\n"; # work
>     my $params = init();
>     log_info(" -=== Start ===- "); # work
>     log_err("test"); # work
> 
>     my $err;
>     my $logger = Log::Log4perl->get_logger("ant-daemon");
>     try
>     {
>         log_err("in try"); # work
>         # some my code
>     }
>     except
>     {
>         my $error=shift;
>         my $id = $error->id;
>         my $text = $error->stringify;
>         chomp($text);
>         $err = "Error id = \"$id\", message = \"$text\"\n";
>         print $err; # work
> 	log_err($err); # do not work!
>     };
> 
> 
>     print "Hey!!\n"; # work
>     $logger->log($INFO, "it's test"); #  do not work!
>     $logger->error("it's test");  #  do not work!
>     log_err("it's test");  #  do not work!
>     if($err)
>     {
>         log_err("fuck");  #  do not work!
> 	print $err; # work
>     }
> }
> 
> sub logmsg
> {
>     my $type = shift;
>     my @what = @_;
>     my $logger = Log::Log4perl->get_logger("ant-daemon");
> 
>     if(defined($type) && scalar(@what) > 0)
>         { $logger->log($type, @what); }
>     else
>     {
>         $logger->log($ERROR, "error in log sub");
>         return 0;
>     }
> 
>     return 1;
> }
> 
> sub log_fatal
> { return logmsg($FATAL, @_); }
> 
> sub log_err
> { return logmsg($ERROR, @_); }
> 
> sub log_warn
> { return logmsg($WARN, @_); }
> 
> sub log_info
> { return logmsg($INFO, @_); }
> 
> sub log_debug
> { return logmsg($DEBUG, @_); }

Alexander Magola

Re: [log4perl-devel] Log4perl logs are binary

[Jim C. <jim...@gm...>]

Gil Vidals wrote:
> I'm new to log4perl. I'm seeing great advantages to using it; however, 
> I'm concerned that when I open the logs generated by log4perl,  I see 
> a bunch of  "@@@@@@@@@@@@@". More importantly when debugging I grep 
> through the log files and my grep fails with this error:
>  
>    [root@dev2 xraylogs]# grep 24 spiderapi.log
>    Binary file spiderapi.log matches
> I'm running log4perl in a linux environment using version 1.03. The 
> log files are about 5 MB in size.
>  
> How can ensure that my log file output only alphanumerics and not 
> binary???
>  
> Thanks,
>
> Gil...@Po... <mailto:Gil...@Po...>
> Position Research, Inc.
> Search engine results by research
> tel: (760) 480-8291 fax: (760) 480-8271
> www.PositionResearch.com <http://www.positionresearch.com/>
>  
do you have a small program that demonstrates this bug ?
without any code, its hard to duplicate/isolate.

[log4perl-devel] Log4perl logs are binary

[Gil V. <gil...@po...>]

I'm new to log4perl. I'm seeing great advantages to using it; however, I'm
concerned that when I open the logs generated by log4perl,  I see a bunch of
"@@@@@@@@@@@@@". More importantly when debugging I grep through the log
files and my grep fails with this error:
 
   [root@dev2 xraylogs]# grep 24 spiderapi.log
   Binary file spiderapi.log matches

I'm running log4perl in a linux environment using version 1.03. The log
files are about 5 MB in size.
 
How can ensure that my log file output only alphanumerics and not binary??? 
 
Thanks,

Gil...@Po...
Position Research, Inc.
Search engine results by research
tel: (760) 480-8291 fax: (760) 480-8271
www.PositionResearch.com <http://www.positionresearch.com/> 
 

Re: [log4perl-devel] logwarn/logdie code references problem

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

On 09-Feb-2006 Mike Schilli wrote:
> On Wed, 8 Feb 2006, Martin J. Evans wrote:
> 
>> I've been using log4perl for around a month in a new project - suits
>> me great - thanks for that. When one of my modules failed I noticed a
>> perculiar message on stderr and have reduced the problem to this:
>>
>> perl -MData::Dumper -e 'use Log::Log4perl qw(get_logger
>> :levels);Log::Log4perl->init_and_watch("/etc/log4.conf", 10);my
>> $log = get_logger("XMLLoad::Log"); $log->logwarn(sub
>> {Dumper([qw(a b c)])});'
> 
> Good catch, that's a bug! I'll fix it in Log::Log4perl 1.04.
> 
> Thanks!
> 
> -- Mike

Mike,

Thanks for that. This issue is not hurting me any but I'll upgrade when I see
1.04. Sorry for not looking in to it more myself but I'm on a really tight
deadline at the moment and posting the issue was the best I could do right now. 

Martin
--
Martin J. Evans
Easysoft Ltd, UK
http://www.easysoft.com

Re: [log4perl-devel] logwarn/logdie code references problem

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

On Wed, 8 Feb 2006, Martin J. Evans wrote:

> I've been using log4perl for around a month in a new project - suits
> me great - thanks for that. When one of my modules failed I noticed a
> perculiar message on stderr and have reduced the problem to this:
>
> perl -MData::Dumper -e 'use Log::Log4perl qw(get_logger
> :levels);Log::Log4perl->init_and_watch("/etc/log4.conf", 10);my
> $log = get_logger("XMLLoad::Log"); $log->logwarn(sub
> {Dumper([qw(a b c)])});'

Good catch, that's a bug! I'll fix it in Log::Log4perl 1.04.

Thanks!

-- Mike

Mike Schilli
m...@pe...

[log4perl-devel] logwarn/logdie code references problem

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

Hi,

I've been using log4perl for around a month in a new project - suits
me great - thanks for that. When one of my modules failed I noticed a
perculiar message on stderr and have reduced the problem to this:

perl -MData::Dumper -e 'use Log::Log4perl qw(get_logger
:levels);Log::Log4perl->init_and_watch("/etc/log4.conf", 10);my
$log = get_logger("XMLLoad::Log"); $log->logwarn(sub
{Dumper([qw(a b c)])});'

When I run the above with the config below I get:
CODE(0x8132f00) at -e line 1

and yet the log file contains:

2006/02/08 14:30:01 WARN> $VAR1 = [
          'a',
          'b',
          'c'
        ];

Why wasn't the output in the log file duplicated on stderr? I seem
to be getting the code reference to the sub instead of the result of
the sub. BTW, same happens with logdie.

My config file is:

log4perl.logger.XMLLoad.Log = DEBUG, A7
log4perl.appender.A7=Log::Dispatch::File
log4perl.appender.A7.filename=/tmp/xml_load.log
log4perl.appender.A7.mode=append
log4perl.appender.A7.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.A7.layout.ConversionPattern=%d %p> %m%n

BTW, I did notice this mailing list was for patches, enhancements and
bug reports but I could not find any other log4perl lists and
the sourceforge forums seemed to be almost dead with the last post
being 1-dec-05 (and unanswered).

Thanks.

Martin
--
Martin J. Evans
Easysoft Ltd, UK
http://www.easysoft.com