diff options
Diffstat (limited to 'lib/Log/Log4perl/FAQ.pm')
| -rw-r--r-- | lib/Log/Log4perl/FAQ.pm | 2682 |
1 files changed, 2682 insertions, 0 deletions
diff --git a/lib/Log/Log4perl/FAQ.pm b/lib/Log/Log4perl/FAQ.pm new file mode 100644 index 0000000..c0c068b --- /dev/null +++ b/lib/Log/Log4perl/FAQ.pm @@ -0,0 +1,2682 @@ +1; + +__END__ + +=encoding utf8 + +=head1 NAME + +Log::Log4perl::FAQ - Frequently Asked Questions on Log::Log4perl + +=head1 DESCRIPTION + +This FAQ shows a wide variety of +commonly encountered logging tasks and how to solve them +in the most elegant way with Log::Log4perl. Most of the time, this will +be just a matter of smartly configuring your Log::Log4perl configuration files. + +=head2 Why use Log::Log4perl instead of any other logging module on CPAN? + +That's a good question. There's dozens of logging modules on CPAN. +When it comes to logging, people typically think: "Aha. Writing out +debug and error messages. Debug is lower than error. Easy. I'm gonna +write my own." Writing a logging module is like a rite of passage for +every Perl programmer, just like writing your own templating system. + +Of course, after getting the basics right, features need to +be added. You'd like to write a timestamp with every message. Then +timestamps with microseconds. Then messages need to be written to both +the screen and a log file. + +And, as your application grows in size you might wonder: Why doesn't +my logging system scale along with it? You would like to switch on +logging in selected parts of the application, and not all across the +board, because this kills performance. This is when people turn to +Log::Log4perl, because it handles all of that. + +Avoid this costly switch. + +Use C<Log::Log4perl> right from the start. C<Log::Log4perl>'s C<:easy> +mode supports easy logging in simple scripts: + + use Log::Log4perl qw(:easy); + Log::Log4perl->easy_init($DEBUG); + + DEBUG "A low-level message"; + ERROR "Won't make it until level gets increased to ERROR"; + +And when your application inevitably grows, your logging system grows +with it without you having to change any code. + +Please, don't re-invent logging. C<Log::Log4perl> is here, it's easy +to use, it scales, and covers many areas you haven't thought of yet, +but will enter soon. + +=head2 What's the easiest way to use Log4perl? + +If you just want to get all the comfort of logging, without much +overhead, use I<Stealth Loggers>. If you use Log::Log4perl in +C<:easy> mode like + + use Log::Log4perl qw(:easy); + +you'll have the following functions available in the current package: + + DEBUG("message"); + INFO("message"); + WARN("message"); + ERROR("message"); + FATAL("message"); + +Just make sure that every package of your code where you're using them in +pulls in C<use Log::Log4perl qw(:easy)> first, then you're set. +Every stealth logger's category will be equivalent to the name of the +package it's located in. + +These stealth loggers +will be absolutely silent until you initialize Log::Log4perl in +your main program with either + + # Define any Log4perl behavior + Log::Log4perl->init("foo.conf"); + +(using a full-blown Log4perl config file) or the super-easy method + + # Just log to STDERR + Log::Log4perl->easy_init($DEBUG); + +or the parameter-style method with a complexity somewhat in between: + + # Append to a log file + Log::Log4perl->easy_init( { level => $DEBUG, + file => ">>test.log" } ); + +For more info, please check out L<Log::Log4perl/"Stealth Loggers">. + +=head2 How can I simply log all my ERROR messages to a file? + +After pulling in the C<Log::Log4perl> module, just initialize its +behavior by passing in a configuration to its C<init> method as a string +reference. Then, obtain a logger instance and write out a message +with its C<error()> method: + + use Log::Log4perl qw(get_logger); + + # Define configuration + my $conf = q( + log4perl.logger = ERROR, FileApp + log4perl.appender.FileApp = Log::Log4perl::Appender::File + log4perl.appender.FileApp.filename = test.log + log4perl.appender.FileApp.layout = PatternLayout + log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n + ); + + # Initialize logging behavior + Log::Log4perl->init( \$conf ); + + # Obtain a logger instance + my $logger = get_logger("Bar::Twix"); + $logger->error("Oh my, a dreadful error!"); + $logger->warn("Oh my, a dreadful warning!"); + +This will append something like + + 2002/10/29 20:11:55> Oh my, a dreadful error! + +to the log file C<test.log>. How does this all work? + +While the Log::Log4perl C<init()> method typically +takes the name of a configuration file as its input parameter like +in + + Log::Log4perl->init( "/path/mylog.conf" ); + +the example above shows how to pass in a configuration as text in a +scalar reference. + +The configuration as shown +defines a logger of the root category, which has an appender of type +C<Log::Log4perl::Appender::File> attached. The line + + log4perl.logger = ERROR, FileApp + +doesn't list a category, defining a root logger. Compare that with + + log4perl.logger.Bar.Twix = ERROR, FileApp + +which would define a logger for the category C<Bar::Twix>, +showing probably different behavior. C<FileApp> on +the right side of the assignment is +an arbitrarily defined variable name, which is only used to somehow +reference an appender defined later on. + +Appender settings in the configuration are defined as follows: + + log4perl.appender.FileApp = Log::Log4perl::Appender::File + log4perl.appender.FileApp.filename = test.log + +It selects the file appender of the C<Log::Log4perl::Appender> +hierarchy, which will append to the file C<test.log> if it already +exists. If we wanted to overwrite a potentially existing file, we would +have to explicitly set the appropriate C<Log::Log4perl::Appender::File> +parameter C<mode>: + + log4perl.appender.FileApp = Log::Log4perl::Appender::File + log4perl.appender.FileApp.filename = test.log + log4perl.appender.FileApp.mode = write + +Also, the configuration defines a PatternLayout format, adding +the nicely formatted current date and time, an arrow (E<gt>) and +a space before the messages, which is then followed by a newline: + + log4perl.appender.FileApp.layout = PatternLayout + log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n + +Obtaining a logger instance and actually logging something is typically +done in a different system part as the Log::Log4perl initialisation section, +but in this example, it's just done right after init for the +sake of compactness: + + # Obtain a logger instance + my $logger = get_logger("Bar::Twix"); + $logger->error("Oh my, a dreadful error!"); + +This retrieves an instance of the logger of the category C<Bar::Twix>, +which, as all other categories, inherits behavior from the root logger if no +other loggers are defined in the initialization section. + +The C<error()> +method fires up a message, which the root logger catches. Its +priority is equal to +or higher than the root logger's priority (ERROR), which causes the root logger +to forward it to its attached appender. By contrast, the following + + $logger->warn("Oh my, a dreadful warning!"); + +doesn't make it through, because the root logger sports a higher setting +(ERROR and up) than the WARN priority of the message. + +=head2 How can I install Log::Log4perl on Microsoft Windows? + +You can install Log::Log4perl using the CPAN client. + +Alternatively you can install it using + + ppm install Log-Log4perl + +if you're using ActiveState perl. + + +That's it! Afterwards, just create a Perl script like + + use Log::Log4perl qw(:easy); + Log::Log4perl->easy_init($DEBUG); + + my $logger = get_logger("Twix::Bar"); + $logger->debug("Watch me!"); + +and run it. It should print something like + + 2002/11/06 01:22:05 Watch me! + +If you find that something doesn't work, please let us know at +log4perl-devel@lists.sourceforge.net -- we'll appreciate it. Have fun! + +=head2 How can I include global (thread-specific) data in my log messages? + +Say, you're writing a web application and want all your +log messages to include the current client's IP address. Most certainly, +you don't want to include it in each and every log message like in + + $logger->debug( $r->connection->remote_ip, + " Retrieving user data from DB" ); + +do you? Instead, you want to set it in a global data structure and +have Log::Log4perl include it automatically via a PatternLayout setting +in the configuration file: + + log4perl.appender.FileApp.layout.ConversionPattern = %X{ip} %m%n + +The conversion specifier C<%X{ip}> references an entry under the key +C<ip> in the global C<MDC> (mapped diagnostic context) table, which +you've set once via + + Log::Log4perl::MDC->put("ip", $r->connection->remote_ip); + +at the start of the request handler. Note that this is a +I<static> (class) method, there's no logger object involved. +You can use this method with as many key/value pairs as you like as long +as you reference them under different names. + +The mappings are stored in a global hash table within Log::Log4perl. +Luckily, because the thread +model in 5.8.0 doesn't share global variables between threads unless +they're explicitly marked as such, there's no problem with multi-threaded +environments. + +For more details on the MDC, please refer to +L<Log::Log4perl/"Mapped Diagnostic Context (MDC)"> and +L<Log::Log4perl::MDC>. + +=head2 My application is already logging to a file. How can I duplicate all messages to also go to the screen? + +Assuming that you already have a Log4perl configuration file like + + log4perl.logger = DEBUG, FileApp + + log4perl.appender.FileApp = Log::Log4perl::Appender::File + log4perl.appender.FileApp.filename = test.log + log4perl.appender.FileApp.layout = PatternLayout + log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n + +and log statements all over your code, +it's very easy with Log4perl to have the same messages both printed to +the logfile and the screen. No reason to change your code, of course, +just add another appender to the configuration file and you're done: + + log4perl.logger = DEBUG, FileApp, ScreenApp + + log4perl.appender.FileApp = Log::Log4perl::Appender::File + log4perl.appender.FileApp.filename = test.log + log4perl.appender.FileApp.layout = PatternLayout + log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n + + log4perl.appender.ScreenApp = Log::Log4perl::Appender::Screen + log4perl.appender.ScreenApp.stderr = 0 + log4perl.appender.ScreenApp.layout = PatternLayout + log4perl.appender.ScreenApp.layout.ConversionPattern = %d> %m%n + +The configuration file above is assuming that both appenders are +active in the same logger hierarchy, in this case the C<root> category. +But even if you've got file loggers defined in several parts of your system, +belonging to different logger categories, +each logging to different files, you can gobble up all logged messages +by defining a root logger with a screen appender, which would duplicate +messages from all your file loggers to the screen due to Log4perl's +appender inheritance. Check + + http://www.perl.com/pub/a/2002/09/11/log4perl.html + +for details. Have fun! + +=head2 How can I make sure my application logs a message when it dies unexpectedly? + +Whenever you encounter a fatal error in your application, instead of saying +something like + + open FILE, "<blah" or die "Can't open blah -- bailing out!"; + +just use Log::Log4perl's fatal functions instead: + + my $log = get_logger("Some::Package"); + open FILE, "<blah" or $log->logdie("Can't open blah -- bailing out!"); + +This will both log the message with priority FATAL according to your current +Log::Log4perl configuration and then call Perl's C<die()> +afterwards to terminate the program. It works the same with +stealth loggers (see L<Log::Log4perl/"Stealth Loggers">), +all you need to do is call + + use Log::Log4perl qw(:easy); + open FILE, "<blah" or LOGDIE "Can't open blah -- bailing out!"; + +What can you do if you're using some library which doesn't use Log::Log4perl +and calls C<die()> internally if something goes wrong? Use a +C<$SIG{__DIE__}> pseudo signal handler + + use Log::Log4perl qw(get_logger); + + $SIG{__DIE__} = sub { + if($^S) { + # We're in an eval {} and don't want log + # this message but catch it later + return; + } + local $Log::Log4perl::caller_depth = + $Log::Log4perl::caller_depth + 1; + my $logger = get_logger(""); + $logger->fatal(@_); + die @_; # Now terminate really + }; + +This will catch every C<die()>-Exception of your +application or the modules it uses. In case you want to +It +will fetch a root logger and pass on the C<die()>-Message to it. +If you make sure you've configured with a root logger like this: + + Log::Log4perl->init(\q{ + log4perl.category = FATAL, Logfile + log4perl.appender.Logfile = Log::Log4perl::Appender::File + log4perl.appender.Logfile.filename = fatal_errors.log + log4perl.appender.Logfile.layout = \ + Log::Log4perl::Layout::PatternLayout + log4perl.appender.Logfile.layout.ConversionPattern = %F{1}-%L (%M)> %m%n + }); + +then all C<die()> messages will be routed to a file properly. The line + + local $Log::Log4perl::caller_depth = + $Log::Log4perl::caller_depth + 1; + +in the pseudo signal handler above merits a more detailed explanation. With +the setup above, if a module calls C<die()> in one of its functions, +the fatal message will be logged in the signal handler and not in the +original function -- which will cause the %F, %L and %M placeholders +in the pattern layout to be replaced by the filename, the line number +and the function/method name of the signal handler, not the error-throwing +module. To adjust this, Log::Log4perl has the C<$caller_depth> variable, +which defaults to 0, but can be set to positive integer values +to offset the caller level. Increasing +it by one will cause it to log the calling function's parameters, not +the ones of the signal handler. +See L<Log::Log4perl/"Using Log::Log4perl from wrapper classes"> for more +details. + +=head2 How can I hook up the LWP library with Log::Log4perl? + +Or, to put it more generally: How can you utilize a third-party +library's embedded logging and debug statements in Log::Log4perl? +How can you make them print +to configurable appenders, turn them on and off, just as if they +were regular Log::Log4perl logging statements? + +The easiest solution is to map the third-party library logging statements +to Log::Log4perl's stealth loggers via a typeglob assignment. + +As an example, let's take LWP, one of the most popular Perl modules, +which makes handling WWW requests and responses a breeze. +Internally, LWP uses its own logging and debugging system, +utilizing the following calls +inside the LWP code (from the LWP::Debug man page): + + # Function tracing + LWP::Debug::trace('send()'); + + # High-granular state in functions + LWP::Debug::debug('url ok'); + + # Data going over the wire + LWP::Debug::conns("read $n bytes: $data"); + +First, let's assign Log::Log4perl priorities +to these functions: I'd suggest that +C<debug()> messages have priority C<INFO>, +C<trace()> uses C<DEBUG> and C<conns()> also logs with C<DEBUG> -- +although your mileage may certainly vary. + +Now, in order to transparently hook up LWP::Debug with Log::Log4perl, +all we have to do is say + + package LWP::Debug; + use Log::Log4perl qw(:easy); + + *trace = *INFO; + *conns = *DEBUG; + *debug = *DEBUG; + + package main; + # ... go on with your regular program ... + +at the beginning of our program. In this way, every time the, say, +C<LWP::UserAgent> module calls C<LWP::Debug::trace()>, it will implicitly +call INFO(), which is the C<info()> method of a stealth logger defined for +the Log::Log4perl category C<LWP::Debug>. Is this cool or what? + +Here's a complete program: + + use LWP::UserAgent; + use HTTP::Request::Common; + use Log::Log4perl qw(:easy); + + Log::Log4perl->easy_init( + { category => "LWP::Debug", + level => $DEBUG, + layout => "%r %p %M-%L %m%n", + }); + + package LWP::Debug; + use Log::Log4perl qw(:easy); + *trace = *INFO; + *conns = *DEBUG; + *debug = *DEBUG; + + package main; + my $ua = LWP::UserAgent->new(); + my $resp = $ua->request(GET "http://amazon.com"); + + if($resp->is_success()) { + print "Success: Received ", + length($resp->content()), "\n"; + } else { + print "Error: ", $resp->code(), "\n"; + } + +This will generate the following output on STDERR: + + 174 INFO LWP::UserAgent::new-164 () + 208 INFO LWP::UserAgent::request-436 () + 211 INFO LWP::UserAgent::send_request-294 GET http://amazon.com + 212 DEBUG LWP::UserAgent::_need_proxy-1123 Not proxied + 405 INFO LWP::Protocol::http::request-122 () + 859 DEBUG LWP::Protocol::collect-206 read 233 bytes + 863 DEBUG LWP::UserAgent::request-443 Simple response: Found + 869 INFO LWP::UserAgent::request-436 () + 871 INFO LWP::UserAgent::send_request-294 + GET http://www.amazon.com:80/exec/obidos/gateway_redirect + 872 DEBUG LWP::UserAgent::_need_proxy-1123 Not proxied + 873 INFO LWP::Protocol::http::request-122 () + 1016 DEBUG LWP::UserAgent::request-443 Simple response: Found + 1020 INFO LWP::UserAgent::request-436 () + 1022 INFO LWP::UserAgent::send_request-294 + GET http://www.amazon.com/exec/obidos/subst/home/home.html/ + 1023 DEBUG LWP::UserAgent::_need_proxy-1123 Not proxied + 1024 INFO LWP::Protocol::http::request-122 () + 1382 DEBUG LWP::Protocol::collect-206 read 632 bytes + ... + 2605 DEBUG LWP::Protocol::collect-206 read 77 bytes + 2607 DEBUG LWP::UserAgent::request-443 Simple response: OK + Success: Received 42584 + +Of course, in this way, the embedded logging and debug statements within +LWP can be utilized in any Log::Log4perl way you can think of. You can +have them sent to different appenders, block them based on the +category and everything else Log::Log4perl has to offer. + +Only drawback of this method: Steering logging behavior via category +is always based on the C<LWP::Debug> package. Although the logging +statements reflect the package name of the issuing module properly, +the stealth loggers in C<LWP::Debug> are all of the category C<LWP::Debug>. +This implies that you can't control the logging behavior based on the +package that's I<initiating> a log request (e.g. LWP::UserAgent) but only +based on the package that's actually I<executing> the logging statement, +C<LWP::Debug> in this case. + +To work around this conundrum, we need to write a wrapper function and +plant it into the C<LWP::Debug> package. It will determine the caller and +create a logger bound to a category with the same name as the caller's +package: + + package LWP::Debug; + + use Log::Log4perl qw(:levels get_logger); + + sub l4p_wrapper { + my($prio, @message) = @_; + $Log::Log4perl::caller_depth += 2; + get_logger(scalar caller(1))->log($prio, @message); + $Log::Log4perl::caller_depth -= 2; + } + + no warnings 'redefine'; + *trace = sub { l4p_wrapper($INFO, @_); }; + *debug = *conns = sub { l4p_wrapper($DEBUG, @_); }; + + package main; + # ... go on with your main program ... + +This is less performant than the previous approach, because every +log request will request a reference to a logger first, then call +the wrapper, which will in turn call the appropriate log function. + +This hierarchy shift has to be compensated for by increasing +C<$Log::Log4perl::caller_depth> by 2 before calling the log function +and decreasing it by 2 right afterwards. Also, the C<l4p_wrapper> +function shown above calls C<caller(1)> which determines the name +of the package I<two> levels down the calling hierarchy (and +therefore compensates for both the wrapper function and the +anonymous subroutine calling it). + +C<no warnings 'redefine'> suppresses a warning Perl would generate +otherwise +upon redefining C<LWP::Debug>'s C<trace()>, C<debug()> and C<conns()> +functions. In case you use a perl prior to 5.6.x, you need +to manipulate C<$^W> instead. + +To make things easy for you when dealing with LWP, Log::Log4perl 0.47 +introduces C<Log::Log4perl-E<gt>infiltrate_lwp()> which does exactly the +above. + +=head2 What if I need dynamic values in a static Log4perl configuration file? + +Say, your application uses Log::Log4perl for logging and +therefore comes with a Log4perl configuration file, specifying the logging +behavior. +But, you also want it to take command line parameters to set values +like the name of the log file. +How can you have +both a static Log4perl configuration file and a dynamic command line +interface? + +As of Log::Log4perl 0.28, every value in the configuration file +can be specified as a I<Perl hook>. So, instead of saying + + log4perl.appender.Logfile.filename = test.log + +you could just as well have a Perl subroutine deliver the value +dynamically: + + log4perl.appender.Logfile.filename = sub { logfile(); }; + +given that C<logfile()> is a valid function in your C<main> package +returning a string containing the path to the log file. + +Or, think about using the value of an environment variable: + + log4perl.appender.DBI.user = sub { $ENV{USERNAME} }; + +When C<Log::Log4perl-E<gt>init()> parses the configuration +file, it will notice the assignment above because of its +C<sub {...}> pattern and treat it in a special way: +It will evaluate the subroutine (which can contain +arbitrary Perl code) and take its return value as the right side +of the assignment. + +A typical application would be called like this on the command line: + + app # log file is "test.log" + app -l mylog.txt # log file is "mylog.txt" + +Here's some sample code implementing the command line interface above: + + use Log::Log4perl qw(get_logger); + use Getopt::Std; + + getopt('l:', \our %OPTS); + + my $conf = q( + log4perl.category.Bar.Twix = WARN, Logfile + log4perl.appender.Logfile = Log::Log4perl::Appender::File + log4perl.appender.Logfile.filename = sub { logfile(); }; + log4perl.appender.Logfile.layout = SimpleLayout + ); + + Log::Log4perl::init(\$conf); + + my $logger = get_logger("Bar::Twix"); + $logger->error("Blah"); + + ########################################### + sub logfile { + ########################################### + if(exists $OPTS{l}) { + return $OPTS{l}; + } else { + return "test.log"; + } + } + +Every Perl hook may contain arbitrary perl code, +just make sure to fully qualify eventual variable names +(e.g. C<%main::OPTS> instead of C<%OPTS>). + +B<SECURITY NOTE>: this feature means arbitrary perl code +can be embedded in the config file. In the rare case +where the people who have access to your config file +are different from the people who write your code and +shouldn't have execute rights, you might want to call + + $Log::Log4perl::Config->allow_code(0); + +before you call init(). This will prevent Log::Log4perl from +executing I<any> Perl code in the config file (including +code for custom conversion specifiers +(see L<Log::Log4perl::Layout::PatternLayout/"Custom cspecs">). + +=head2 How can I roll over my logfiles automatically at midnight? + +Long-running applications tend to produce ever-increasing logfiles. +For backup and cleanup purposes, however, it is often desirable to move +the current logfile to a different location from time to time and +start writing a new one. + +This is a non-trivial task, because it has to happen in sync with +the logging system in order not to lose any messages in the process. + +Luckily, I<Mark Pfeiffer>'s C<Log::Dispatch::FileRotate> appender +works well with Log::Log4perl to rotate your logfiles in a variety of ways. + +Note, however, that having the application deal with rotating a log +file is not cheap. Among other things, it requires locking the log file +with every write to avoid race conditions. +There are good reasons to use external rotators like C<newsyslog> +instead. +See the entry C<How can I rotate a logfile with newsyslog?> in the +FAQ for more information on how to configure it. + +When using C<Log::Dispatch::FileRotate>, +all you have to do is specify it in your Log::Log4perl configuration file +and your logfiles will be rotated automatically. + +You can choose between rolling based on a maximum size ("roll if greater +than 10 MB") or based on a date pattern ("roll everyday at midnight"). +In both cases, C<Log::Dispatch::FileRotate> allows you to define a +number C<max> of saved files to keep around until it starts overwriting +the oldest ones. If you set the C<max> parameter to 2 and the name of +your logfile is C<test.log>, C<Log::Dispatch::FileRotate> will +move C<test.log> to C<test.log.1> on the first rollover. On the second +rollover, it will move C<test.log.1> to C<test.log.2> and then C<test.log> +to C<test.log.1>. On the third rollover, it will move C<test.log.1> to +C<test.log.2> (therefore discarding the old C<test.log.2>) and +C<test.log> to C<test.log.1>. And so forth. This way, there's always +going to be a maximum of 2 saved log files around. + +Here's an example of a Log::Log4perl configuration file, defining a +daily rollover at midnight (date pattern C<yyyy-MM-dd>), keeping +a maximum of 5 saved logfiles around: + + log4perl.category = WARN, Logfile + log4perl.appender.Logfile = Log::Dispatch::FileRotate + log4perl.appender.Logfile.filename = test.log + log4perl.appender.Logfile.max = 5 + log4perl.appender.Logfile.DatePattern = yyyy-MM-dd + log4perl.appender.Logfile.TZ = PST + log4perl.appender.Logfile.layout = \ + Log::Log4perl::Layout::PatternLayout + log4perl.appender.Logfile.layout.ConversionPattern = %d %m %n + +Please see the C<Log::Dispatch::FileRotate> documentation for details. +C<Log::Dispatch::FileRotate> is available on CPAN. + +=head2 What's the easiest way to turn off all logging, even with a lengthy Log4perl configuration file? + +In addition to category-based levels and appender thresholds, +Log::Log4perl supports system-wide logging thresholds. This is the +minimum level the system will require of any logging events in order for them +to make it through to any configured appenders. + +For example, putting the line + + log4perl.threshold = ERROR + +anywhere in your configuration file will limit any output to any appender +to events with priority of ERROR or higher (ERROR or FATAL that is). + +However, in order to suppress all logging entirely, you need to use a +priority that's higher than FATAL: It is simply called C<OFF>, and it is never +used by any logger. By definition, it is higher than the highest +defined logger level. + +Therefore, if you keep the line + + log4perl.threshold = OFF + +somewhere in your Log::Log4perl configuration, the system will be quiet +as a graveyard. If you deactivate the line (e.g. by commenting it out), +the system will, upon config reload, snap back to normal operation, providing +logging messages according to the rest of the configuration file again. + +=head2 How can I log DEBUG and above to the screen and INFO and above to a file? + +You need one logger with two appenders attached to it: + + log4perl.logger = DEBUG, Screen, File + + log4perl.appender.Screen = Log::Log4perl::Appender::Screen + log4perl.appender.Screen.layout = SimpleLayout + + log4perl.appender.File = Log::Log4perl::Appender::File + log4perl.appender.File.filename = test.log + log4perl.appender.File.layout = SimpleLayout + log4perl.appender.Screen.Threshold = INFO + +Since the file logger isn't supposed to get any messages with a priority +less than INFO, the appender's C<Threshold> setting blocks those out, +although the logger forwards them. + +It's a common mistake to think you can define two loggers for this, but +it won't work unless those two loggers have different categories. If you +wanted to log all DEBUG and above messages from the Foo::Bar module to a file +and all INFO and above messages from the Quack::Schmack module to the +screen, then you could have defined two loggers with different levels +C<log4perl.logger.Foo.Bar> (level INFO) +and C<log4perl.logger.Quack.Schmack> (level DEBUG) and assigned the file +appender to the former and the screen appender to the latter. But what we +wanted to accomplish was to route all messages, regardless of which module +(or category) they came from, to both appenders. The only +way to accomplish this is to define the root logger with the lower +level (DEBUG), assign both appenders to it, and block unwanted messages at +the file appender (C<Threshold> set to INFO). + +=head2 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::Log4perl::Appender::Screen + log4perl.appender.Screen.layout = SimpleLayout + +It defines two loggers, one for category C<Cat> and one for +C<Cat::Subcat>, which is obviously a subcategory of C<Cat>. +The parent logger has a priority setting of ERROR, the child +is set to the lower C<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 +C<Cat::Subcat> logger will accept it and forward it to the +attached C<Screen> appender. Then, the message will percolate up +the logger hierarchy, find +the C<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 C<Cat::Subcat> +decides to fire, it will forward the message I<unconditionally> +to all directly or indirectly attached appenders. The C<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 C<Cat>. + +One way to prevent the message from bubbling up the logger +hierarchy is to set the C<additivity> flag of the subordinate logger to +C<0>: + + log4perl.logger.Cat = ERROR, Screen + log4perl.logger.Cat.Subcat = WARN, Screen + log4perl.additivity.Cat.Subcat = 0 + + log4perl.appender.Screen = Log::Log4perl::Appender::Screen + log4perl.appender.Screen.layout = SimpleLayout + +The message will now be accepted by the C<Cat::Subcat> logger, +forwarded to its appender, but then C<Cat::Subcat> will suppress +any further action. While this setting avoids duplicate messages +as seen before, it is often not the desired behavior. Messages +percolating up the hierarchy are a useful Log4perl feature. + +If you're defining I<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::Log4perl::Appender::Screen + log4perl.appender.Screen1.layout = SimpleLayout + log4perl.appender.Screen1.Threshold = ERROR + + log4perl.appender.Screen2 = Log::Log4perl::Appender::Screen + log4perl.appender.Screen2.layout = SimpleLayout + +Since the C<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 I<not> appended to C<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::Log4perl::Appender::Screen + log4perl.appender.Screen.layout = SimpleLayout + + log4perl.oneMessagePerAppender = 1 + +The C<oneMessagePerAppender> flag will suppress duplicate messages +to the same appender. Again, that's non-standard. But way cool :). + +=head2 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 C<Log::Dispatch::Email::MailSend> +module as an appender. It comes with the C<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 = drone@pageme.net + 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 C<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 recipient's inbox. + +There's one caveat you need to know about: The C<Log::Dispatch::Email> +hierarchy of appenders turns on I<buffering> by default. This means that +the appender will not send out messages right away but wait until a +certain threshold has been reached. If you'd rather have your alerts +sent out immediately, use + + log4perl.appender.Mailer.buffered = 0 + +to turn buffering off. + +=head2 How can I write my own appender? + +First off, Log::Log4perl comes with a set of standard appenders. Then, +there's a lot of Log4perl-compatible appenders already +available on CPAN: Just run a search for C<Log::Dispatch> on +http://search.cpan.org and chances are that what you're looking for +has already been developed, debugged and been used successfully +in production -- no need for you to reinvent the wheel. + +Also, Log::Log4perl ships with a nifty database appender named +Log::Log4perl::Appender::DBI -- check it out if talking to databases is your +desire. + +But if you're up for a truly exotic task, you might have to write +an appender yourself. That's very easy -- it takes no longer +than a couple of minutes. + +Say, we wanted to create an appender of the class +C<ColorScreenAppender>, which logs messages +to the screen in a configurable color. Just create a new class +in C<ColorScreenAppender.pm>: + + package ColorScreenAppender; + +Now let's assume that your Log::Log4perl +configuration file C<test.conf> looks like this: + + log4perl.logger = INFO, ColorApp + + log4perl.appender.ColorApp=ColorScreenAppender + log4perl.appender.ColorApp.color=blue + + log4perl.appender.ColorApp.layout = PatternLayout + log4perl.appender.ColorApp.layout.ConversionPattern=%d %m %n + +This will cause Log::Log4perl on C<init()> to look for a class +ColorScreenAppender and call its constructor new(). Let's add +new() to ColorScreenAppender.pm: + + sub new { + my($class, %options) = @_; + + my $self = { %options }; + bless $self, $class; + + return $self; + } + +To initialize this appender, Log::Log4perl will call +and pass all attributes of the appender as defined in the configuration +file to the constructor as name/value pairs (in this case just one): + + ColorScreenAppender->new(color => "blue"); + +The new() method listed above stores the contents of the +%options hash in the object's +instance data hash (referred to by $self). +That's all for initializing a new appender with Log::Log4perl. + +Second, ColorScreenAppender needs to expose a +C<log()> method, which will be called by Log::Log4perl +every time it thinks the appender should fire. Along with the +object reference (as usual in Perl's object world), log() +will receive a list of name/value pairs, of which only the one +under the key C<message> shall be of interest for now since it is the +message string to be logged. At this point, Log::Log4perl has already taken +care of joining the message to be a single string. + +For our special appender ColorScreenAppender, we're using the +Term::ANSIColor module to colorize the output: + + use Term::ANSIColor; + + sub log { + my($self, %params) = @_; + + print colored($params{message}, + $self->{color}); + } + +The color (as configured in the Log::Log4perl configuration file) +is available as $self-E<gt>{color} in the appender object. Don't +forget to return + + 1; + +at the end of ColorScreenAppender.pm and you're done. Install the new appender +somewhere where perl can find it and try it with a test script like + + use Log::Log4perl qw(:easy); + Log::Log4perl->init("test.conf"); + ERROR("blah"); + +to see the new colored output. Is this cool or what? + +And it gets even better: You can write dynamically generated appender +classes using the C<Class::Prototyped> module. Here's an example of +an appender prepending every outgoing message with a configurable +number of bullets: + + use Class::Prototyped; + + my $class = Class::Prototyped->newPackage( + "MyAppenders::Bulletizer", + bullets => 1, + log => sub { + my($self, %params) = @_; + print "*" x $self->bullets(), + $params{message}; + }, + ); + + use Log::Log4perl qw(:easy); + + Log::Log4perl->init(\ q{ + log4perl.logger = INFO, Bully + + log4perl.appender.Bully=MyAppenders::Bulletizer + log4perl.appender.Bully.bullets=3 + + log4perl.appender.Bully.layout = PatternLayout + log4perl.appender.Bully.layout.ConversionPattern=%m %n + }); + + # ... prints: "***Boo!\n"; + INFO "Boo!"; + +=head2 How can I drill down on references before logging them? + +If you've got a reference to a nested structure or object, then +you probably don't want to log it as C<HASH(0x81141d4)> but rather +dump it as something like + + $VAR1 = { + 'a' => 'b', + 'd' => 'e' + }; + +via a module like Data::Dumper. While it's syntactically correct to say + + $logger->debug(Data::Dumper::Dumper($ref)); + +this call imposes a huge performance penalty on your application +if the message is suppressed by Log::Log4perl, because Data::Dumper +will perform its expensive operations in any case, because it doesn't +know that its output will be thrown away immediately. + +As of Log::Log4perl 0.28, there's a better way: Use the +message output filter format as in + + $logger->debug( {filter => \&Data::Dumper::Dumper, + value => $ref} ); + +and Log::Log4perl won't call the filter function unless the message really +gets written out to an appender. Just make sure to pass the whole slew as a +reference to a hash specifying a filter function (as a sub reference) +under the key C<filter> and the value to be passed to the filter function in +C<value>). +When it comes to logging, Log::Log4perl will call the filter function, +pass the C<value> as an argument and log the return value. +Saves you serious cycles. + +=head2 How can I collect all FATAL messages in an extra log file? + +Suppose you have employed Log4perl all over your system and you've already +activated logging in various subsystems. On top of that, without disrupting +any other settings, how can you collect all FATAL messages all over the system +and send them to a separate log file? + +If you define a root logger like this: + + log4perl.logger = FATAL, File + log4perl.appender.File = Log::Log4perl::Appender::File + log4perl.appender.File.filename = /tmp/fatal.txt + log4perl.appender.File.layout = PatternLayout + log4perl.appender.File.layout.ConversionPattern= %d %m %n + # !!! Something's missing ... + +you'll be surprised to not only receive all FATAL messages +issued anywhere in the system, +but also everything else -- gazillions of +ERROR, WARN, INFO and even DEBUG messages will end up in +your fatal.txt logfile! +Reason for this is Log4perl's (or better: Log4j's) appender additivity. +Once a +lower-level logger decides to fire, the message is going to be forwarded +to all appenders upstream -- without further priority checks with their +attached loggers. + +There's a way to prevent this, however: If your appender defines a +minimum threshold, only messages of this priority or higher are going +to be logged. So, just add + + log4perl.appender.File.Threshold = FATAL + +to the configuration above, and you'll get what you wanted in the +first place: An overall system FATAL message collector. + +=head2 How can I bundle several log messages into one? + +Would you like to tally the messages arriving at your appender and +dump out a summary once they're exceeding a certain threshold? +So that something like + + $logger->error("Blah"); + $logger->error("Blah"); + $logger->error("Blah"); + +won't be logged as + + Blah + Blah + Blah + +but as + + [3] Blah + +instead? If you'd like to hold off on logging a message until it has been +sent a couple of times, you can roll that out by creating a buffered +appender. + +Let's define a new appender like + + package TallyAppender; + + sub new { + my($class, %options) = @_; + + my $self = { maxcount => 5, + %options + }; + + bless $self, $class; + + $self->{last_message} = ""; + $self->{last_message_count} = 0; + + return $self; + } + +with two additional instance variables C<last_message> and +C<last_message_count>, storing the content of the last message sent +and a counter of how many times this has happened. Also, it features +a configuration parameter C<maxcount> which defaults to 5 in the +snippet above but can be set in the Log4perl configuration file like this: + + log4perl.logger = INFO, A + log4perl.appender.A=TallyAppender + log4perl.appender.A.maxcount = 3 + +The main tallying logic lies in the appender's C<log> method, +which is called every time Log4perl thinks a message needs to get logged +by our appender: + + sub log { + my($self, %params) = @_; + + # Message changed? Print buffer. + if($self->{last_message} and + $params{message} ne $self->{last_message}) { + print "[$self->{last_message_count}]: " . + "$self->{last_message}"; + $self->{last_message_count} = 1; + $self->{last_message} = $params{message}; + return; + } + + $self->{last_message_count}++; + $self->{last_message} = $params{message}; + + # Threshold exceeded? Print, reset counter + if($self->{last_message_count} >= + $self->{maxcount}) { + print "[$self->{last_message_count}]: " . + "$params{message}"; + $self->{last_message_count} = 0; + $self->{last_message} = ""; + return; + } + } + +We basically just check if the oncoming message in C<$param{message}> +is equal to what we've saved before in the C<last_message> instance +variable. If so, we're increasing C<last_message_count>. +We print the message in two cases: If the new message is different +than the buffered one, because then we need to dump the old stuff +and store the new. Or, if the counter exceeds the threshold, as +defined by the C<maxcount> configuration parameter. + +Please note that the appender always gets the fully rendered message and +just compares it as a whole -- so if there's a date/timestamp in there, +that might confuse your logic. You can work around this by specifying +%m %n as a layout and add the date later on in the appender. Or, make +the comparison smart enough to omit the date. + +At last, don't forget what happens if the program is being shut down. +If there's still messages in the buffer, they should be printed out +at that point. That's easy to do in the appender's DESTROY method, +which gets called at object destruction time: + + sub DESTROY { + my($self) = @_; + + if($self->{last_message_count}) { + print "[$self->{last_message_count}]: " . + "$self->{last_message}"; + return; + } + } + +This will ensure that none of the buffered messages are lost. +Happy buffering! + +=head2 I want to log ERROR and WARN messages to different files! How can I do that? + +Let's assume you wanted to have each logging statement written to a +different file, based on the statement's priority. Messages with priority +C<WARN> are supposed to go to C</tmp/app.warn>, events prioritized +as C<ERROR> should end up in C</tmp/app.error>. + +Now, if you define two appenders C<AppWarn> and C<AppError> +and assign them both to the root logger, +messages bubbling up from any loggers below will be logged by both +appenders because of Log4perl's message propagation feature. If you limit +their exposure via the appender threshold mechanism and set +C<AppWarn>'s threshold to C<WARN> and C<AppError>'s to C<ERROR>, you'll +still get C<ERROR> messages in C<AppWarn>, because C<AppWarn>'s C<WARN> +setting will just filter out messages with a I<lower> priority than +C<WARN> -- C<ERROR> is higher and will be allowed to pass through. + +What we need for this is a Log4perl I<Custom Filter>, available with +Log::Log4perl 0.30. + +Both appenders need to verify that +the priority of the oncoming messages exactly I<matches> the priority +the appender is supposed to log messages of. To accomplish this task, +let's define two custom filters, C<MatchError> and C<MatchWarn>, which, +when attached to their appenders, will limit messages passed on to them +to those matching a given priority: + + log4perl.logger = WARN, AppWarn, AppError + + # Filter to match level ERROR + log4perl.filter.MatchError = Log::Log4perl::Filter::LevelMatch + log4perl.filter.MatchError.LevelToMatch = ERROR + log4perl.filter.MatchError.AcceptOnMatch = true + + # Filter to match level WARN + log4perl.filter.MatchWarn = Log::Log4perl::Filter::LevelMatch + log4perl.filter.MatchWarn.LevelToMatch = WARN + log4perl.filter.MatchWarn.AcceptOnMatch = true + + # Error appender + log4perl.appender.AppError = Log::Log4perl::Appender::File + log4perl.appender.AppError.filename = /tmp/app.err + log4perl.appender.AppError.layout = SimpleLayout + log4perl.appender.AppError.Filter = MatchError + + # Warning appender + log4perl.appender.AppWarn = Log::Log4perl::Appender::File + log4perl.appender.AppWarn.filename = /tmp/app.warn + log4perl.appender.AppWarn.layout = SimpleLayout + log4perl.appender.AppWarn.Filter = MatchWarn + +The appenders C<AppWarn> and C<AppError> defined above are logging to C</tmp/app.warn> and +C</tmp/app.err> respectively and have the custom filters C<MatchWarn> and C<MatchError> +attached. +This setup will direct all WARN messages, issued anywhere in the system, to /tmp/app.warn (and +ERROR messages to /tmp/app.error) -- without any overlaps. + +=head2 On our server farm, Log::Log4perl configuration files differ slightly from host to host. Can I roll them all into one? + +You sure can, because Log::Log4perl allows you to specify attribute values +dynamically. Let's say that one of your appenders expects the host's IP address +as one of its attributes. Now, you could certainly roll out different +configuration files for every host and specify the value like + + log4perl.appender.MyAppender = Log::Log4perl::Appender::SomeAppender + log4perl.appender.MyAppender.ip = 10.0.0.127 + +but that's a maintenance nightmare. Instead, you can have Log::Log4perl +figure out the IP address at configuration time and set the appender's +value correctly: + + # Set the IP address dynamically + log4perl.appender.MyAppender = Log::Log4perl::Appender::SomeAppender + log4perl.appender.MyAppender.ip = sub { \ + use Sys::Hostname; \ + use Socket; \ + return inet_ntoa(scalar gethostbyname hostname); \ + } + +If Log::Log4perl detects that an attribute value starts with something like +C<"sub {...">, it will interpret it as a perl subroutine which is to be executed +once at configuration time (not runtime!) and its return value is +to be used as the attribute value. This comes in handy +for rolling out applications where Log::Log4perl configuration files +show small host-specific differences, because you can deploy the unmodified +application distribution on all instances of the server farm. + +=head2 Log4perl doesn't interpret my backslashes correctly! + +If you're using Log4perl's feature to specify the configuration as a +string in your program (as opposed to a separate configuration file), +chances are that you've written it like this: + + # *** WRONG! *** + + Log::Log4perl->init( \ <<END_HERE); + log4perl.logger = WARN, A1 + log4perl.appender.A1 = Log::Log4perl::Appender::Screen + log4perl.appender.A1.layout = \ + Log::Log4perl::Layout::PatternLayout + log4perl.appender.A1.layout.ConversionPattern = %m%n + END_HERE + + # *** WRONG! *** + +and you're getting the following error message: + + Layout not specified for appender A1 at .../Config.pm line 342. + +What's wrong? The problem is that you're using a here-document with +substitution enabled (C<E<lt>E<lt>END_HERE>) and that Perl won't +interpret backslashes at line-ends as continuation characters but +will essentially throw them out. So, in the code above, the layout line +will look like + + log4perl.appender.A1.layout = + +to Log::Log4perl which causes it to report an error. To interpret the backslash +at the end of the line correctly as a line-continuation character, use +the non-interpreting mode of the here-document like in + + # *** RIGHT! *** + + Log::Log4perl->init( \ <<'END_HERE'); + log4perl.logger = WARN, A1 + log4perl.appender.A1 = Log::Log4perl::Appender::Screen + log4perl.appender.A1.layout = \ + Log::Log4perl::Layout::PatternLayout + log4perl.appender.A1.layout.ConversionPattern = %m%n + END_HERE + + # *** RIGHT! *** + +(note the single quotes around C<'END_HERE'>) or use C<q{...}> +instead of a here-document and Perl will treat the backslashes at +line-end as intended. + +=head2 I want to suppress certain messages based on their content! + +Let's assume you've plastered all your functions with Log4perl +statements like + + sub some_func { + + INFO("Begin of function"); + + # ... Stuff happens here ... + + INFO("End of function"); + } + +to issue two log messages, one at the beginning and one at the end of +each function. Now you want to suppress the message at the beginning +and only keep the one at the end, what can you do? You can't use the category +mechanism, because both messages are issued from the same package. + +Log::Log4perl's custom filters (0.30 or better) provide an interface for the +Log4perl user to step in right before a message gets logged and decide if +it should be written out or suppressed, based on the message content or other +parameters: + + use Log::Log4perl qw(:easy); + + Log::Log4perl::init( \ <<'EOT' ); + log4perl.logger = INFO, A1 + log4perl.appender.A1 = Log::Log4perl::Appender::Screen + log4perl.appender.A1.layout = \ + Log::Log4perl::Layout::PatternLayout + log4perl.appender.A1.layout.ConversionPattern = %m%n + + log4perl.filter.M1 = Log::Log4perl::Filter::StringMatch + log4perl.filter.M1.StringToMatch = Begin + log4perl.filter.M1.AcceptOnMatch = false + + log4perl.appender.A1.Filter = M1 +EOT + +The last four statements in the configuration above are defining a custom +filter C<M1> of type C<Log::Log4perl::Filter::StringMatch>, which comes with +Log4perl right out of the box and allows you to define a text pattern to match +(as a perl regular expression) and a flag C<AcceptOnMatch> indicating +if a match is supposed to suppress the message or let it pass through. + +The last line then assigns this filter to the C<A1> appender, which will +call it every time it receives a message to be logged and throw all +messages out I<not> matching the regular expression C<Begin>. + +Instead of using the standard C<Log::Log4perl::Filter::StringMatch> filter, +you can define your own, simply using a perl subroutine: + + log4perl.filter.ExcludeBegin = sub { !/Begin/ } + log4perl.appender.A1.Filter = ExcludeBegin + +For details on custom filters, check L<Log::Log4perl::Filter>. + +=head2 My new module uses Log4perl -- but what happens if the calling program didn't configure it? + +If a Perl module uses Log::Log4perl, it will typically rely on the +calling program to initialize it. If it is using Log::Log4perl in C<:easy> +mode, like in + + package MyMod; + use Log::Log4perl qw(:easy); + + sub foo { + DEBUG("In foo"); + } + + 1; + +and the calling program doesn't initialize Log::Log4perl at all (e.g. because +it has no clue that it's available), Log::Log4perl will silently +ignore all logging messages. However, if the module is using Log::Log4perl +in regular mode like in + + package MyMod; + use Log::Log4perl qw(get_logger); + + sub foo { + my $logger = get_logger(""); + $logger->debug("blah"); + } + + 1; + +and the main program is just using the module like in + + use MyMode; + MyMode::foo(); + +then Log::Log4perl will also ignore all logging messages but +issue a warning like + + Log4perl: Seems like no initialization happened. + Forgot to call init()? + +(only once!) to remind novice users to not forget to initialize +the logging system before using it. +However, if you want to suppress this message, just +add the C<:nowarn> target to the module's C<use Log::Log4perl> call: + + use Log::Log4perl qw(get_logger :nowarn); + +This will have Log::Log4perl silently ignore all logging statements if +no initialization has taken place. If, instead of using init(), you're +using Log4perl's API to define loggers and appenders, the same +notification happens if no call to add_appenders() is made, i.e. no +appenders are defined. + +If the module wants to figure out if some other program part has +already initialized Log::Log4perl, it can do so by calling + + Log::Log4perl::initialized() + +which will return a true value in case Log::Log4perl has been initialized +and a false value if not. + +=head2 How can I synchronize access to an appender? + +If you're using the same instance of an appender in multiple processes, +and each process is passing on messages to the appender in parallel, +you might end up with overlapping log entries. + +Typical scenarios include a file appender that you create in the main +program, and which will then be shared between the parent and a +forked child process. Or two separate processes, each initializing a +Log4perl file appender on the same logfile. + +Log::Log4perl won't synchronize access to the shared logfile by +default. Depending on your operating system's flush mechanism, +buffer size and the size of your messages, there's a small chance of +an overlap. + +The easiest way to prevent overlapping messages in logfiles written to +by multiple processes is setting the +file appender's C<syswrite> flag along with a file write mode of C<"append">. +This makes sure that +C<Log::Log4perl::Appender::File> uses C<syswrite()> (which is guaranteed +to run uninterrupted) instead of C<print()> which might buffer +the message or get interrupted by the OS while it is writing. And in +C<"append"> mode, the OS kernel ensures that multiple processes share +one end-of-file marker, ensuring that each process writes to the I<real> +end of the file. (The value of C<"append"> +for the C<mode> parameter is the default setting in Log4perl's file +appender so you don't have to set it explicitly.) + + # Guarantees atomic writes + + log4perl.category.Bar.Twix = WARN, Logfile + + log4perl.appender.Logfile = Log::Log4perl::Appender::File + log4perl.appender.Logfile.mode = append + log4perl.appender.Logfile.syswrite = 1 + log4perl.appender.Logfile.filename = test.log + log4perl.appender.Logfile.layout = SimpleLayout + +Another guaranteed way of having messages separated with any kind of +appender is putting a Log::Log4perl::Appender::Synchronized composite +appender in between Log::Log4perl and the real appender. It will make +sure to let messages pass through this virtual gate one by one only. + +Here's a sample configuration to synchronize access to a file appender: + + log4perl.category.Bar.Twix = WARN, Syncer + + log4perl.appender.Logfile = Log::Log4perl::Appender::File + log4perl.appender.Logfile.autoflush = 1 + log4perl.appender.Logfile.filename = test.log + log4perl.appender.Logfile.layout = SimpleLayout + + log4perl.appender.Syncer = Log::Log4perl::Appender::Synchronized + log4perl.appender.Syncer.appender = Logfile + +C<Log::Log4perl::Appender::Synchronized> uses +the C<IPC::Shareable> module and its semaphores, which will slow down writing +the log messages, but ensures sequential access featuring atomic checks. +Check L<Log::Log4perl::Appender::Synchronized> for details. + +=head2 Can I use Log::Log4perl with log4j's Chainsaw? + +Yes, Log::Log4perl can be configured to send its events to log4j's +graphical log UI I<Chainsaw>. + +=for html +<p> +<TABLE><TR><TD> +<A HREF="http://log4perl.sourceforge.net/images/chainsaw2.jpg"><IMG SRC="http://log4perl.sourceforge.net/images/chainsaw2s.jpg"></A> +<TR><TD> +<I>Figure 1: Chainsaw receives Log::Log4perl events</I> +</TABLE> +<p> + +=for text +Figure1: Chainsaw receives Log::Log4perl events + +Here's how it works: + +=over 4 + +=item * + +Get Guido Carls' E<lt>gcarls@cpan.orgE<gt> Log::Log4perl extension +C<Log::Log4perl::Layout::XMLLayout> from CPAN and install it: + + perl -MCPAN -eshell + cpan> install Log::Log4perl::Layout::XMLLayout + +=item * + +Install and start Chainsaw, which is part of the C<log4j> distribution now +(see http://jakarta.apache.org/log4j ). Create a configuration file like + + <log4j:configuration debug="true"> + <plugin name="XMLSocketReceiver" + class="org.apache.log4j.net.XMLSocketReceiver"> + <param name="decoder" value="org.apache.log4j.xml.XMLDecoder"/> + <param name="Port" value="4445"/> + </plugin> + <root> <level value="debug"/> </root> + </log4j:configuration> + +and name it e.g. C<config.xml>. Then start Chainsaw like + + java -Dlog4j.debug=true -Dlog4j.configuration=config.xml \ + -classpath ".:log4j-1.3alpha.jar:log4j-chainsaw-1.3alpha.jar" \ + org.apache.log4j.chainsaw.LogUI + +and watch the GUI coming up. + +=item * + +Configure Log::Log4perl to use a socket appender with an XMLLayout, pointing +to the host/port where Chainsaw (as configured above) is waiting with its +XMLSocketReceiver: + + use Log::Log4perl qw(get_logger); + use Log::Log4perl::Layout::XMLLayout; + + my $conf = q( + log4perl.category.Bar.Twix = WARN, Appender + log4perl.appender.Appender = Log::Log4perl::Appender::Socket + log4perl.appender.Appender.PeerAddr = localhost + log4perl.appender.Appender.PeerPort = 4445 + log4perl.appender.Appender.layout = Log::Log4perl::Layout::XMLLayout + ); + + Log::Log4perl::init(\$conf); + + # Nasty hack to suppress encoding header + my $app = Log::Log4perl::appenders->{"Appender"}; + $app->layout()->{enc_set} = 1; + + my $logger = get_logger("Bar.Twix"); + $logger->error("One"); + +The nasty hack shown in the code snippet above is currently (October 2003) +necessary, because Chainsaw expects XML messages to arrive in a format like + + <log4j:event logger="Bar.Twix" + timestamp="1066794904310" + level="ERROR" + thread="10567"> + <log4j:message><![CDATA[Two]]></log4j:message> + <log4j:NDC><![CDATA[undef]]></log4j:NDC> + <log4j:locationInfo class="main" + method="main" + file="./t" + line="32"> + </log4j:locationInfo> + </log4j:event> + +without a preceding + + <?xml version = "1.0" encoding = "iso8859-1"?> + +which Log::Log4perl::Layout::XMLLayout applies to the first event sent +over the socket. + +=back + +See figure 1 for a screenshot of Chainsaw in action, receiving events from +the Perl script shown above. + +Many thanks to Chainsaw's +Scott Deboy <sdeboy@comotivsystems.com> for his support! + +=head2 How can I run Log::Log4perl under mod_perl? + +In persistent environments it's important to play by the rules outlined +in section L<Log::Log4perl/"Initialize once and only once">. +If you haven't read this yet, please go ahead and read it right now. It's +very important. + +And no matter if you use a startup handler to init() Log::Log4perl or use the +init_once() strategy (added in 0.42), either way you're very likely to have +unsynchronized writes to logfiles. + +If Log::Log4perl is configured with a log file appender, and it is +initialized via +the Apache startup handler, the file handle created initially will be +shared among all Apache processes. Similarly, with the init_once() +approach: although every process has a separate L4p configuration, +processes are gonna share the appender file I<names> instead, effectively +opening several different file handles on the same file. + +Now, having several appenders using the same file handle or having +several appenders logging to the same file unsynchronized, this might +result in overlapping messages. Sometimes, this is acceptable. If it's +not, here's two strategies: + +=over 4 + +=item * + +Use the L<Log::Log4perl::Appender::Synchronized> appender to connect to +your file appenders. Here's the writeup: +http://log4perl.sourceforge.net/releases/Log-Log4perl/docs/html/Log/Log4perl/FAQ.html#23804 + +=item * + +Use a different logfile for every process like in + + #log4perl.conf + ... + log4perl.appender.A1.filename = sub { "mylog.$$.log" } + +=back + +=head2 My program already uses warn() and die(). How can I switch to Log4perl? + +If your program already uses Perl's C<warn()> function to spew out +error messages and you'd like to channel those into the Log4perl world, +just define a C<__WARN__> handler where your program or module resides: + + use Log::Log4perl qw(:easy); + + $SIG{__WARN__} = sub { + local $Log::Log4perl::caller_depth = + $Log::Log4perl::caller_depth + 1; + WARN @_; + }; + +Why the C<local> setting of C<$Log::Log4perl::caller_depth>? +If you leave that out, +C<PatternLayout> conversion specifiers like C<%M> or C<%F> (printing +the current function/method and source filename) will refer +to where the __WARN__ handler resides, not the environment +Perl's C<warn()> function was issued from. Increasing C<caller_depth> +adjusts for this offset. Having it C<local>, makes sure the level +gets set back after the handler exits. + +Once done, if your program does something like + + sub some_func { + warn "Here's a warning"; + } + +you'll get (depending on your Log::Log4perl configuration) something like + + 2004/02/19 20:41:02-main::some_func: Here's a warning at ./t line 25. + +in the appropriate appender instead of having a screen full of STDERR +messages. It also works with the C<Carp> module and its C<carp()> +and C<cluck()> functions. + +If, on the other hand, catching C<die()> and friends is +required, a C<__DIE__> handler is appropriate: + + $SIG{__DIE__} = sub { + if($^S) { + # We're in an eval {} and don't want log + # this message but catch it later + return; + } + local $Log::Log4perl::caller_depth = + $Log::Log4perl::caller_depth + 1; + LOGDIE @_; + }; + +This will call Log4perl's C<LOGDIE()> function, which will log a fatal +error and then call die() internally, causing the program to exit. Works +equally well with C<Carp>'s C<croak()> and C<confess()> functions. + +=head2 Some module prints messages to STDERR. How can I funnel them to Log::Log4perl? + +If a module you're using doesn't use Log::Log4perl but prints logging +messages to STDERR instead, like + + ######################################## + package IgnorantModule; + ######################################## + + sub some_method { + print STDERR "Parbleu! An error!\n"; + } + + 1; + +there's still a way to capture these messages and funnel them +into Log::Log4perl, even without touching the module. What you need is +a trapper module like + + ######################################## + package Trapper; + ######################################## + + use Log::Log4perl qw(:easy); + + sub TIEHANDLE { + my $class = shift; + bless [], $class; + } + + sub PRINT { + my $self = shift; + $Log::Log4perl::caller_depth++; + DEBUG @_; + $Log::Log4perl::caller_depth--; + } + + 1; + +and a C<tie> command in the main program to tie STDERR to the trapper +module along with regular Log::Log4perl initialization: + + ######################################## + package main; + ######################################## + + use Log::Log4perl qw(:easy); + + Log::Log4perl->easy_init( + {level => $DEBUG, + file => 'stdout', # make sure not to use stderr here! + layout => "%d %M: %m%n", + }); + + tie *STDERR, "Trapper"; + +Make sure not to use STDERR as Log::Log4perl's file appender +here (which would be the default in C<:easy> mode), because it would +end up in an endless recursion. + +Now, calling + + IgnorantModule::some_method(); + +will result in the desired output + + 2004/05/06 11:13:04 IgnorantModule::some_method: Parbleu! An error! + +=head2 How come PAR (Perl Archive Toolkit) creates executables which then can't find their Log::Log4perl appenders? + +If not instructed otherwise, C<Log::Log4perl> dynamically pulls in +appender classes found in its configuration. If you specify + + #!/usr/bin/perl + # mytest.pl + + use Log::Log4perl qw(get_logger); + + my $conf = q( + log4perl.category.Bar.Twix = WARN, Logfile + log4perl.appender.Logfile = Log::Log4perl::Appender::Screen + log4perl.appender.Logfile.layout = SimpleLayout + ); + + Log::Log4perl::init(\$conf); + my $logger = get_logger("Bar::Twix"); + $logger->error("Blah"); + +then C<Log::Log4perl::Appender::Screen> will be pulled in while the program +runs, not at compile time. If you have PAR compile the script above to an +executable binary via + + pp -o mytest mytest.pl + +and then run C<mytest> on a machine without having Log::Log4perl installed, +you'll get an error message like + + ERROR: can't load appenderclass 'Log::Log4perl::Appender::Screen' + Can't locate Log/Log4perl/Appender/Screen.pm in @INC ... + +Why? At compile time, C<pp> didn't realize that +C<Log::Log4perl::Appender::Screen> would be needed later on and didn't +wrap it into the executable created. To avoid this, either say +C<use Log::Log4perl::Appender::Screen> in the script explicitly or +compile it with + + pp -o mytest -M Log::Log4perl::Appender::Screen mytest.pl + +to make sure the appender class gets included. + +=head2 How can I access a custom appender defined in the configuration? + +Any appender defined in the configuration file or somewhere in the code +can be accessed later via +C<Log::Log4perl-E<gt>appender_by_name("appender_name")>, +which returns a reference of the appender object. + +Once you've got a hold of the object, it can be queried or modified to +your liking. For example, see the custom C<IndentAppender> defined below: +After calling C<init()> to define the Log4perl settings, the +appender object is retrieved to call its C<indent_more()> and C<indent_less()> +methods to control indentation of messages: + + package IndentAppender; + + sub new { + bless { indent => 0 }, $_[0]; + } + + sub indent_more { $_[0]->{indent}++ } + sub indent_less { $_[0]->{indent}-- } + + sub log { + my($self, %params) = @_; + print " " x $self->{indent}, $params{message}; + } + + package main; + + use Log::Log4perl qw(:easy); + + my $conf = q( + log4perl.category = DEBUG, Indented + log4perl.appender.Indented = IndentAppender + log4perl.appender.Indented.layout = Log::Log4perl::Layout::SimpleLayout + ); + + Log::Log4perl::init(\$conf); + + my $appender = Log::Log4perl->appender_by_name("Indented"); + + DEBUG "No identation"; + $appender->indent_more(); + DEBUG "One more"; + $appender->indent_more(); + DEBUG "Two more"; + $appender->indent_less(); + DEBUG "One less"; + +As you would expect, this will print + + DEBUG - No identation + DEBUG - One more + DEBUG - Two more + DEBUG - One less + +because the very appender used by Log4perl is modified dynamically at +runtime. + +=head2 I don't know if Log::Log4perl is installed. How can I prepare my script? + +In case your script needs to be prepared for environments that may or may +not have Log::Log4perl installed, there's a trick. + +If you put the following BEGIN blocks at the top of the program, +you'll be able to use the DEBUG(), INFO(), etc. macros in +Log::Log4perl's C<:easy> mode. +If Log::Log4perl +is installed in the target environment, the regular Log::Log4perl rules +apply. If not, all of DEBUG(), INFO(), etc. are "stubbed" out, i.e. they +turn into no-ops: + + use warnings; + use strict; + + BEGIN { + eval { require Log::Log4perl; }; + + if($@) { + print "Log::Log4perl not installed - stubbing.\n"; + no strict qw(refs); + *{"main::$_"} = sub { } for qw(DEBUG INFO WARN ERROR FATAL); + } else { + no warnings; + print "Log::Log4perl installed - life is good.\n"; + require Log::Log4perl::Level; + Log::Log4perl::Level->import(__PACKAGE__); + Log::Log4perl->import(qw(:easy)); + Log::Log4perl->easy_init($main::DEBUG); + } + } + + # The regular script begins ... + DEBUG "Hey now!"; + +This snippet will first probe for Log::Log4perl, and if it can't be found, +it will alias DEBUG(), INFO(), with empty subroutines via typeglobs. +If Log::Log4perl is available, its level constants are first imported +(C<$DEBUG>, C<$INFO>, etc.) and then C<easy_init()> gets called to initialize +the logging system. + +=head2 Can file appenders create files with different permissions? + +Typically, when C<Log::Log4perl::Appender::File> creates a new file, +its permissions are set to C<rw-r--r-->. Why? Because your +environment's I<umask> most likely defaults to +C<0022>, that's the standard setting. + +What's a I<umask>, you're asking? It's a template that's applied to +the permissions of all newly created files. While calls like +C<open(FILE, "E<gt>foo")> will always try to create files in C<rw-rw-rw- +> mode, the system will apply the current I<umask> template to +determine the final permission setting. I<umask> is a bit mask that's +inverted and then applied to the requested permission setting, using a +bitwise AND: + + $request_permission &~ $umask + +So, a I<umask> setting of 0000 (the leading 0 simply indicates an +octal value) will create files in C<rw-rw-rw-> mode, a setting of 0277 +will use C<r-------->, and the standard 0022 will use C<rw-r--r-->. + +As an example, if you want your log files to be created with +C<rw-r--rw-> permissions, use a I<umask> of C<0020> before +calling Log::Log4perl->init(): + + use Log::Log4perl; + + umask 0020; + # Creates log.out in rw-r--rw mode + Log::Log4perl->init(\ q{ + log4perl.logger = WARN, File + log4perl.appender.File = Log::Log4perl::Appender::File + log4perl.appender.File.filename = log.out + log4perl.appender.File.layout = SimpleLayout + }); + +=head2 Using Log4perl in an END block causes a problem! + +It's not easy to get to this error, but if you write something like + + END { Log::Log4perl::get_logger()->debug("Hey there."); } + + use Log::Log4perl qw(:easy); + Log::Log4perl->easy_init($DEBUG); + +it won't work. The reason is that C<Log::Log4perl> defines an +END block that cleans up all loggers. And perl will run END blocks +in the reverse order as they're encountered in the compile phase, +so in the scenario above, the END block will run I<after> Log4perl +has cleaned up its loggers. + +Placing END blocks using Log4perl I<after> +a C<use Log::Log4perl> statement fixes the problem: + + use Log::Log4perl qw(:easy); + Log::Log4perl->easy_init($DEBUG); + + END { Log::Log4perl::get_logger()->debug("Hey there."); } + +In this scenario, the shown END block is executed I<before> Log4perl +cleans up and the debug message will be processed properly. + +=head2 Help! My appender is throwing a "Wide character in print" warning! + +This warning shows up when Unicode strings are printed without +precautions. The warning goes away if the complaining appender is +set to utf-8 mode: + + # Either in the log4perl configuration file: + log4perl.appender.Logfile.filename = test.log + log4perl.appender.Logfile.utf8 = 1 + + # Or, in easy mode: + Log::Log4perl->easy_init( { + level => $DEBUG, + file => ":utf8> test.log" + } ); + +If the complaining appender is a screen appender, set its C<utf8> option: + + log4perl.appender.Screen.stderr = 1 + log4perl.appender.Screen.utf8 = 1 + +Alternatively, C<binmode> does the trick: + + # Either STDOUT ... + binmode(STDOUT, ":utf8); + + # ... or STDERR. + binmode(STDERR, ":utf8); + +Some background on this: Perl's strings are either byte strings or +Unicode strings. C<"Mike"> is a byte string. +C<"\x{30DE}\x{30A4}\x{30AF}"> is a Unicode string. Unicode strings are +marked specially and are UTF-8 encoded internally. + +If you print a byte string to STDOUT, +all is well, because STDOUT is by default set to byte mode. However, +if you print a Unicode string to STDOUT without precautions, C<perl> +will try to transform the Unicode string back to a byte string before +printing it out. This is troublesome if the Unicode string contains +'wide' characters which can't be represented in Latin-1. + +For example, if you create a Unicode string with three japanese Katakana +characters as in + + perl -le 'print "\x{30DE}\x{30A4}\x{30AF}"' + +(coincidentally pronounced Ma-i-ku, the japanese pronunciation of +"Mike"), STDOUT is in byte mode and the warning + + Wide character in print at ./script.pl line 14. + +appears. Setting STDOUT to UTF-8 mode as in + + perl -le 'binmode(STDOUT, ":utf8"); print "\x{30DE}\x{30A4}\x{30AF}"' + +will silently print the Unicode string to STDOUT in UTF-8. To see the +characters printed, you'll need a UTF-8 terminal with a font including +japanese Katakana characters. + +=head2 How can I send errors to the screen, and debug messages to a file? + +Let's assume you want to maintain a detailed DEBUG output in a file +and only messages of level ERROR and higher should be printed on the +screen. Often times, developers come up with something like this: + + # Wrong!!! + log4perl.logger = DEBUG, FileApp + log4perl.logger = ERROR, ScreenApp + # Wrong!!! + +This won't work, however. Logger definitions aren't additive, and the +second statement will overwrite the first one. Log4perl versions +below 1.04 were silently accepting this, leaving people confused why +it wouldn't work as expected. +As of 1.04, this will throw a I<fatal error> to notify the user of +the problem. + +What you want to do instead, is this: + + log4perl.logger = DEBUG, FileApp, ScreenApp + + log4perl.appender.FileApp = Log::Log4perl::Appender::File + log4perl.appender.FileApp.filename = test.log + log4perl.appender.FileApp.layout = SimpleLayout + + log4perl.appender.ScreenApp = Log::Log4perl::Appender::Screen + log4perl.appender.ScreenApp.stderr = 0 + log4perl.appender.ScreenApp.layout = SimpleLayout + ### limiting output to ERROR messages + log4perl.appender.ScreenApp.Threshold = ERROR + ### + +Note that without the second appender's C<Threshold> setting, both appenders +would receive all messages prioritized DEBUG and higher. With the +threshold set to ERROR, the second appender will filter the messages +as required. + +=head2 Where should I put my logfiles? + +Your log files may go anywhere you want them, but the effective +user id of the calling process must have write access. + +If the log file doesn't exist at program start, Log4perl's file appender +will create it. For this, it needs write access to the directory where +the new file will be located in. If the log file already exists at startup, +the process simply needs write access to the file. Note that it will +need write access to the file's directory if you're encountering situations +where the logfile gets recreated, e.g. during log rotation. + +If Log::Log4perl is used by a web server application (e.g. in a CGI script +or mod_perl), then the webserver's user (usually C<nobody> or C<www>) +must have the permissions mentioned above. + +To prepare your web server to use log4perl, we'd recommend: + + webserver:~$ su - + webserver:~# mkdir /var/log/cgiapps + webserver:~# chown nobody:root /var/log/cgiapps/ + webserver:~# chown nobody:root -R /var/log/cgiapps/ + webserver:~# chmod 02755 -R /var/log/cgiapps/ + +Then set your /etc/log4perl.conf file to include: + + log4perl.appender.FileAppndr1.filename = + /var/log/cgiapps/<app-name>.log + +=head2 How can my file appender deal with disappearing log files? + +The file appender that comes with Log4perl, L<Log::Log4perl::Appender::File>, +will open a specified log file at initialization time and will +keep writing to it via a file handle. + +In case the associated file goes way, messages written by a +long-running process will still be written +to the file handle. In case the file has been moved to a different +location on the same file system, the writer will keep writing to +it under the new filename. In case the file has been removed from +the file system, the log messages will end up in nowhere land. This +is not a bug in Log4perl, this is how Unix works. There is +no error message in this case, because the writer has no idea that +the file handle is not associated with a visible file. + +To prevent the loss of log messages when log files disappear, the +file appender's C<recreate> option needs to be set to a true value: + + log4perl.appender.Logfile.recreate = 1 + +This will instruct the file appender to check in regular intervals +(default: 30 seconds) if the log file is still there. If it finds +out that the file is missing, it will recreate it. + +Continuously checking if the log file still exists is fairly +expensive. For this reason it is only performed every 30 seconds. To +change this interval, the option C<recreate_check_interval> can be set +to the number of seconds between checks. In the extreme case where the +check should be performed before every write, it can even be set to 0: + + log4perl.appender.Logfile.recreate = 1 + log4perl.appender.Logfile.recreate_check_interval = 0 + +To avoid having to check the file system so frequently, a signal +handler can be set up: + + log4perl.appender.Logfile.recreate = 1 + log4perl.appender.Logfile.recreate_check_signal = USR1 + +This will install a signal handler which will recreate a missing log file +immediately when it receives the defined signal. + +Note that the init_and_watch() method for Log4perl's initialization +can also be instructed to install a signal handler, usually using the +HUP signal. Make sure to use a different signal if you're using both +of them at the same time. + +=head2 How can I rotate a logfile with newsyslog? + +Here's a few things that need to be taken care of when using the popular +log file rotating utility C<newsyslog> +(http://www.courtesan.com/newsyslog) with Log4perl's file appender +in long-running processes. + +For example, with a newsyslog configuration like + + # newsyslog.conf + /tmp/test.log 666 12 5 * B + +and a call to + + # newsyslog -f /path/to/newsyslog.conf + +C<newsyslog> will take action if C</tmp/test.log> is larger than the +specified 5K in size. It will move the current log file C</tmp/test.log> to +C</tmp/test.log.0> and create a new and empty C</tmp/test.log> with +the specified permissions (this is why C<newsyslog> needs to run as root). +An already existing C</tmp/test.log.0> would be moved to +C</tmp/test.log.1>, C</tmp/test.log.1> to C</tmp/test.log.2>, and so +forth, for every one of a max number of 12 archived logfiles that have +been configured in C<newsyslog.conf>. + +Although a new file has been created, from Log4perl's appender's point +of view, this situation is identical to the one described in the +previous FAQ entry, labeled C<How can my file appender deal with +disappearing log files>. + +To make sure that log messages are written to the new log file and not +to an archived one or end up in nowhere land, +the appender's C<recreate> and C<recreate_check_interval> have to be +configured to deal with the 'disappearing' log file. + +The situation gets interesting when C<newsyslog>'s option +to compress archived log files is enabled. This causes the +original log file not to be moved, but to disappear. If the +file appender isn't configured to recreate the logfile in this situation, +log messages will actually be lost without warning. This also +applies for the short time frame of C<recreate_check_interval> seconds +in between the recreator's file checks. + +To make sure that no messages get lost, one option is to set the +interval to + + log4perl.appender.Logfile.recreate_check_interval = 0 + +However, this is fairly expensive. A better approach is to define +a signal handler: + + log4perl.appender.Logfile.recreate = 1 + log4perl.appender.Logfile.recreate_check_signal = USR1 + log4perl.appender.Logfile.recreate_pid_write = /tmp/myappid + +As a service for C<newsyslog> users, Log4perl's file appender writes +the current process ID to a PID file specified by the C<recreate_pid_write> +option. C<newsyslog> then needs to be configured as in + + # newsyslog.conf configuration for compressing archive files and + # sending a signal to the Log4perl-enabled application + /tmp/test.log 666 12 5 * B /tmp/myappid 30 + +to send the defined signal (30, which is USR1 on FreeBSD) to the +application process at rotation time. Note that the signal number +is different on Linux, where USR1 denotes as 10. Check C<man signal> +for details. + +=head2 How can a process under user id A log to a file under user id B? + +This scenario often occurs in configurations where processes run under +various user IDs but need to write to a log file under a fixed, but +different user id. + +With a traditional file appender, the log file will probably be created +under one user's id and appended to under a different user's id. With +a typical umask of 0002, the file will be created with -rw-rw-r-- +permissions. If a user who's not in the first user's group +subsequently appends to the log file, it will fail because of a +permission problem. + +Two potential solutions come to mind: + +=over 4 + +=item * + +Creating the file with a umask of 0000 will allow all users to append +to the log file. Log4perl's file appender C<Log::Log4perl::Appender::File> +has an C<umask> option that can be set to support this: + + log4perl.appender.File = Log::Log4perl::Appender::File + log4perl.appender.File.umask = sub { 0000 }; + +This way, the log file will be created with -rw-rw-rw- permissions and +therefore has world write permissions. This might open up the logfile +for unwanted manipulations by arbitrary users, though. + +=item * + +Running the process under an effective user id of C<root> will allow +it to write to the log file, no matter who started the process. +However, this is not a good idea, because of security concerns. + +=back + +Luckily, under Unix, there's the syslog daemon which runs as root and +takes log requests from user processes over a socket and writes them +to log files as configured in C</etc/syslog.conf>. + +By modifying C</etc/syslog.conf> and HUPing the syslog daemon, you can +configure new log files: + + # /etc/syslog.conf + ... + user.* /some/path/file.log + +Using the C<Log::Dispatch::Syslog> appender, which comes with the +C<Log::Log4perl> distribution, you can then send messages via syslog: + + use Log::Log4perl qw(:easy); + + Log::Log4perl->init(\<<EOT); + log4perl.logger = DEBUG, app + log4perl.appender.app=Log::Dispatch::Syslog + log4perl.appender.app.Facility=user + log4perl.appender.app.layout=SimpleLayout + EOT + + # Writes to /some/path/file.log + ERROR "Message!"; + +This way, the syslog daemon will solve the permission problem. + +Note that while it is possible to use syslog() without Log4perl (syslog +supports log levels, too), traditional syslog setups have a +significant drawback. + +Without Log4perl's ability to activate logging in only specific +parts of a system, complex systems will trigger log events all over +the place and slow down execution to a crawl at high debug levels. + +Remote-controlling logging in the hierarchical parts of an application +via Log4perl's categories is one of its most distinguished features. +It allows for enabling high debug levels in specified areas without +noticeable performance impact. + +=head2 I want to use UTC instead of the local time! + +If a layout defines a date, Log::Log4perl uses local time to populate it. +If you want UTC instead, set + + log4perl.utcDateTimes = 1 + +in your configuration. Alternatively, you can set + + $Log::Log4perl::DateFormat::GMTIME = 1; + +in your program before the first log statement. + +=head2 Can Log4perl intercept messages written to a filehandle? + +You have a function that prints to a filehandle. You want to tie +into that filehandle and forward all arriving messages to a +Log4perl logger. + +First, let's write a package that ties a file handle and forwards it +to a Log4perl logger: + + package FileHandleLogger; + use Log::Log4perl qw(:levels get_logger); + + sub TIEHANDLE { + my($class, %options) = @_; + + my $self = { + level => $DEBUG, + category => '', + %options + }; + + $self->{logger} = get_logger($self->{category}), + bless $self, $class; + } + + sub PRINT { + my($self, @rest) = @_; + $Log::Log4perl::caller_depth++; + $self->{logger}->log($self->{level}, @rest); + $Log::Log4perl::caller_depth--; + } + + sub PRINTF { + my($self, $fmt, @rest) = @_; + $Log::Log4perl::caller_depth++; + $self->PRINT(sprintf($fmt, @rest)); + $Log::Log4perl::caller_depth--; + } + + 1; + +Now, if you have a function like + + sub function_printing_to_fh { + my($fh) = @_; + printf $fh "Hi there!\n"; + } + +which takes a filehandle and prints something to it, it can be used +with Log4perl: + + use Log::Log4perl qw(:easy); + usa FileHandleLogger; + + Log::Log4perl->easy_init($DEBUG); + + tie *SOMEHANDLE, 'FileHandleLogger' or + die "tie failed ($!)"; + + function_printing_to_fh(*SOMEHANDLE); + # prints "2007/03/22 21:43:30 Hi there!" + +If you want, you can even specify a different log level or category: + + tie *SOMEHANDLE, 'FileHandleLogger', + level => $INFO, category => "Foo::Bar" or die "tie failed ($!)"; + +=head2 I want multiline messages rendered line-by-line! + +With the standard C<PatternLayout>, if you send a multiline message to +an appender as in + + use Log::Log4perl qw(:easy); + Log + +it gets rendered this way: + + 2007/04/04 23:23:39 multi + line + message + +If you want each line to be rendered separately according to +the layout use C<Log::Log4perl::Layout::PatternLayout::Multiline>: + + use Log::Log4perl qw(:easy); + + Log::Log4perl->init(\<<EOT); + log4perl.category = DEBUG, Screen + log4perl.appender.Screen = Log::Log4perl::Appender::Screen + log4perl.appender.Screen.layout = \\ + Log::Log4perl::Layout::PatternLayout::Multiline + log4perl.appender.Screen.layout.ConversionPattern = %d %m %n + EOT + + DEBUG "some\nmultiline\nmessage"; + +and you'll get + + 2007/04/04 23:23:39 some + 2007/04/04 23:23:39 multiline + 2007/04/04 23:23:39 message + +instead. + +=head2 I'm on Windows and I'm getting all these 'redefined' messages! + +If you're on Windows and are getting warning messages like + + Constant subroutine Log::Log4perl::_INTERNAL_DEBUG redefined at + C:/Programme/Perl/lib/constant.pm line 103. + Subroutine import redefined at + C:/Programme/Perl/site/lib/Log/Log4Perl.pm line 69. + Subroutine initialized redefined at + C:/Programme/Perl/site/lib/Log/Log4Perl.pm line 207. + +then chances are that you're using 'Log::Log4Perl' (wrong uppercase P) +instead of the correct 'Log::Log4perl'. Perl on Windows doesn't +handle this error well and spits out a slew of confusing warning +messages. But now you know, just use the correct module name and +you'll be fine. + +=head2 Log4perl complains that no initialization happened during shutdown! + +If you're using Log4perl log commands in DESTROY methods of your objects, +you might see confusing messages like + + Log4perl: Seems like no initialization happened. Forgot to call init()? + Use of uninitialized value in subroutine entry at + /home/y/lib/perl5/site_perl/5.6.1/Log/Log4perl.pm line 134 during global + destruction. (in cleanup) Undefined subroutine &main:: called at + /home/y/lib/perl5/site_perl/5.6.1/Log/Log4perl.pm line 134 during global + destruction. + +when the program shuts down. What's going on? + +This phenomenon happens if you have circular references in your objects, +which perl can't clean up when an object goes out of scope but waits +until global destruction instead. At this time, however, Log4perl has +already shut down, so you can't use it anymore. + +For example, here's a simple class which uses a logger in its DESTROY +method: + + package A; + use Log::Log4perl qw(:easy); + sub new { bless {}, shift } + sub DESTROY { DEBUG "Waaah!"; } + +Now, if the main program creates a self-referencing object, like in + + package main; + use Log::Log4perl qw(:easy); + Log::Log4perl->easy_init($DEBUG); + + my $a = A->new(); + $a->{selfref} = $a; + +then you'll see the error message shown above during global destruction. +How to tackle this problem? + +First, you should clean up your circular references before global +destruction. They will not only cause objects to be destroyed in an order +that's hard to predict, but also eat up memory until the program shuts +down. + +So, the program above could easily be fixed by putting + + $a->{selfref} = undef; + +at the end or in an END handler. If that's hard to do, use weak references: + + package main; + use Scalar::Util qw(weaken); + use Log::Log4perl qw(:easy); + Log::Log4perl->easy_init($DEBUG); + + my $a = A->new(); + $a->{selfref} = weaken $a; + +This allows perl to clean up the circular reference when the object +goes out of scope, and doesn't wait until global destruction. + +=head2 How can I access POE heap values from Log4perl's layout? + +POE is a framework for creating multitasked applications running in a +single process and a single thread. POE's threads equivalents are +'sessions' and since they run quasi-simultaneously, you can't use +Log4perl's global NDC/MDC to hold session-specific data. + +However, POE already maintains a data store for every session. It is called +'heap' and is just a hash storing session-specific data in key-value pairs. +To access this per-session heap data from a Log4perl layout, define a +custom cspec and reference it with the newly defined pattern in the layout: + + use strict; + use POE; + use Log::Log4perl qw(:easy); + + Log::Log4perl->init( \ q{ + log4perl.logger = DEBUG, Screen + log4perl.appender.Screen = Log::Log4perl::Appender::Screen + log4perl.appender.Screen.layout = PatternLayout + log4perl.appender.Screen.layout.ConversionPattern = %U %m%n + log4perl.PatternLayout.cspec.U = \ + sub { POE::Kernel->get_active_session->get_heap()->{ user } } + } ); + + for (qw( Huey Lewey Dewey )) { + POE::Session->create( + inline_states => { + _start => sub { + $_[HEAP]->{user} = $_; + POE::Kernel->yield('hello'); + }, + hello => sub { + DEBUG "I'm here now"; + } + } + ); + } + + POE::Kernel->run(); + exit; + +The code snippet above defines a new layout placeholder (called +'cspec' in Log4perl) %U which calls a subroutine, retrieves the active +session, gets its heap and looks up the entry specified ('user'). + +Starting with Log::Log4perl 1.20, cspecs also support parameters in +curly braces, so you can say + + log4perl.appender.Screen.layout.ConversionPattern = %U{user} %U{id} %m%n + log4perl.PatternLayout.cspec.U = \ + sub { POE::Kernel->get_active_session-> \ + get_heap()->{ $_[0]->{curlies} } } + +and print the POE session heap entries 'user' and 'id' with every logged +message. For more details on cpecs, read the PatternLayout manual. + +=head2 I want to print something unconditionally! + +Sometimes it's a script that's supposed to log messages regardless if +Log4perl has been initialized or not. Or there's a logging statement that's +not going to be suppressed under any circumstances -- many people want to +have the final word, make the executive decision, because it seems like +the only logical choice. + +But think about it: +First off, if a messages is supposed to be printed, where is it supposed +to end up at? STDOUT? STDERR? And are you sure you want to set in stone +that this message needs to be printed, while someone else might +find it annoying and wants to get rid of it? + +The truth is, there's always going to be someone who wants to log a +messages at all cost, but also another person who wants to suppress it +with equal vigilance. There's no good way to serve these two conflicting +desires, someone will always want to win at the cost of leaving +the other party disappointed. + +So, the best Log4perl offers is the ALWAYS level for a message that even +fires if the system log level is set to $OFF: + + use Log::Log4perl qw(:easy); + + Log::Log4perl->easy_init( $OFF ); + ALWAYS "This gets logged always. Well, almost always"; + +The logger won't fire, though, if Log4perl hasn't been initialized or +if someone defines a custom log hurdle that's higher than $OFF. + +Bottom line: Leave the setting of the logging level to the initial Perl +script -- let their owners decided what they want, no matter how tempting +it may be to decide it for them. + +=head2 Why doesn't my END handler remove my log file on Win32? + +If you have code like + + use Log::Log4perl qw( :easy ); + Log::Log4perl->easy_init( { level => $DEBUG, file => "my.log" } ); + END { unlink "my.log" or die }; + +then you might be in for a surprise when you're running it on +Windows, because the C<unlink()> call in the END handler will complain that +the file is still in use. + +What happens in Perl if you have something like + + END { print "first end in main\n"; } + use Module; + END { print "second end in main\n"; } + +and + + package Module; + END { print "end in module\n"; } + 1; + +is that you get + + second end in main + end in module + first end in main + +because perl stacks the END handlers in reverse order in which it +encounters them in the compile phase. + +Log4perl defines an END handler that cleans up left-over appenders (e.g. +file appenders which still hold files open), because those appenders have +circular references and therefore aren't cleaned up otherwise. + +Now if you define an END handler after "use Log::Log4perl", it'll +trigger before Log4perl gets a chance to clean up, which isn't a +problem on Unix where you can delete a file even if some process has a +handle to it open, but it's a problem on Win32, where the OS won't +let you do that. + +The solution is easy, just place the END handler I<before> Log4perl +gets loaded, like in + + END { unlink "my.log" or die }; + use Log::Log4perl qw( :easy ); + Log::Log4perl->easy_init( { level => $DEBUG, file => "my.log" } ); + +which will call the END handlers in the intended order. + +=cut + +=head1 SEE ALSO + +Log::Log4perl + +=head1 LICENSE + +Copyright 2002-2013 by Mike Schilli E<lt>m@perlmeister.comE<gt> +and Kevin Goess E<lt>cpan@goess.orgE<gt>. + +This library is free software; you can redistribute it and/or modify +it under the same terms as Perl itself. + +=head1 AUTHOR + +Please contribute patches to the project on Github: + + http://github.com/mschilli/log4perl + +Send bug reports or requests for enhancements to the authors via our + +MAILING LIST (questions, bug reports, suggestions/patches): +log4perl-devel@lists.sourceforge.net + +Authors (please contact them via the list above, not directly): +Mike Schilli <m@perlmeister.com>, +Kevin Goess <cpan@goess.org> + +Contributors (in alphabetical order): +Ateeq Altaf, Cory Bennett, Jens Berthold, Jeremy Bopp, Hutton +Davidson, Chris R. Donnelly, Matisse Enzer, Hugh Esco, Anthony +Foiani, James FitzGibbon, Carl Franks, Dennis Gregorovic, Andy +Grundman, Paul Harrington, Alexander Hartmaier David Hull, +Robert Jacobson, Jason Kohles, Jeff Macdonald, Markus Peter, +Brett Rann, Peter Rabbitson, Erik Selberg, Aaron Straup Cope, +Lars Thegler, David Viner, Mac Yang. + |