Re: [Catalyst] Catalyst::Log::Log4perl log duplicates
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
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
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
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
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
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
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
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
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/