Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-08 Thread Jason Kohles

On Jan 7, 2008, at 10:16 PM, Adam Jacob wrote:


On 1/7/08, Jason Kohles <[EMAIL PROTECTED]> wrote:

It's also kind of a pain.  I use log4perl with Catalyst, but without
the plugin, primarily for three reasons:


Patches are gladly accepted, especially if they make things better,
and don't break backwards compatibility.

I'm not saying the module is broken, just that some of it's goals  
(being able to abort at any point during the request and have all the  
logs for that request suppressed) were incompatible with some of my  
goals (having the logs arrive in real-time).  I was willing to make  
the trade-off of not being able to suppress _all_ the logs for a given  
aborted request, but it's not something that can be patched in a  
backwards-compatible manner.


I started to put a patch together, but when I discovered that my goals  
couldn't be met in a backwards compatible way I postponed it.  When I  
get some free time this week I'll try and finish that up and get it to  
you.



--
Jason Kohles, RHCA RHCDS RHCE
[EMAIL PROTECTED] - http://www.jasonkohles.com/
"A witty saying proves nothing."  -- Voltaire



___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Adam Jacob
On 1/7/08, Adam Jacob <[EMAIL PROTECTED]> wrote:
> On 1/7/08, Jason Kohles <[EMAIL PROTECTED]> wrote:
> > It's also kind of a pain.  I use log4perl with Catalyst, but without
> > the plugin, primarily for three reasons:
>
> Patches are gladly accepted, especially if they make things better,
> and don't break backwards compatibility.

I know, replying to myself isn't a good sign..

But, does this mean I also accept patches that suck and do break
backward compatibility?

English, a tricky thing.

Adam

-- 
HJK Solutions - We Launch Startups - http://www.hjksolutions.com
Adam Jacob, Senior Partner
T: (206) 508-4759 E: [EMAIL PROTECTED]

___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Adam Jacob
On 1/7/08, Jason Kohles <[EMAIL PROTECTED]> wrote:
> It's also kind of a pain.  I use log4perl with Catalyst, but without
> the plugin, primarily for three reasons:

Patches are gladly accepted, especially if they make things better,
and don't break backwards compatibility.

Regards,
Adam

-- 
HJK Solutions - We Launch Startups - http://www.hjksolutions.com
Adam Jacob, Senior Partner
T: (206) 508-4759 E: [EMAIL PROTECTED]

___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Jason Kohles

On Jan 7, 2008, at 3:27 PM, Adam Jacob wrote:


On 1/7/08, Marius Kjeldahl <[EMAIL PROTECTED]> wrote:

I tried briefly looking into the source, when I ran into this:

   # I really have no idea why the correct subroutine
   # is on a different call stack
   $caller{subroutine} = ( caller(1) )[3];#wtf?

Does anybody want to comment on the maturity of the Catalyst log4perl
module?


Besides the smarty-pants comment, it's pretty mature. :)

It's also kind of a pain.  I use log4perl with Catalyst, but without  
the plugin, primarily for three reasons:


1. The support for ->abort() means all the logs are saved up and then  
pushed out at the end of the request, which makes debugging anything  
time related a pain.
2. The funkiness pasted above, where it fakes a bunch of the cspecs in  
order to work around the fact that isn't logging in real time, and  
which has caused me problems every time I've tried to use it.
3. The way support for ->abort() was implemented makes it all-or- 
nothing, I wanted to suppress Static::Simple output on the console,  
but have it show up in the logs.


This is the approach I took, which solves these problems.  I'm  
probably going to encapsulate this into a catalyst component at some  
point, when I have some free time...



package MyApp::Web::Logger;
use strict;
use warnings;
use Log::Log4perl;

BEGIN {
my @levels = qw( fatal error warn info debug trace );
for ( @levels ) {
my $level = $_;
no strict 'refs';
*{ $level } = sub {
my $self = shift;
local $Log::Log4perl::caller_depth += 1;
my $caller = caller( 1 );
return Log::Log4perl->get_logger( $caller )->$level( @_ );
};
$level = "is_".$level;
*{ $level } = sub {
local $Log::Log4perl::caller_depth += 1;
my $caller = caller( 1 );
return Log::Log4perl->get_logger( $caller )->$level();
};
}
};

sub levels { }
sub enable { }
sub disable { }
sub abort {
my $self = shift;
if ( @_ ) { Log::Log4perl::MDC->put( '_abort_request_log' =>  
shift() ) }

return Log::Log4perl::MDC->get( '_abort_request_log' );
}

So now Catalyst just stores the abort flag in the MDC, which makes it  
easy enough to have a filter to skip logging when the request aborted.


package Log::Log4perl::Filter::CatalystAbort;
use strict;
use warnings;
use base qw( Log::Log4perl::Filter );

sub ok {
my ( $self, %param ) = @_;
return ! Log::Log4perl::MDC->get( '_abort_request_log' );
}

To use the filter, you just add it as a filter to your log4perl  
configuration file...


log4perl.rootLogger=TRACE,ColorScreen,RollingFile

# ColorScreen appender, good choice for debugging
log4perl 
.appender.ColorScreen=Log::Log4perl::Appender::ScreenColoredLevels

log4perl.appender.ColorScreen.stderr=1
log4perl 
.appender.ColorScreen.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.ColorScreen.layout.ConversionPattern=%d{HH:mm}  
%p[%c] %m%n

log4perl.appender.ColorScreen.color.FATAL=bold red
log4perl.appender.ColorScreen.color.DEBUG=white
log4perl.appender.ColorScreen.Filter = CatalystAbort

# RollingFile appender, keeps a logfile
log4perl.appender.RollingFile=Log::Dispatch::FileRotate
log4perl.appender.RollingFile.filename=debug.log
log4perl.appender.RollingFile.max=1
log4perl 
.appender.RollingFile.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.RollingFile.layout.ConversionPattern=%d{HH:mm}  
%p[%c] %m%n


# Filter to support Catalyst::Log->abort(1)
log4perl.filter.CatalystAbort = Log::Log4perl::Filter::CatalystAbort


Now the aborted log entries are skipped for the ColorScreen appender,  
but included in the RollingFile appender, so that if something does go  
wrong with Static::Simple, then I can look at the log to see what it  
was, but the rest of the time I don't get swamped with the static file  
output.


The only downside to doing it this way is that things that use ->abort  
may not do it early enough to really supress all the logging for that  
component.  For Static::Simple, for example, I still get the first two  
lines of output, but that is much less annoying than the alternative  
(IMHO):


17:32 DEBUG[Catalyst] "GET" request for "static/reset-fonts-grids.css"  
from "127.0.0.1"

17:32 DEBUG[Catalyst] Arguments are "static/reset-fonts-grids.css"

--
Jason Kohles, RHCA RHCDS RHCE
[EMAIL PROTECTED] - http://www.jasonkohles.com/
"A witty saying proves nothing."  -- Voltaire



___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Marius Kjeldahl
Excellent, and thank you for your work.

As mentioned already I've used Log4perl on another project and I never
ran into the issue. I googled for "catalyst log4perl duplicate" and the
FAQ didn't turn up on the first page. Had I removed catalyst from the
search terms, it would have been item number two.

My apologies.

Regards,

Marius K.

Adam Jacob wrote:
> On 1/7/08, Marius Kjeldahl <[EMAIL PROTECTED]> wrote:
>> I tried briefly looking into the source, when I ran into this:
>>
>> # I really have no idea why the correct subroutine
>> # is on a different call stack
>> $caller{subroutine} = ( caller(1) )[3];#wtf?
>>
>> Does anybody want to comment on the maturity of the Catalyst log4perl
>> module?
> 
> Besides the smarty-pants comment, it's pretty mature. :)
> 
> Adam
> 


___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Adam Jacob
On 1/7/08, Marius Kjeldahl <[EMAIL PROTECTED]> wrote:
> I tried briefly looking into the source, when I ran into this:
>
> # I really have no idea why the correct subroutine
> # is on a different call stack
> $caller{subroutine} = ( caller(1) )[3];#wtf?
>
> Does anybody want to comment on the maturity of the Catalyst log4perl
> module?

Besides the smarty-pants comment, it's pretty mature. :)

Adam

-- 
HJK Solutions - We Launch Startups - http://www.hjksolutions.com
Adam Jacob, Senior Partner
T: (206) 508-4759 E: [EMAIL PROTECTED]

___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Marius Kjeldahl
Jason Kohles wrote:
> It isn't the logger that's confused.  :)
> 
> Refer to the Log::Log4perl::FAQ entry titled 'I keep getting duplicate
> log messages! What's wrong?'

Thanks, looks like oneMessagePerAppender is what is needed. Strangely
enough, I did not encounter this problem at a previous project where I
used Log4perl.

Marius K.


___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


Re: [Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Jason Kohles

On Jan 7, 2008, at 8:53 AM, Marius Kjeldahl wrote:


As you can see from the output, for some reason the logger decides to
log several times, even though the logger is/should be only called  
once.

If I remove the two first lines in the logger configuration file, it
works fine.

It looks like the logger is getting confused with having different
settings for parts of the code, and when/if a log is triggered for one
level it outputs it for all levels defined.



It isn't the logger that's confused.  :)

Refer to the Log::Log4perl::FAQ entry titled 'I keep getting duplicate  
log messages! What's wrong?'


--
Jason Kohles, RHCA RHCDS RHCE
[EMAIL PROTECTED] - http://www.jasonkohles.com/
"A witty saying proves nothing."  -- Voltaire



___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/


[Catalyst] Catalyst::Log::Log4perl log duplicates

2008-01-07 Thread Marius Kjeldahl
I'm trying to use Catalyst::Log::Log4perl with Catalyst. My "main"
package is called MintApp.pm, where I do the following calls:

use Catalyst::Log::Log4perl;
...
__PACKAGE__->log (Catalyst::Log::Log4perl->new ('mintapp-log.conf'));

The conf file looks as follows:

log4perl.logger.MintApp=ERROR, SCREEN
log4perl.logger.MintApp.Controller=ERROR, SCREEN
log4perl.logger.MintApp.Controller.Pub=DEBUG, SCREEN
log4perl.appender.SCREEN=Log::Log4perl::Appender::ScreenColoredLevels
log4perl.appender.SCREEN.stderr=1
log4perl.appender.SCREEN.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.SCREEN.layout.ConversionPattern=[%P] %p [%c] %m%n

In one of the controllers (MintApp::Controller::Pub) I have a line:

print STDERR "CALLED!\n";
$c->log->debug ("Pub::begin: " . Dumper ($c->session));

For some reason, this is the output I get when calling the controller
MintApp::Controller::Pub :

CALLED!
[8517] DEBUG [MintApp.Controller.Pub] Pub::begin: $VAR1 = {
  '__created' => 1199713585,
  '__updated' => 1199713585
};
[8517] DEBUG [MintApp.Controller.Pub] Pub::begin: $VAR1 = {
  '__created' => 1199713585,
  '__updated' => 1199713585
};
[8517] DEBUG [MintApp.Controller.Pub] Pub::begin: $VAR1 = {
  '__created' => 1199713585,
  '__updated' => 1199713585
};


As you can see from the output, for some reason the logger decides to
log several times, even though the logger is/should be only called once.
If I remove the two first lines in the logger configuration file, it
works fine.

It looks like the logger is getting confused with having different
settings for parts of the code, and when/if a log is triggered for one
level it outputs it for all levels defined.

I'm using Catalyst::Log::Log4perl version 1.00.

I tried briefly looking into the source, when I ran into this:

# I really have no idea why the correct subroutine
# is on a different call stack
$caller{subroutine} = ( caller(1) )[3];#wtf?

Does anybody want to comment on the maturity of the Catalyst log4perl
module?

Thanks,

Marius K.


___
List: Catalyst@lists.scsys.co.uk
Listinfo: http://lists.scsys.co.uk/cgi-bin/mailman/listinfo/catalyst
Searchable archive: http://www.mail-archive.com/catalyst@lists.scsys.co.uk/
Dev site: http://dev.catalyst.perl.org/