log4perl-devel

[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] 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...>]

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. <cp...@go...>]

On Apr 13, 2006, at 11:49 AM, Gil Vidals wrote:
> Kevin, We're using log4perl in the Perl Object Environment (POE)

I haven't worked with POE at all yet, although I used your question  
as an excuse to take a look at it this weekend for the first time.   
After a superficial browsing of the POE docs, I don't see any reason  
why the Log4perl and POE shouldn't be able to play well together, and  
on Google I see at least one reference to "I have used POE with  
Log4perl before and it was a dream."

> I'm updating all
> calls to logger to use the standard init and avoid the  
> "init_and_watch".
> ...
> 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?

It's not inconcievable.  Do the problems happen after the timestamp  
on your log4perl.conf file is changed?  The init_and_watch stuff  
shouldn't make any difference to anything if the conf file never  
changes because it would never get called.

So taking out init_and_watch in favor of init sounds like a good  
thing to try--did that help?  If it did, can you forward  a tiny  
sample of code that shows the way you're using POE and Log4perl and  
we could take a look at it.

Hopefully this doesn't sound like ducking the issue, but did you try  
posing the question to the POE folks?  A look at Google suggests POE  
users have seen this error before when not using log4perl. I suspect  
it's something about the magical POE enviroment, so they might have  
something useful to say about it.

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

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

On Sun, 16 Apr 2006, Kevin M. Goess wrote:

> On Apr 13, 2006, at 11:49 AM, Gil Vidals wrote:
> > Kevin, We're using log4perl in the Perl Object Environment (POE)
>
> I haven't worked with POE at all yet, although I used your question
> as an excuse to take a look at it this weekend for the first time.
> After a superficial browsing of the POE docs, I don't see any reason
> why the Log4perl and POE shouldn't be able to play well together, and
> on Google I see at least one reference to "I have used POE with
> Log4perl before and it was a dream."

I have used POE and Log::Log4perl many times and I'm not aware
of any interaction problems.

> > I'm updating all
> > calls to logger to use the standard init and avoid the
> > "init_and_watch".
> > ...
> > 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?

There's nothing magical about POE or Log::Log4perl, and their 'states'
are truly orthogonal and they're not sharing any 'state machine code'.
But of course there could be a bug in either of them.

Is there a short snippet of code you could provide that reproduces
the problem? If it's not-so-short, no problem, it's just easier to
track down a problem with actual code in hand.

-- Mike

Mike Schilli
m...@pe...

>
> It's not inconcievable.  Do the problems happen after the timestamp
> on your log4perl.conf file is changed?  The init_and_watch stuff
> shouldn't make any difference to anything if the conf file never
> changes because it would never get called.
>
> So taking out init_and_watch in favor of init sounds like a good
> thing to try--did that help?  If it did, can you forward  a tiny
> sample of code that shows the way you're using POE and Log4perl and
> we could take a look at it.
>
> Hopefully this doesn't sound like ducking the issue, but did you try
> posing the question to the POE folks?  A look at Google suggests POE
> users have seen this error before when not using log4perl. I suspect
> it's something about the magical POE enviroment, so they might have
> something useful to say about it.
>
>
>
>
> -------------------------------------------------------
> 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
>