From: <msc...@ao...> - 2002-12-28 08:44:21
|
In a message dated 12/27/2002 6:02:45 PM Eastern Standard Time, Kevin Goess <ke...@go...> writes: >Ha! That's in our CVS code right now, just hasn't been released yet. ... and the development release (containing the new functionality) is available for download here: http://log4perl.sourceforge.net/releases/Log-Log4perl-0.28dev.tar.gz -- -- Mike ############################ # Mike Schilli # # log...@pe... # # http://perlmeister.com # # log4perl.sourceforge.net # ############################ |
From: <msc...@ao...> - 2003-01-12 20:59:43
|
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 # ############################ |
From: Kevin G. <ke...@go...> - 2003-01-13 17:51:51
|
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 |
From: Mike S. <msc...@ao...> - 2003-01-13 18:42:03
|
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... |
From: Jim C. <jc...@di...> - 2003-01-02 15:54:41
|
msc...@ao... wrote: >In a message dated 12/27/2002 6:02:45 PM Eastern Standard Time, Kevin Goess <ke...@go...> writes: > > > >>Ha! That's in our CVS code right now, just hasn't been released yet. >> >> > >... and the development release (containing the new functionality) is available for download here: > http://log4perl.sourceforge.net/releases/Log-Log4perl-0.28dev.tar.gz > > > thanks guys - it just works! wrt to my use of AUTOLOAD to give Auto-Categorization, is that something for which you might accept a feature patch ? I was thinking of a couple of options on how to do it. use Log::Log4perl qw(:autocategorize); use Log::Log4perl::AutoCat; a whole new class seems overkill to add one function, but you may have philosophical objections to an import-tag that causes sub AUTOLOAD {} to be compiled. anyway, thx again |
From: Mike S. <msc...@ao...> - 2003-01-10 22:28:17
|
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... |
From: Wiggins d'A. <wi...@da...> - 2003-01-11 01:23:31
|
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 |
From: Mike S. <msc...@ao...> - 2003-01-14 21:28:22
|
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... |
From: Mike S. <msc...@ao...> - 2003-01-22 02:10:01
|
jc...@di... wrote: > Mike, > > do you want to carry this conversation over to log4perl-devel ? > if so, cc them in, and Ill follow it over. Sure ... everybody, please see below ... > > >> >> 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? >> > > Ive taken a 2nd swing at getting around the everytime AUTOLOAD, caller > problem. > > attached is a generic explanation which I put to perlmonks today, and > will put to perl-porters later, > after another round of nearest-neighbor reality checks. > > I also posted an earlier version of this to perlmonks.org, if youve > ever ben there > >------------------------------------------------------------------------ > >#!/usr/local/bin/perl -w >use strict; >no strict 'refs'; > >=for request for assistance > >im trying to work out an auto-categorization feature for >Log::Log4perl::AutoCategorize, a notional extension to its namesake. > >My exploratory version used AUTOLOAD on every Logger->invoke, and used >caller() to dynamically extract caller context, which is then used for >logging decisions. > >This works nicely, except for speed; it would be great to capture this >info once, either at compile phase, or on 1st invocation of an >autoload-vivified subroutine. > >=head GOAL > >use Log::Log4perl::AutoCategorize ( alias_as => 'Logger' ); > ># want simple invocation >Logger->debug(@_); > ># to invoke a late-vivified, custom-named function >Logger->debug_<$callerpkg,$caller_sub,$caller_ln>(@_); > ># which will be mapped at 1st use according to the config ># sub {return undef} is CONSTANT; > >=head1 PROBLEM > >I mentally file this as a function-name munging problem cuz I hope it >happens at compile time. That said, Im trying to solve it with >1st-time AUTOLOAD handling, cuz thats what I know. So, with these >blinders applied; > >Munging: > changing the subroutine-ref added to %__PACKAGE_:: > > >Inner: > producing munged name from user context. > lexical context should be available. > A::AUTOLOAD adds new sub to symbol table, either munged or unmunged > >Outer (heres where my problems are): > > wo munging, symtab entry is call-once to AUTOLOAD > w munging, munged name is not available on 2nd try > > getting Logger->debug() to invoke AUTOLOAD repeatedly. > w munging, this is given, as lookup fails > > in sub cooperative_dynamic_name_invoke() below, Im doing the munge > externally, > > > >=head1 Hunch > >I think optimizer.pm, B::Generate are probably the tools, but Ive got >insufficient fu of B::* to understand where to start (I have read, and >will reread. I hope that this might be an 'intersting app' of >optimizer.pm; with sufficient merit to garner porter interest. > > 1. when to 'require optimizer extend ...' > whats it mean to do so in INIT{} or CHECK {} blocks ? > or do it directly in AUTOLOAD {} ? > > 2. how to recognize (particularly at compile time) whether AUTOLOAD > would eventually be called, or how to get the lexical scope > during compilation. a compile-time analogue to caller() would be > cool. > >=cut > >package A; >use Data::Dumper; >use vars qw($AUTOLOAD); >use Carp 'cluck'; > >sub AUTOLOAD { > # compile and goto& munged method-name > # > (my $meth = $AUTOLOAD) =~ s/.*:://; > return if $meth eq 'DESTROY'; > my ($package, $filename, $line, $subroutine) = caller(0); > > my $buf = "<$meth>: $package, $filename, $line, $subroutine\n"; > $buf =~ s|[\./]||g; > print "creating: $buf"; > > *{'A::'.$meth} = sub { > print "invoked: $buf"; # force string interpolation, no closure (dont need) > # print "\twith ", Dumper (\@_); > }; > goto &{'A::'.$meth}; >} > >package main; >A::auto("string{}"); >cooperative_dynamic_name_invoke(); >print "done\n"; > >sub cooperative_dynamic_name_invoke { > > # macro-like invoke of auto-names > # invoker help needed; by creating custom sub-name > # for each lexical invocation > > foreach (1..2) { > > # autoload compiles sub on 1st iteration > # (and vivifies name in symbol table) > # 2nd time, new asub called directly > > my $munge = "dyn_name_000"; # wo reinit, would just make 3,4 > $munge++; # this doesnt give string++, but irrelevant to test > $munge = undef; > A->$munge("1st try"); > > $munge++; > A->$munge("2nd try\n"); > > $munge++; > A->$munge("3rd try\n"); > > } >} > >__END__ > > > >=cut > >use optimizer extend => sub { > print "dump ", Dumper \@_ > if 0 > #or $_[0]->name() eq "goto" > #or ref $_[0] =~ /CV/i > ; > # =~ /__ANON__/; >}; > >sub loop { > foreach (1..2) { > # if hashref were CONSTANT, and not rebuilt for each invocation, > # it could preserve the > A::fancy({arb=>1},1); > A::fancy({ok=>2},2); > A::auto({}); > A::auto({}); > } > use Data::Dumper; > print Dumper (\%A::); >} > > > >__END__ > > > -- -- Mike Mike Schilli log...@pe... |