log4perl-devel — Ongoing log4perl development

Re: [log4perl-devel] Patch for suggested new behaviour

[<msc...@ao...>]

In a message dated 1/20/2003 12:40:27 PM Eastern Standard Time, Kevin Goess <ke...@go...> writes:

>The new stuff is checked in, all tests pass.

That's great news, thanks! Couple of notes:

* in the DBI appender's docs, the sentence "You can mix up the order the placeholders with %x specifiers as you see fit" seems to be missing an "of" and I'm confused about what the %x specifier does in this context.

* What happens in case PatternLayout is chosen instead of NoopLayout? Probably needs to be documented.

* Also, I thought that filter_message would be a code ref which could be used to manipulate logger arguments? I think the appender should be able to correct any log statement argument list (like limit it to the number of arguments it expects etc.)

* could you please add some comments to the "Changes" file (also about the XML-DOM addition)

* I've corrected Ceki's name in the DOMConfiguration docs with umlauts, these crazy Europeans are so adamant about it :) Also, is there a URL to the original spec we could add?

BTW, I'm gonna add a couple of test cases for the new { filter => \&filter, value => $value} syntax.

All test cases run fine on my box, too, looks good so far!
 
-- Mike

############################
# Mike Schilli             #
# log...@pe... #
# http://perlmeister.com   #
# log4perl.sourceforge.net #
############################

Re: [log4perl-devel] Patch for suggested new behaviour

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

The new stuff is checked in, all tests pass.


-- 
Happy Trails . . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510) 525-5217

Re: [log4perl-devel] Patch for suggested new behaviour

[Mike S. <msc...@ao...>]

ke...@go... wrote:

> - input_filter as a property of an appender in the config, normally is
>not defined, but can be defined and false or set to...what? a coderef? 
>Would need to implement set_input_filter method in Appender.pm.
>
Yeah, that's much better! Only thing that could happen now is that some 
appender would want to define a default filter (like DBI cutting off 
excess fields) which could be slipped in via setting 
$p->{filter_message}in the appender's constructor and potentially 
overridden by a config file setting. Nice. Yeah, set_input_filter() 
would be useful.

> - I'm still not sure how this will interact with jcromie are talking
>about, but it's more than I can keep in my head at one time.
>
Do you mean the {filter => \&filter, value => "val"} syntax? That should 
work fine, because it's evaluated before the input_filter potentially 
kicks in.

If you meant the "autocategorize" stuff, that should be independent (and 
it's not yet decided if it's going to be in).

One more thing: currently, there's no check (in my part of the patch, 
sorry about that :) if someone writes something stupid like
    {feelter => \&filter, value => "val"}
The result would be somewhat nasty. In case we get a hashref, we should 
probably check that both "filter" and "value" are present.      

Otherwise -- looks good to me to check in, thanks for fixing! :)

-- 
-- Mike

Mike Schilli
log...@pe...

[log4perl-devel] DOMConfigurator is in alpha

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

There's now a decent version of DOMConfigurator in CVS that will
initialize log4perl from an xml file that conforms to the log4j.dtd.  It
doesn't yet support any of the log4perl extensions we've been coming up
with.  Still a bunch of loose ends to tie up, but it's useable.

--
Happy Trails. . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510)525-5217

Re: [log4perl-devel] Patch for suggested new behaviour

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

Ahh, I feel clarity approaching.   I think I've got the best of our
approaches coming on.  Collaboration rocks.

 - input_filter as a property of an appender in the config, normally is
not defined, but can be defined and false or set to...what? a coderef? 
Would need to implement set_input_filter method in Appender.pm.

 - I was suffering confusion hacking the Layouts to return arrayrefs
untouched, silly.  The log4j behavior is to have a sql statement like
this
	insert into LogTable (Thread, Class, Message) values ("%t", "%c", "%m")
passed to PatternLayout.  We still support that, log4j configs will run
just fine as-is.  My new behavior with the bind values doesn't need
PatternLayout at that level, it needs a NoopLayout to just pass the
array back, that's not log4j but that's ok, it's consistently not log4j.

 - thanks for noticing the join in the noop coderef

 - I'm still not sure how this will interact with jcromie are talking
about, but it's more than I can keep in my head at one time.

Check out the attached patch and let me know what you think!



Mike Schilli wrote:
> 
> ke...@go... wrote:
> 
> > Are you guaranteeing that no Log::Dispatch::* class will ever have a
> > subroutine called "input_filter"?
> 
> Well, admittedly, that's somewhat sloppy right now. Although, long term
> we need a more generalized appender interface anyway -- but we can't
> finalize that right now, because we don't know yet which crazy ideas
> we're gonna come up with in the future ;).
> 
> > And why call a method *all* the time when *most* of the time we're
> > just doing a join?
> 
> Good point. It's clearly unnecessary to call input_filter() every time.
> That could be changed to cache the default behaviour (join) and do it in
> Log::Log4perl::Appender.
> 
> > How about something like this instead.  Munging the message should be
> > a function of the Layout class, shouldn't it?
> 
> Hmm, really? Isn't it up to the appender to decide which format it
> likes/needs? Shouldn't it be a property of the appender?
> 
> > If need be, I might have time tonight to generate a patch for
> > discussion purposes.
> 
> Good idea -- think that would help clear things up.
> 
> --
> -- Mike
> 
> Mike Schilli
> log...@pe...

--
Happy Trails. . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510)525-5217

[log4perl-devel] Log::Log4perl Recipe of the Week (#12)

[<log...@pe...>]

Welcome to the Log::Log4perl recipe of the week. Today:

============================================================
Log::Log4perl Recipe of the Week (#12):

How can I configure Log::Log4perl to send me email if
something happens?
============================================================

Some incidents require immediate action. You can't wait
until someone checks the log files, you need to get notified
on your pager right away.

The easiest way to do that is by using the
"Log::Dispatch::Email::MailSend" module as an appender. It
comes with the "Log::Dispatch" bundle and allows you to
specify recipient and subject of outgoing emails in the
Log4perl configuration file:

    log4perl.category = FATAL, Mailer
    log4perl.appender.Mailer         = Log::Dispatch::Email::MailSend
    log4perl.appender.Mailer.to      = dr...@pa...
    log4perl.appender.Mailer.subject = Something's broken!
    log4perl.appender.Mailer.layout  = SimpleLayout

The message of every log incident this appender gets will
then be forwarded to the given email address. Check the
"Log::Dispatch::Email::MailSend" documentation for details.
And please make sure there's not a flood of email messages
sent out by your application, filling up the receipient's
inbox.


Have fun! Until next week.

-- Mike

###################################
# Mike Schilli                    #
# log...@pe...        #
# http://perlmeister.com          #
# http://log4perl.sourceforge.net #
###################################

Re: [log4perl-devel] autocat feature, log4perl config file

[Mike S. <msc...@ao...>]

jc...@di... wrote:

>
> FWIW - my auto-dump only kicks in at the end of the arg-list ( or 
> should ).
> As I scan @_, I just print non-refs, thus avoiding the needless 
> encapsulation
> of string-args into output like; 

Problem is that some appenders require a certain number of arguments to 
be passed without any interpretation (please see the thread on "Patch 
for suggested new behaviour" on this list) -- we need to find a solution 
which serves both purposes, special appenders and special parameter 
treatment.

>
> autocat constructs the category from info available from caller(), the 
> 1st 4 are most useful.
>
>          ($package, $filename, $line, $subroutine, $hasargs,
>           $wantarray, $evaltext, $is_require, $hints, $bitmask) = 
> caller($i);
>
> If theyre put in the right order, (typically scoped - like code):
>
>     "$filename.$package.$subroutine.$line",
>
> then the log-config file can control which messages are logged, in a 
> fashion consistent with the scoping. 

Ah, now I understand. I like the idea of being able to manipulate 
logging behaviour at this very granular level. However, the performance 
impact is overwhelming:

Every log statement, no matter if it's actually active or not, will 
cause a call to caller() and get_logger(). This way, it doesn't really 
matter if you enable or disable logging, the load on the system will 
always like if you enabled DEBUG logging all over the place. That's 
something log4j has been designed to avoid. Is there a way of getting 
around this?

-- 
-- Mike

Mike Schilli
log...@pe...

Re: [log4perl-devel] Patch for suggested new behaviour

[Mike S. <msc...@ao...>]

ke...@go... wrote:

> Are you guaranteeing that no Log::Dispatch::* class will ever have a 
> subroutine called "input_filter"?

Well, admittedly, that's somewhat sloppy right now. Although, long term 
we need a more generalized appender interface anyway -- but we can't 
finalize that right now, because we don't know yet which crazy ideas 
we're gonna come up with in the future ;).

> And why call a method *all* the time when *most* of the time we're 
> just doing a join? 

Good point. It's clearly unnecessary to call input_filter() every time. 
That could be changed to cache the default behaviour (join) and do it in 
Log::Log4perl::Appender.

> How about something like this instead.  Munging the message should be 
> a function of the Layout class, shouldn't it?  

Hmm, really? Isn't it up to the appender to decide which format it 
likes/needs? Shouldn't it be a property of the appender?

> If need be, I might have time tonight to generate a patch for 
> discussion purposes.

Good idea -- think that would help clear things up.

-- 
-- Mike

Mike Schilli
log...@pe...

Re: [log4perl-devel] [Fwd: Log::Log4perl::Layout::PatternLayout - Pattern Layout]

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

Good work.  I had fixed the docs in Log4perl.pm and the code in 
PatternLayout.pm, missed this one.


Mike Schilli wrote:
> ... forwarded:
> 
> 
> 
> ------------------------------------------------------------------------
> 
> Subject:
> Log::Log4perl::Layout::PatternLayout - Pattern Layout
> From:
> Chris Mayo <ma...@st...>
> Date:
> Tue, 14 Jan 2003 16:28:44 +0000
> To:
> m...@pe...
> 
> 
> Mike
> 
> Many thanks for your excellent module. I'm just starting to grasp the 
> flexible power that it gives to logging.
> 
> To make some small contribution, I think there is a typo in the 
> 'Fine-tuning with curlies' section of the following manpage:
> 
> http://log4perl.sourceforge.net/releases/Log-Log4perl/docs/html/Log/Log4perl/Layout/PatternLayout.html 
> 
> 
> in that the file name placeholder is given as %f (lowercase) instead of %F.
> 
> Regards
> 
> Chris Mayo
> 


-- 
Happy Trails . . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510) 525-5217

Re: [log4perl-devel] Patch for suggested new behaviour

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

+        # Check if the appender's got its own input_filter
+    unless($appender->can("input_filter")) {
+        # No ? Then just slip it our own
+        eval "*${appenderclass}::input_filter = *input_filter";
+    }

<Edvard Munch Scream>Noooooooo!</Edvard Munch Scream>  Are you 
guaranteeing that no Log::Dispatch::* class will ever have a subroutine 
called "input_filter"? (Or "can()" for that matter?)  Don't be mucking 
about in namespaces of modules you ain't even met yet ;-)

I think can() is more work than we need to do, it has to traverse the 
class heirarchy all the way back up to UNIVERSAL, I've seen it fail in 
wierd cases where it looks like it's actually running the method it's 
supposed to be checking.  And why call a method *all* the time when 
*most* of the time we're just doing a join?

How about something like this instead.  Munging the message should be a 
function of the Layout class, shouldn't it?  Why not pass the message 
arrayref straight through to {layout}->render(...), and let it do a
	join unless $dontCollapse
or something?

If need be, I might have time tonight to generate a patch for discussion 
purposes.

I realize that I'm focusing on the specific problem of  where a list 
gets collapsed instead of the more generalized question of these input 
filters (I don't know POE), but this filter parameter doesn't sound very 
log4j-ish, wouldn't the log4j idiom be to subclass the Layout if you 
want different behavior?


msc...@ao... wrote:
 > Hey Kevin,
 >
 > here's a patch implementing what I've suggested earlier -- I haven't
 > tested the new functionality extensivly, but the patch passes the
 > existing test suite.
 >
 > There's a couple of open issues :
 >
 > [1] There's a "join" command in generate_noop_coderef() which
 > concatenates the message chunks together to somehow log the message
 > later if a config_and_watch event occurs. Think that won't work even
 > with the old DBI appender -- right ;) ?
 >
 > [2] In case a log event passes several message chunks on to an
 > appender, could there be appenders which want to render each chunk
 > individually? Just a thought, maybe not.
 >
 > The code in the patch is not well commented, hope it's somehow
 > decipherable :) Basically what I did is slip in a default
 > input_filter method into the filter's package if it doesn't define
 > one. The input_filter method will take a array ref of parameters
 > (always) and return either a single string (in case the appender
 > wants to collapse) or an array ref with the new elements. Arguments
 > to debug(), info(), etc. are now plain arguments, hashes indicate
 > parameter with special filtering needs. Code refs is also evaluated.
 >
 > Please let me know if that all makes sense ... :)
 >
 >
 >
 > ------------------------------------------------------------------------
 >
 >
 > Index: lib/Log/Log4perl/Appender.pm
 > ===================================================================
 > RCS file:
 > /cvsroot/log4perl/Log-Log4perl/lib/Log/Log4perl/Appender.pm,v
 > retrieving revision 1.18 diff -a -u -r1.18 Appender.pm ---
 > lib/Log/Log4perl/Appender.pm	26 Dec 2002 23:57:35 -0000	1.18 +++
 > lib/Log/Log4perl/Appender.pm	14 Jan 2003 09:25:58 -0000 @@ -37,8
 > +37,8 @@ no strict 'refs'; # see 'perldoc -f require' for why two
 > evals eval "require $appenderclass" -             unless
 > ${$appenderclass.'::IS_LOADED'};  #for unit tests, see 004Config -
 > ; +             unless ${$appenderclass.'::IS_LOADED'};  #for unit
 > tests, +                                                      #see
 > 004Config die $@ if $@;
 >
 > # Eval erroneously succeeds on unknown appender classes if @@ -68,6
 > +68,12 @@ map { $_ => $params{$_} } keys %params, );
 >
 > +        # Check if the appender's got its own input_filter +
 > unless($appender->can("input_filter")) { +        # No ? Then just
 > slip it our own +        eval "*${appenderclass}::input_filter =
 > *input_filter"; +    } + my $self = { appender => $appender, name
 > => $params{name}, @@ -116,13 +122,34 @@ #doing the rendering in here
 > 'cause this is #where we keep the layout
 >
 > -    $p->{message} = $self->{layout}->render($p->{message}, -
 > $category, -                                            $level, -
 > 3 + $Log::Log4perl::caller_depth, -
 > ); +    #use Data::Dumper; +    #print "Message1 = ",
 > Data::Dumper::Dumper($p->{message}), "\n"; + +        # Call the
 > appender's input filter to modify our arguments +        # (either
 > collapse, pass them as an array, etc.) +    $p->{message} =
 > $self->{appender}->input_filter($p->{message}); + +    if(ref
 > $p->{message} eq "ARRAY") { +            # Render each element
 > individually +# For now, disable that +#        for(0 ..
 > $#{$p->{message}}) { +#            $p->{message}->[$_] = +#
 > $self->{layout}->render($p->{message}->[$_], +#
 > $category, +#                                        $level, +#
 > 3 + $Log::Log4perl::caller_depth, +#
 > ); +#        } +    } else { +            $p->{message} = +
 > $self->{layout}->render($p->{message}, +
 > $category, +                                        $level, +
 > 3 + $Log::Log4perl::caller_depth, +
 > ); +    }
 >
 > -    $self->{appender}->log(%$p, +    $self->{appender}->log(%$p,
 > #these are used by our Appender::DBI log4p_category => $category,
 > log4p_level  => $level,); @@ -156,10 +183,27 @@ }elsif (!
 > $self->{layout}) { $self->{layout} =
 > Log::Log4perl::Layout::SimpleLayout ->new($self->{name}); - }
 >
 > return $self->{layout}; +} +
 > +########################################### +sub input_filter {
 > +########################################### +    # Expects a
 > (single!) array ref as arg +    # +    # Default input filter. Active
 > if the appender +    # (subclass) doesn't define one of its own. +
 > # +    # The default input filter just takes the +    # array passed
 > in as a ref, concatenates all +    # elements and returns a single
 > string as result + +#use Data::Dumper; +#print "input_filter(a) got
 > ", Data::Dumper::Dumper(\@_), "\n"; + +    return join('', @{$_[1]});
 >  }
 >
 > ################################################## Index:
 > lib/Log/Log4perl/Logger.pm
 > ===================================================================
 > RCS file: /cvsroot/log4perl/Log-Log4perl/lib/Log/Log4perl/Logger.pm,v
 >  retrieving revision 1.42 diff -a -u -r1.42 Logger.pm ---
 > lib/Log/Log4perl/Logger.pm	31 Dec 2002 00:57:05 -0000	1.42 +++
 > lib/Log/Log4perl/Logger.pm	14 Jan 2003 09:26:00 -0000 @@ -198,20
 > +198,30 @@ \$coderef = sub { my (\$logger)  = shift; my (\$level)   =
 > pop; -      my \$message; my \$appenders_fired = 0;
 >
 > -      \$message = ref \$_[0] eq 'ARRAY' ? \$_[0] : -
 > join('', map { ref \$_ eq "CODE" ? \$_->() : defined \$_ ? \$_ : '' }
 > \@_); - -      print("coderef: \$logger->{category}\n") if DEBUG; +
 > # Evaluate all parameters that need to evaluated. Two kinds: +      #
 >  +      # (1) It's a hash like { filter => "filtername", +      #
 > value  => "value" } +      #     => filtername(value) +      # +
 > # (2) It's a code ref +      #     => coderef() +      # + +      my
 > \$message   = [map { ref \$_ eq "HASH" ? +
 > \$_->{filter}->(\$_->{value}) : +                              ref
 > \$_ eq "CODE" ? +                                  \$_->() : \$_ +
 > } \@_];
 >
 > $watch_delay_code;  #note interpolation here
 >
 > foreach my \$a (\@\$appenders) {   #note the closure here my
 > (\$appender_name, \$appender) = \@\$a;
 >
 > -          print("  Sending message '\$message' (\$level) " . +
 > print("  Sending message '<\$message>' (\$level) " . "to
 > \$appender_name\n") if DEBUG;
 >
 > \$appender->log( Index: lib/Log/Log4perl/Appender/DBI.pm
 > ===================================================================
 > RCS file:
 > /cvsroot/log4perl/Log-Log4perl/lib/Log/Log4perl/Appender/DBI.pm,v
 > retrieving revision 1.8 diff -a -u -r1.8 DBI.pm ---
 > lib/Log/Log4perl/Appender/DBI.pm	8 Jan 2003 17:21:58 -0000	1.8 +++
 > lib/Log/Log4perl/Appender/DBI.pm	14 Jan 2003 09:26:01 -0000 @@ -241,6
 > +241,16 @@ } }
 >
 > +################################################## +sub input_filter
 > { +################################################## +    # No
 > changes, just return the array ref passed in as the 1st +    #
 > argument back to the caller. We could have modified it's +    #
 > content if we wanted (e.g. collapse some elements) +    #use
 > Data::Dumper; +    #print "input_filter in: ",
 > Data::Dumper::Dumper($_[1]), "\n"; +    return $_[1]; +}
 >
 > 1;
 >
 > Index: lib/Log/Log4perl/Layout/PatternLayout.pm
 > ===================================================================
 > RCS file:
 > /cvsroot/log4perl/Log-Log4perl/lib/Log/Log4perl/Layout/PatternLayout.pm,v
 >  retrieving revision 1.33 diff -a -u -r1.33 PatternLayout.pm ---
 > lib/Log/Log4perl/Layout/PatternLayout.pm	8 Jan 2003 07:00:51 -0000
 > 1.33 +++ lib/Log/Log4perl/Layout/PatternLayout.pm	14 Jan 2003
 > 09:26:03 -0000 @@ -159,14 +159,6 @@
 > ################################################## my($self,
 > $message, $category, $priority, $caller_level) = @_;
 >
 > -    if (ref $message eq 'ARRAY' ) { -        if
 > ($self->{dontCollapseArrayRefs}) { -            return $message; -
 > }else{ -            $message =
 > join($Log::Log4perl::JOIN_ARRAYREFS_CHAR, @$message); -        } -
 > } - $caller_level = 0 unless defined  $caller_level;
 >
 > my %info    = (); Index: lib/Log/Log4perl/Layout/SimpleLayout.pm
 > ===================================================================
 > RCS file:
 > /cvsroot/log4perl/Log-Log4perl/lib/Log/Log4perl/Layout/SimpleLayout.pm,v
 >  retrieving revision 1.5 diff -a -u -r1.5 SimpleLayout.pm ---
 > lib/Log/Log4perl/Layout/SimpleLayout.pm	27 Dec 2002 00:02:29 -0000
 > 1.5 +++ lib/Log/Log4perl/Layout/SimpleLayout.pm	14 Jan 2003 09:26:03
 > -0000 @@ -35,14 +35,6 @@
 > ################################################## my($self,
 > $message, $category, $priority, $caller_level) = @_;
 >
 > -    if (ref $message eq 'ARRAY' ) { -        if
 > ($self->{dontCollapseArrayRefs}) { -            return $message; -
 > }else{ -            $message =
 > join($Log::Log4perl::JOIN_ARRAYREFS_CHAR, @$message); -        } -
 > } - return "$priority - $message\n"; }
 >
 > Index: t/034DBI.t
 > ===================================================================
 > RCS file: /cvsroot/log4perl/Log-Log4perl/t/034DBI.t,v retrieving
 > revision 1.3 diff -a -u -r1.3 034DBI.t --- t/034DBI.t	1 Jan 2003
 > 05:43:39 -0000	1.3 +++ t/034DBI.t	14 Jan 2003 09:26:03 -0000 @@ -95,9
 > +95,9 @@ my $logger = Log::Log4perl->get_logger("groceries.beer");
 >
 >
 > -$logger->fatal(['fatal message',1234,'foo','bar']);
 > -$logger->warn(['warning message',3456,'foo','bar']);
 > -$logger->debug(['debug message',99,'foo','bar']);
 > +$logger->fatal('fatal message',1234,'foo','bar');
 > +$logger->warn('warning message',3456,'foo','bar');
 > +$logger->debug('debug message',99,'foo','bar');
 >
 > my $sth = $dbh->prepare('select * from log4perltest'); $sth->execute;
 >  Index: t/035JDBCAppender.t
 > ===================================================================
 > RCS file: /cvsroot/log4perl/Log-Log4perl/t/035JDBCAppender.t,v
 > retrieving revision 1.1 diff -a -u -r1.1 035JDBCAppender.t ---
 > t/035JDBCAppender.t	27 Dec 2002 00:03:28 -0000	1.1 +++
 > t/035JDBCAppender.t	14 Jan 2003 09:26:03 -0000 @@ -94,9 +94,9 @@
 >
 > my $logger = Log::Log4perl->get_logger("groceries.beer");
 >
 > -$logger->fatal(['fatal message',1234,'foo','bar']);
 > -$logger->warn(['warning message',3456,'foo','bar']);
 > -$logger->debug(['debug message',99,'foo','bar']);
 > +$logger->fatal('fatal message',1234,'foo','bar');
 > +$logger->warn('warning message',3456,'foo','bar');
 > +$logger->debug('debug message',99,'foo','bar');
 >
 > my $sth = $dbh->prepare('select * from log4perltest'); $sth->execute;
 >
-- 
Happy Trails . . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510) 525-5217

[log4perl-devel] Re: Log::Log4perl::Layout::PatternLayout - Pattern Layout

[Mike S. <msc...@ao...>]

ma...@st... wrote:

> Many thanks for your excellent module. I'm just starting to grasp the 
> flexible power that it gives to logging. 

Thanks -- and keep digging :)

> To make some small contribution, I think there is a typo in the 
> 'Fine-tuning with curlies' section of the following manpage:
>
> http://log4perl.sourceforge.net/releases/Log-Log4perl/docs/html/Log/Log4perl/Layout/PatternLayout.html
>
> in that the file name placeholder is given as %f (lowercase) instead 
> of %F.
>
You are absolutely correct. I've fixed the typo in CVS, the web page 
will be updated with the upcoming 0.28 release. Thanks!

-- 
-- Mike

Mike Schilli
log...@pe...

[log4perl-devel] [Fwd: Log::Log4perl::Layout::PatternLayout - Pattern Layout]

[Mike S. <msc...@ao...>]

... forwarded:

[log4perl-devel] Patch for suggested new behaviour

[<msc...@ao...>]

Hey Kevin,

here's a patch implementing what I've suggested earlier -- I haven't tested the new functionality extensivly, but the patch passes the existing test suite.

There's a couple of open issues :

[1] There's a "join" command in generate_noop_coderef() which concatenates the message chunks together to somehow log the message later if a config_and_watch event occurs. Think that won't work even with the old DBI appender -- right ;) ?

[2] In case a log event passes several message chunks on to an appender, could there be appenders which want to render each chunk individually? Just a thought, maybe not.

The code in the patch is not well commented, hope it's somehow decipherable :) Basically what I did is slip in a default input_filter method into the filter's package if it doesn't define one. The input_filter method will take a array ref of parameters (always) and return either a single string (in case the appender wants to collapse) or an array ref with the new elements. Arguments to debug(), info(), etc. are now plain arguments, hashes indicate parameter with special filtering needs. Code refs is also evaluated.

Please let me know if that all makes sense ... :)

-- 
-- Mike

############################
# Mike Schilli             #
# log...@pe... #
# http://perlmeister.com   #
# log4perl.sourceforge.net #
############################

Re: [log4perl-devel] env-vars in log4perl config file

[Mike S. <msc...@ao...>]

ke...@go... wrote:

>>
>> 1) If a message chunk is supposed to be run through a
>> "message filter", specify it as a hashref, with entries for "filter" 
>> and "value":
>>
>> log("Here's, the dump: ==>",     { filter => \&Data::Dumper::Dump, 
>>       value => $someref },
>>     "<==");
>
>
> I'm confused, where would this be called?  Is this part of the public 
> API or the internal one?

Sorry, I wasn't clear on that one, I meant the public logging API:

    $logger->debug("Here's, the dump: ==>",   
                              { filter => \&Data::Dumper::Dump,  value 
=> $someref },
                               "<==");

>
> Ahh, very nice.  Then the DBI appender wouldn't have to use an 
> arrayref to protect against collapsing the list into a string.
>
> But I have an alternative to checking to see whether the appender 
> class defines a method.  Calling class->can() is slow (?) and error-prone,

Slow yes, but it'd be called only once at Log::Log4perl init() time -- 
so its impact is negligable. Error-prone? I'm not aware of any problems.

> and since we're trying to take advantage of third-party appender 
> modules, we don't always have the option to define our method in their 
> class. 

The 3rd party module decides whether it wants a certain format or not. 
Log::Log4perl doesn't really need to interfere -- we just need to know, 
so we call the module's format-adapting routine correctly.

> How about an appender-specific config option, like
>
>        #leave incoming data alone
>    log4perl.appender.A2.input_filter = 0
>
>        #or muck about with the data
>    log4perl.appender.A2.input_filter = sub {Data::Dumper(shift)} 

As an additional option to control the 3rd party module's behaviour, 
that's probably nice-to-have. But I think most modules (like DBI) know 
what they want and don't even want that to be modified by the system 
using the appender.

Also, Data::Dumper wouldn't be a typical choice for an input filter ([1] 
and [2] as outlined in the last mail should be totally separate issues).

input_filter should be more likely something like a method which accepts 
the arguments of the debug/info/...() call issued by the Log::Log4perl 
user as an arrayref and which then has the opportunity to juggle them 
around (like skip one, collapse some, etc.) and then Log::Log4perl would 
pass on the new array to the appender's log() method.

E.g., user says

    $logger->debug("1", "2", "3", "4");

then Log::Log4perl would pass that on to 
Log::Log4perl::Appender::DBI->input_filter as

    ["1", "2", "3", "4"]

which would modify it to skip the last element (e.g. because the DB 
table only has 3 rows):

    ["1", "2", "3"]

which would be passed on to DBI::log() as

    ("1", "2", "3")

which would end up in the DB as three different columns. Does that make 
sense?

-- 
-- Mike

Mike Schilli
log...@pe...

Re: [log4perl-devel] env-vars in log4perl config file

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

msc...@ao... wrote:
> In a message dated 1/10/2003 8:24:13 PM Eastern Standard Time, "Wiggins d'Anconia" <wi...@da...> writes:
> 
> 
> 1) If a message chunk is supposed to be run through a
> "message filter", specify it as a hashref, with entries for "filter" and "value":
> 
> log("Here's, the dump: ==>", 
>     { filter => \&Data::Dumper::Dump, 
>       value => $someref },
>     "<==");

I'm confused, where would this be called?  Is this part of the public 
API or the internal one?



> 2) Some appenders expect message chunks in a specific
> format. DBI wants columns, for Screen and other
> Log::Dispatch appenders we want to collapse all chunks to a
> single string.
> 
> If an appender class defines an input_filter() method
> (which we detect at appender init time via can() and then
> cache it), all input will be passed through this method by
> Log4perl before forwarding message chunks to the
> appender's log method.
> 
> DBI's input_filter() would then just return the arguments
> passed to it, which Log4perl would then pass on to log().

Ahh, very nice.  Then the DBI appender wouldn't have to use an arrayref 
to protect against collapsing the list into a string.

But I have an alternative to checking to see whether the appender class 
defines a method.  Calling class->can() is slow (?) and error-prone, and 
since we're trying to take advantage of third-party appender modules, we 
don't always have the option to define our method in their class.  How 
about an appender-specific config option, like

		#leave incoming data alone
	log4perl.appender.A2.input_filter = 0

		#or muck about with the data
	log4perl.appender.A2.input_filter = sub {Data::Dumper(shift)}

The default would be to collapse a list into a string, calling any 
coderefs along the way, unless the appender class defines a class 
variable called something like LOG4PERL_INPUT_FILTER, in which case that 
would be the default, overrideable by data within the config.

So Appender::DBI could define 
$Log::Log4perl::Appender::DBI::LOG4PERL_INPUT_FILTER = 0

and then the logging methods would just be

	$logger->info(1234,'bob smith','created account');


> These suggestions would require some changes to the current
> development release, sorry I'm coming up with them so late
> in the game, but it's probably still ok to change it
> because we haven't rolled out the new functionality yet.

That's fine, that's why they call it "development" ;-)



-- 
Happy Trails . . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510) 525-5217

Re: [log4perl-devel] env-vars in log4perl config file

[<msc...@ao...>]

In a message dated 1/10/2003 8:24:13 PM Eastern Standard Time, "Wiggins d'Anconia" <wi...@da...> writes:

> This seems like a great idea, similar to the way 
> [...] POE uses "Filters" 

I thought a little harder about this issue and figured we
really need semantics for two different items:

1) Some appenders expect a certain format of the message
chunks passed on to them (like DBI expects columns).

2) Some message chunks we want to run through filters
before logging them (like some refs we want to log as
Data::Dumper output).

With the current Log::Log4perl::Appender::DBI expecting the
message chunks to arrive as an arrayref, it's difficult to
distinguish the two.

I juggled with POE filters (great idea, Wiggins!), and came up with that: 

Here's some new syntax we could use to embody both
requirements:

1) If a message chunk is supposed to be run through a
"message filter", specify it as a hashref, with entries for "filter" and "value":

log("Here's, the dump: ==>", 
    { filter => \&Data::Dumper::Dump, 
      value => $someref },
    "<==");

Arg1 and arg3 of this call are regular strings, the 2nd arg
specifies that $someref is supposed to be run through the
sub Date::Dumper::Dump and its output is to be logged
(optionally "filter" could specify a class, which
implements some POE-style get() and put() methods).

This filter is being run *before* the message is passed on
to any appenders.

2) Some appenders expect message chunks in a specific
format. DBI wants columns, for Screen and other
Log::Dispatch appenders we want to collapse all chunks to a
single string.

Here's how we could distinguish these, without disrupting
traditional Log::Dispatch-appenders:

If an appender class defines an input_filter() method
(which we detect at appender init time via can() and then
cache it), all input will be passed through this method by
Log4perl before forwarding message chunks to the
appender's log method.

DBI's input_filter() would then just return the arguments
passed to it, which Log4perl would then pass on to log().

If the appender doesn't define an input_filter() method,
Log4perl will run the message chunks through a default
input_filter(), which will just join all chunks together to a
single string (again, instead of the method we could have a filter class, like POE).


These suggestions would require some changes to the current
development release, sorry I'm coming up with them so late
in the game, but it's probably still ok to change it
because we haven't rolled out the new functionality yet.

Kevin and all, should we go this route or can you
think of anything else we might want in the future? Now is
the time ... any new ideas are of course welcome!

-- 
-- Mike

############################
# Mike Schilli             #
# log...@pe... #
# http://perlmeister.com   #
# log4perl.sourceforge.net #
############################

Re: [log4perl-devel] env-vars in log4perl config file

[Wiggins d'A. <wi...@da...>]

Mike Schilli wrote:

> We're currently evaluating the idea of passing in an options hash before
> the real message comes:
> 
>     $logger->log({format => "dbi"}, $col1, $col2, $col3);
> 
> and
> 
>     $logger->log({format => "dump"}, $some_ref);
> 
> The advantage of the latter over something like
> 
>     $logger->log(Data::Dumper::Dump($some_ref));
> 
> is obviously the performance gain in case the message gets suppressed.
> 

This seems like a great idea, similar to the way (sorry I have it on the 
brain right now) POE uses "Filters" that basically work as translators 
on either end of a pipe.  You tell one end of the pipe what to expect as 
a filter when the data comes out, and on the other end you create a 
filter and run the output through it before sticking it in the pipe, 
similar to saving state, or "formatting".

Just a couple of thoughts, having a look at the POE implementation might 
give further ideas on this. And since our app most likely will be using 
POE with Log4perl it would help me out too ;-), since POE filters do not 
depend on the rest of POE.

http://danconia.org

Re: [log4perl-devel] env-vars in log4perl config file

[Mike S. <msc...@ao...>]

Jim Cromie wrote:

 > wrt to my use of AUTOLOAD to give Auto-Categorization,
 > is that something for which you might accept a feature patch ?

Sorry for the late response on this, but finally I got around to it: In
short, I like the idea of having subroutine-based loggers, but I'm a
little unclear on how your implementation works and if it meets our
performance requirements. It looks to me like you're paying a high
performance penalty by AUTOLOADing and calling caller(), both of which
slow down the application significantly. One of the core Log::Log4perl
principles is that the overhead of logging should always be negligable.
Can you elaborate a bit more about how :autocategorize works and what
the perfomance impact is?

Also, I like your idea of having some kind of logic for Data::Dumper-ing
nested structures. However, we can't just use it for every reference
that comes in, because this syntax is somewhat taken by the new DBI
appender, which lets you specify the DB columns this way:

     $logger->log([$col1, $col2, $col3]);

We're currently evaluating the idea of passing in an options hash before
the real message comes:

     $logger->log({format => "dbi"}, $col1, $col2, $col3);

and

     $logger->log({format => "dump"}, $some_ref);

The advantage of the latter over something like

     $logger->log(Data::Dumper::Dump($some_ref));

is obviously the performance gain in case the message gets suppressed.

-- 
-- Mike

Mike Schilli
log...@pe...

[log4perl-devel] Log::Log4perl Recipe of the Week (#11)

[<log...@pe...>]

Welcome to the Log::Log4perl recipe of the week. Today:

============================================================
Log::Log4perl Recipe of the Week (#11):

I keep getting duplicate log messages! What's wrong?
============================================================

Having several settings for related categories in the
Log4perl configuration file sometimes leads to a phenomenon
called "message duplication". It can be very confusing at
first, but if thought through properly, it turns out that
Log4perl behaves as advertised. But, don't despair, of
course there's a number of ways to avoid message duplication
in your logs.

Here's a sample Log4perl configuration file that produces
the phenomenon:

    log4perl.logger.Cat        = ERROR, Screen
    log4perl.logger.Cat.Subcat = WARN, Screen

    log4perl.appender.Screen   = Log::Dispatch::Screen
    log4perl.appender.Screen.layout = SimpleLayout

It defines two loggers, one for category "Cat" and one for
"Cat::Subcat", which is obviously a subcategory of "Cat".
The parent logger has a priority setting of ERROR, the child
is set to the lower "WARN" level.

Now imagine the following code in your program:

    my $logger = get_logger("Cat.Subcat");
    $logger->warn("Warning!");

What do you think will happen? An unexperienced Log4perl
user might think: "Well, the message is being sent with
level WARN, so the "Cat::Subcat" logger will accept it and
forward it to the attached "Screen" appender. Then, the
message will percolate up the logger hierarchy, find the
"Cat" logger, which will suppress the message because of its
ERROR setting." But, perhaps surprisingly, what you'll get
with the code snippet above is not one but two log messages
written to the screen:

    WARN - Warning!
    WARN - Warning!

What happened? The culprit is that once the logger
"Cat::Subcat" decides to fire, it will forward the message
*unconditionally* to all directly or indirectly attached
appenders. The "Cat" logger will never be asked if it wants
the message or not -- the message will just be pushed
through to the appender attached to "Cat".

One way to prevent the message from bubbling up the logger
hierarchy is to set the "additivity" flag of the subordinate
logger to 0:

    log4perl.logger.Cat            = ERROR, Screen
    log4perl.logger.Cat.Subcat     = WARN, Screen
    log4perl.additivity.Cat.Subcat = 0

    log4perl.appender.Screen   = Log::Dispatch::Screen
    log4perl.appender.Screen.layout = SimpleLayout

The message will now be accepted by the "Cat::Subcat"
logger, forwarded to its appender, but then "Cat::Subcat"
will suppress any further action. While this setting avoids
duplicate messages as seen before, it is often not the
desired behaviour. Messages percolating up the hierarchy are
a useful Log4perl feature.

If you're defining *different* appenders for the two
loggers, one other option is to define an appender threshold
for the higher-level appender. Typically it is set to be
equal to the logger's level setting:

    log4perl.logger.Cat           = ERROR, Screen1
    log4perl.logger.Cat.Subcat    = WARN, Screen2

    log4perl.appender.Screen1   = Log::Dispatch::Screen
    log4perl.appender.Screen1.layout = SimpleLayout
    log4perl.appender.Screen1.Threshold = ERROR

    log4perl.appender.Screen2   = Log::Dispatch::Screen
    log4perl.appender.Screen2.layout = SimpleLayout

Since the "Screen1" appender now blocks every message with a
priority less than ERROR, even if the logger in charge lets
it through, the message percolating up the hierarchy is
being blocked at the last minute and *not* appended to
"Screen1".

So far, we've been operating well within the boundaries of
the Log4j standard, which Log4perl adheres to. However, if
you would really, really like to use a single appender and
keep the message percolation intact without having to deal
with message duplication, there's a non-standard solution
for you:

    log4perl.logger.Cat        = ERROR, Screen
    log4perl.logger.Cat.Subcat = WARN, Screen

    log4perl.appender.Screen   = Log::Dispatch::Screen
    log4perl.appender.Screen.layout = SimpleLayout

    log4perl.oneMessagePerAppender = 1

The "oneMessagePerAppender" flag will suppress duplicate
messages to the same appender. Again, that's non-standard.
But way cool :).


Have fun! Until next week.

-- Mike

###################################
# Mike Schilli                    #
# log...@pe...        #
# http://perlmeister.com          #
# http://log4perl.sourceforge.net #
###################################

Re: [log4perl-devel] logging unix timestamp?

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

After thinking about it a little, I think I know why--it's not platform 
independent (epochs differ on different platforms).  No pid, no 
hostname, no time()--java surely does not subscribe to the "easy things 
should be easy" philosphy.


Msc...@ao... wrote:
> In a message dated 1/7/03 3:12:12 PM Pacific Standard Time, 
> ke...@go... writes:
> 
>> Hey, am I missing something, or is there no way to log the current
>> seconds-in-the-epoch (time()) without writing a custom cspec?  It's not
>> part of the java SimpleDateFormat.
> 
> 
> 
> Hmm, strange, doesn't look like there is. There's %r for the number of 
> seconds since program start (in PatternLayout), and all sorts of stuff 
> in SimpleDateFormat, but no unix time. It'd be easy to implement, but 
> since we've got custom specs, we're all set :).
> 
> -- Mike


-- 
Happy Trails . . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510) 525-5217

Re: [log4perl-devel] logging unix timestamp?

[<Msc...@ao...>]

In a message dated 1/7/03 3:12:12 PM Pacific Standard Time, ke...@go... 
writes:

> Hey, am I missing something, or is there no way to log the current 
> seconds-in-the-epoch (time()) without writing a custom cspec?  It's not 
> part of the java SimpleDateFormat.
> 

Hmm, strange, doesn't look like there is. There's %r for the number of 
seconds since program start (in PatternLayout), and all sorts of stuff in 
SimpleDateFormat, but no unix time. It'd be easy to implement, but since 
we've got custom specs, we're all set :).

-- Mike

[log4perl-devel] logging unix timestamp?

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

Hey, am I missing something, or is there no way to log the current 
seconds-in-the-epoch (time()) without writing a custom cspec?  It's not 
part of the java SimpleDateFormat.

-- 
Happy Trails . . .

Kevin M. Goess
(and Anne and Frank)
904 Carmel Ave.
Albany, CA  94706
(510) 525-5217

Re: [log4perl-devel] Message Duplication

[<Msc...@ao...>]

In a message dated 1/7/03 10:31:08 AM Pacific Standard Time, 
mra...@ci... writes:

> As the log level for the CCBU.Patch is set to ERROR, I would expect (even if 
> the logger decides to fire for a WARN message from CCBU.Patch.Ticket ), 
> appender for the CCBU.Patch not pickup the WARN message that is started 
> from CCBU.Patch.Ticket. So eventually there should be just one WARN message 
> for CCBU.Patch.Ticket and CCBU.Patch should ignore WARN log as it is below 
> the log level set for its appender?

That's exactly the catch with Log4j. Once one logger has decided that the 
message is going to be logged, it is forwarded to all appenders 
*unconditonally* (except, of course, appender thresholds have the last word). 
In your example, this means that CCBU.Patch won't run any checks once 
CCBU.Patch.Ticket has already decided to fire. That's a concept that's, 
admittedly, sometimes confusing -- but well established in the log4j 
community.

-- Mike
Mike Schilli
log...@pe...

Fwd: [log4perl-devel] Message Duplication

[<Msc...@ao...>]

Re: [log4perl-devel] Message Duplication

[<Msc...@ao...>]

In a message dated 1/7/03 8:52:15 AM Pacific Standard Time, ke...@go... 
writes:

> >   log4perl.logger.CCBU.Patch=ERROR, Log
> >   log4perl.logger.CCBU.Patch.Ticket=WARN,Log
> 

Actually, these lines in your configuration file are defining this behaviour. 
If the Patch.Ticket logger decides to fire, it will not only forward it to 
the message to the attached appender, but also have it bubble up the 
hierarchy, where it will be forwarded to all appenders on the way up (to the 
appender attached to the "Patch" logger in this case).

There's an explanation of this as well as a solution on

    <A HREF="http://www.perl.com/pub/a/2002/09/11/log4perl.html?page=3">http://www.perl.com/pub/a/2002/09/11/log4perl.html?page=3</A>

in the "Beginner's Pitfalls" section. 

And, I might add, the trick Kevin showed you with

    log4perl.oneMessagePerAppender = 1

would probably cause an outrage with the log4j folks. But it is elegant, 
nevertheless :).

Let me know if this answers your question.

-- Mike