log4perl-devel

[log4perl-devel] Docs/Test cases for message_filter

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

Hey Kevin,

just finished a couple of changes:

* added Log::Log4perl::Appender::TestArrayBuffer as a test appender capable of handling array refs.

* added test cases in 015fltmsg.t (for some strange reason 015 was still available :).

* looks like we can't use "sub {...}" as the syntax for filter_message coderefs because it's taken by the perl hooks already which are executed at config time. filter_message, on the other hand, needs to run at log time. For now, I've changed the code to expect a function *name* instead of a code ref -- see the latest addition to the Log::Log4perl::Appender docs ... thoughts?

* While I wrote the test cases, I felt regrets that we don't have a generic interface (other than in the DBI appender) to run PatternLayout substitutions on multiple-argument appender calls. Like $log->debug("%d", "%m") -- could we do that somehow? Brain storming ideas? :)

-- 
-- Mike

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

[log4perl-devel] Re: Docs/Test cases for message_filter

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

 > * looks like we can't use "sub {...}" as the syntax for
 > filter_message coderefs because it's taken by the perl hooks already
 > which are executed at config time. filter_message, on the other hand,
 > needs to run at log time. For now, I've changed the code to expect a
 > function *name* instead of a code ref -- see the latest addition to
 > the Log::Log4perl::Appender docs ... thoughts?

PropertyConfigurator is already special-casing away the cspecs:

	$val = eval_if_perl($val) if $key !~ /\.cspec\./;

why no just add another special case? Something like

	$val = eval_if_perl($val)
		if $key !~ 	/\.(cspec\.[^\.]+|filter_message)$/;


I just noticed this in the Appender.pm docs:

    B<Please note that the standard appenders in the Log::Dispatch
    hierarchy will choke on a bunch of messages passed to them as an
    array reference. You can't use C<filter_message = 0> (or the
    function name syntax defined below) on them.

but the standard appenders will work fine as long as the filter_message 
function returns a string, not an arrayref, right?


And it just occurred to me, if we're eventually going to implement log4j 
event filters, are we going to get naming confusion between 
filter_message and filter?   Should we consider other options for 
filter_message?  alter_message, munge_message, refashion_message?



-- 
Happy Trails . . .

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

Re: [log4perl-devel] Docs/Test cases for message_filter

[Jim C. <jc...@di...>]

msc...@ao... wrote:

>Hey Kevin,
>
>just finished a couple of changes:
>

I dont yet grok this filtering, ( I havent tried yet - so thats 
understandable),
but its potentially related to the AutoCategorization feature I sent 
earlier.

If you recall, my patch  wrapped Log4perl with another class.
that class handled all logging requests via AUTOLOAD;

     $logCat = $AUTOLOAD . glom(caller())
    then tested that $logCat for writability

    IIRC:
     if ( $logger->is_$logCat()) { # ok log it.


All prohibitively expensive...


enter AUTOMUNGE - (my name for it)

Ive now succeeded (partly) in using   optimizer.pm   from to alter the 
optree
where AUTOLOAD is called,

with this MUNGE in place,  every invocation gets a unique function-name
to call, so fn_001 and fn_002 can be customized.  The customization could
be able to consider *ALL* the log/dont-log criteria, and produce a yes/no
decision.  All no's could be reduced to a no-op.

All of above requires that log/no-log decisions dont have to change during
runtime, a reasonable constraint I hope.

Number of custom-funcs is linear with size of Log-config, not number
of places in client-code where a Logging call is made.  This is cuz of
scoping rules - the log-conf may choose not to override any configs that
apply more broadly - and AUTOLOAD can detect that shared config and
use its custom loggers - not building new subs.



with AUTOCATEGORIZE in place,   you have  detailed control of what gets
written ( ie log filtering )



heres some output from my experiment:


# optimizer phase - examines chains of ops which make a function call
# rejects some, works on others.
# more optree-fu needed.

junkop-chain:  pushmark const null
junkop-chain:  pushmark const padsv
junkop-chain:  pushmark const null
junkop-chain:  pushmark const padsv
junkop-chain:  pushmark const null
junkop-chain:  pushmark const null

# by visual inspection of perl -MO=Concise a2.pl
# I found that pushmark, const+, method_named is
# the/an opcode pattern for AUTOLOAD invoke

matched op-chain:  pushmark const method_named
package: A
munged-method-name: my_debug_001

# created &A::my_debug_001()

matched op-chain:  pushmark const method_named
package: A
munged-method-name: my_info_002
matched op-chain:  pushmark const method_named
package: A
munged-method-name: my_info_003
matched op-chain:  pushmark const method_named
package: A
munged-method-name: something_004
matched op-chain:  pushmark const method_named
package: A
munged-method-name: other_005
matched op-chain:  pushmark const const method_named
package: A
munged-method-name: other_006
matched op-chain:  pushmark const const const method_named
package: A
munged-method-name: ary3_007
junkop-chain:  pushmark const const const anonlist null
junkop-chain:  pushmark const anonlist null
junkop-chain:  pushmark const const const anonhash null
junkop-chain:  pushmark const anonhash null
junkop-chain:  pushmark const entersub
junkop-chain:  pushmark const gv
junkop-chain:  pushmark const nextstate
junkop-chain:  pushmark const nextstate
junkop-chain:  pushmark const null
junkop-chain:  pushmark const nextstate

1:  
# first run - AUTOLOAD is creating pre-munged functions here,
# cuz the name is already customized in the optree.

creating <my_debug_001> my_debug_001_main_a2pl_19
 calling <my_debug_001> my_debug_001_main_a2pl_19 (aval)
creating <my_info_002> my_info_002_main_a2pl_20
 calling <my_info_002> my_info_002_main_a2pl_20 (1)
creating <my_info_003> my_info_003_main_a2pl_21
 calling <my_info_003> my_info_003_main_a2pl_21 (2)
creating <something_004> something_004_main_a2pl_22
 calling <something_004> something_004_main_a2pl_22 (anything)
creating <other_005> other_005_main_a2pl_23
 calling <other_005> other_005_main_a2pl_23 (1thing)
creating <other_006> other_006_main_a2pl_25
 calling <other_006> other_006_main_a2pl_25 (1 2)
creating <ary3_007> ary3_007_main_a2pl_26
 calling <ary3_007> ary3_007_main_a2pl_26 (1 2 3)
creating <ary1> ary1_main_a2pl_27
 calling <ary1> ary1_main_a2pl_27 (ARRAY(0x8130c24))
 calling <ary1> ary1_main_a2pl_27 (HASH(0x8130c24))
creating <missed_none_args> missed_none_args_main_a2pl_31
 calling <missed_none_args> missed_none_args_main_a2pl_31 ()
creating <classmeth> classmeth_main_a2pl_32
 calling <classmeth> classmeth_main_a2pl_32 ()
creating <classmeth2> classmeth2_main_a2pl_33
 calling <classmeth2> classmeth2_main_a2pl_33 (2)
2:
 calling <my_debug_001> my_debug_001_main_a2pl_19 (aval)
 calling <my_info_002> my_info_002_main_a2pl_20 (1)
 calling <my_info_003> my_info_003_main_a2pl_21 (2)
 calling <something_004> something_004_main_a2pl_22 (anything)
 calling <other_005> other_005_main_a2pl_23 (1thing)
 calling <other_006> other_006_main_a2pl_25 (1 2)
 calling <ary3_007> ary3_007_main_a2pl_26 (1 2 3)
 calling <ary1> ary1_main_a2pl_27 (ARRAY(0x8241360))
 calling <ary1> ary1_main_a2pl_27 (HASH(0x8241360))
 calling <missed_none_args> missed_none_args_main_a2pl_31 ()
 calling <classmeth> classmeth_main_a2pl_32 ()
 calling <classmeth2> classmeth2_main_a2pl_33 (2)
done
[jimc@harpo auto]$