11;
2
3__END__
4
5=head1 NAME
6
7Log::Log4perl::FAQ - Frequently Asked Questions on Log::Log4perl
8
9=head1 DESCRIPTION
10
11This FAQ shows a wide variety of
12commonly encountered logging tasks and how to solve them
13in the most elegant way with Log::Log4perl. Most of the time, this will
14be just a matter of smartly configuring your Log::Log4perl configuration files.
15
16=head2 Why use Log::Log4perl instead of any other logging module on CPAN?
17
18That's a good question. There's dozens of logging modules on CPAN.
19When it comes to logging, people typically think: "Aha. Writing out
20debug and error messages. Debug is lower than error. Easy. I'm gonna
21write my own." Writing a logging module is like a rite of passage for
22every Perl programmer, just like writing your own templating system.
23
24Of course, after getting the basics right, features need to
25be added. You'd like to write a timestamp with every message. Then
26timestamps with microseconds. Then messages need to be written to both
27the screen and a log file.
28
29And, as your application grows in size you might wonder: Why doesn't
30my logging system scale along with it? You would like to switch on
31logging in selected parts of the application, and not all across the
32board, because this kills performance. This is when people turn to
33Log::Log4perl, because it handles all of that.
34
35Avoid this costly switch.
36
37Use C<Log::Log4perl> right from the start. C<Log::Log4perl>'s C<:easy>
38mode supports easy logging in simple scripts:
39
40    use Log::Log4perl qw(:easy);
41    Log::Log4perl->easy_init($DEBUG);
42
43    DEBUG "A low-level message";
44    ERROR "Won't make it until level gets increased to ERROR";
45
46And when your application inevitably grows, your logging system grows
47with it without you having to change any code.
48
49Please, don't re-invent logging. C<Log::Log4perl> is here, it's easy
50to use, it scales, and covers many areas you haven't thought of yet,
51but will enter soon.
52
53=head2 What's the easiest way to use Log4perl?
54
55If you just want to get all the comfort of logging, without much
56overhead, use I<Stealth Loggers>. If you use Log::Log4perl in
57C<:easy> mode like
58
59    use Log::Log4perl qw(:easy);
60
61you'll have the following functions available in the current package:
62
63    DEBUG("message");
64    INFO("message");
65    WARN("message");
66    ERROR("message");
67    FATAL("message");
68
69Just make sure that every package of your code where you're using them in
70pulls in C<use Log::Log4perl qw(:easy)> first, then you're set.
71Every stealth logger's category will be equivalent to the name of the
72package it's located in.
73
74These stealth loggers
75will be absolutely silent until you initialize Log::Log4perl in
76your main program with either
77
78        # Define any Log4perl behaviour
79    Log::Log4perl->init("foo.conf");
80
81(using a full-blown Log4perl config file) or the super-easy method
82
83        # Just log to STDERR
84    Log::Log4perl->easy_init($DEBUG);
85
86or the parameter-style method with a complexity somewhat in between:
87
88        # Append to a log file
89    Log::Log4perl->easy_init( { level   => $DEBUG,
90                                file    => ">>test.log" } );
91
92For more info, please check out L<Log::Log4perl/"Stealth Loggers">.
93
94=head2 How can I simply log all my ERROR messages to a file?
95
96After pulling in the C<Log::Log4perl> module, just initialize its
97behaviour by passing in a configuration to its C<init> method as a string
98reference. Then, obtain a logger instance and write out a message
99with its C<error()> method:
100
101    use Log::Log4perl qw(get_logger);
102
103        # Define configuration
104    my $conf = q(
105        log4perl.logger                    = ERROR, FileApp
106        log4perl.appender.FileApp          = Log::Log4perl::Appender::File
107        log4perl.appender.FileApp.filename = test.log
108        log4perl.appender.FileApp.layout   = PatternLayout
109        log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n
110    );
111
112        # Initialize logging behaviour
113    Log::Log4perl->init( \$conf );
114
115        # Obtain a logger instance
116    my $logger = get_logger("Bar::Twix");
117    $logger->error("Oh my, a dreadful error!");
118    $logger->warn("Oh my, a dreadful warning!");
119
120This will append something like
121
122    2002/10/29 20:11:55> Oh my, a dreadful error!
123
124to the log file C<test.log>. How does this all work?
125
126While the Log::Log4perl C<init()> method typically
127takes the name of a configuration file as its input parameter like
128in
129
130    Log::Log4perl->init( "/path/mylog.conf" );
131
132the example above shows how to pass in a configuration as text in a
133scalar reference.
134
135The configuration as shown
136defines a logger of the root category, which has an appender of type
137C<Log::Log4perl::Appender::File> attached. The line
138
139    log4perl.logger = ERROR, FileApp
140
141doesn't list a category, defining a root logger. Compare that with
142
143    log4perl.logger.Bar.Twix = ERROR, FileApp
144
145which would define a logger for the category C<Bar::Twix>,
146showing probably different behaviour. C<FileApp> on
147the right side of the assignment is
148an arbitrarily defined variable name, which is only used to somehow
149reference an appender defined later on.
150
151Appender settings in the configuration are defined as follows:
152
153    log4perl.appender.FileApp          = Log::Log4perl::Appender::File
154    log4perl.appender.FileApp.filename = test.log
155
156It selects the file appender of the C<Log::Log4perl::Appender>
157hierarchy, which will append to the file C<test.log> if it already
158exists. If we wanted to overwrite a potentially existing file, we would
159have to explicitly set the appropriate C<Log::Log4perl::Appender::File>
160parameter C<mode>:
161
162    log4perl.appender.FileApp          = Log::Log4perl::Appender::File
163    log4perl.appender.FileApp.filename = test.log
164    log4perl.appender.FileApp.mode     = write
165
166Also, the configuration defines a PatternLayout format, adding
167the nicely formatted current date and time, an arrow (E<gt>) and
168a space before the messages, which is then followed by a newline:
169
170    log4perl.appender.FileApp.layout   = PatternLayout
171    log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n
172
173Obtaining a logger instance and actually logging something is typically
174done in a different system part as the Log::Log4perl initialisation section,
175but in this example, it's just done right after init for the
176sake of compactness:
177
178        # Obtain a logger instance
179    my $logger = get_logger("Bar::Twix");
180    $logger->error("Oh my, a dreadful error!");
181
182This retrieves an instance of the logger of the category C<Bar::Twix>,
183which, as all other categories, inherits behaviour from the root logger if no
184other loggers are defined in the initialization section.
185
186The C<error()>
187method fires up a message, which the root logger catches. Its
188priority is equal to
189or higher than the root logger's priority (ERROR), which causes the root logger
190to forward it to its attached appender. By contrast, the following
191
192    $logger->warn("Oh my, a dreadful warning!");
193
194doesn't make it through, because the root logger sports a higher setting
195(ERROR and up) than the WARN priority of the message.
196
197=head2 How can I install Log::Log4perl on Microsoft Windows?
198
199Log::Log4perl is fully supported on the Win32 platform. It has been tested
200with Activestate perl 5.6.1 under Windows 98 and rumor has it that it
201also runs smoothly on all other major flavors (Windows NT, 2000, XP, etc.).
202
203It also runs nicely with ActiveState 5.8.0, and, believe me,
204we had to jump through some major hoops for that.
205
206Typically, Win32 systems don't have the C<make> utility installed,
207so the standard C<perl Makefile.PL; make install> on the downloadable
208distribution won't work. But don't despair, there's a very easy solution!
209
210The C<Log::Log4perl> homepage provides a so-called PPD file for ActiveState's
211C<ppm> installer, which comes with ActiveState perl by default.
212
213=over 4
214
215=item Install on ActiveState 5.6.*
216
217The DOS command line
218
219    ppm install "http://log4perl.sourceforge.net/ppm/Log-Log4perl.ppd"
220
221will contact the Log4perl homepage, download the latest
222C<Log::Log4perl>
223distribution and install it. If your ActiveState installation
224lacks any of the modules C<Log::Log4perl> depends upon, C<ppm> will
225automatically contact ActivateState and download them from their CPAN-like
226repository.
227
228=item Install on ActiveState 5.8.*
229
230ActiveState's "Programmer's Package Manager" can be called from
231Window's Start Menu:
232Start-E<gt>Programs->E<gt>ActiveState ActivePerl 5.8E<gt>Perl Package Manager
233will invoke ppm. Since Log::Log4perl hasn't made it yet into the standard
234ActiveState repository (and you probably don't want their outdated packages
235anyway), just tell ppm the first time you call it to add the Log4perl
236repository
237
238    ppm> repository add http://log4perl.sourceforge.net/ppm
239
240Then, just tell it to install Log::Log4perl and it will resolve all
241dependencies automatically and fetch them from log4perl.sourceforge.net
242if it can't find them in the main archives:
243
244    ppm> install Log-Log4perl
245
246=back
247
248That's it! Afterwards, just create a Perl script like
249
250    use Log::Log4perl qw(:easy);
251    Log::Log4perl->easy_init($DEBUG);
252
253    my $logger = get_logger("Twix::Bar");
254    $logger->debug("Watch me!");
255
256and run it. It should print something like
257
258    2002/11/06 01:22:05 Watch me!
259
260If you find that something doesn't work, please let us know at
261log4perl-devel@lists.sourceforge.net -- we'll apprechiate it. Have fun!
262
263=head2 How can I include global (thread-specific) data in my log messages?
264
265Say, you're writing a web application and want all your
266log messages to include the current client's IP address. Most certainly,
267you don't want to include it in each and every log message like in
268
269    $logger->debug( $r->connection->remote_ip,
270                    " Retrieving user data from DB" );
271
272do you? Instead, you want to set it in a global data structure and
273have Log::Log4perl include it automatically via a PatternLayout setting
274in the configuration file:
275
276    log4perl.appender.FileApp.layout.ConversionPattern = %X{ip} %m%n
277
278The conversion specifier C<%X{ip}> references an entry under the key
279C<ip> in the global C<MDC> (mapped diagnostic context) table, which
280you've set once via
281
282    Log::Log4perl::MDC->put("ip", $r->connection->remote_ip);
283
284at the start of the request handler. Note that this is a
285I<static> (class) method, there's no logger object involved.
286You can use this method with as many key/value pairs as you like as long
287as you reference them under different names.
288
289The mappings are stored in a global hash table within Log::Log4perl.
290Luckily, because the thread
291model in 5.8.0 doesn't share global variables between threads unless
292they're explicitly marked as such, there's no problem with multi-threaded
293environments.
294
295For more details on the MDC, please refer to
296L<Log::Log4perl/"Mapped Diagnostic Context (MDC)"> and
297L<Log::Log4perl::MDC>.
298
299=head2 My application is already logging to a file. How can I duplicate all messages to also go to the screen?
300
301Assuming that you already have a Log4perl configuration file like
302
303    log4perl.logger                    = DEBUG, FileApp
304
305    log4perl.appender.FileApp          = Log::Log4perl::Appender::File
306    log4perl.appender.FileApp.filename = test.log
307    log4perl.appender.FileApp.layout   = PatternLayout
308    log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n
309
310and log statements all over your code,
311it's very easy with Log4perl to have the same messages both printed to
312the logfile and the screen. No reason to change your code, of course,
313just add another appender to the configuration file and you're done:
314
315    log4perl.logger                    = DEBUG, FileApp, ScreenApp
316
317    log4perl.appender.FileApp          = Log::Log4perl::Appender::File
318    log4perl.appender.FileApp.filename = test.log
319    log4perl.appender.FileApp.layout   = PatternLayout
320    log4perl.appender.FileApp.layout.ConversionPattern = %d> %m%n
321
322    log4perl.appender.ScreenApp          = Log::Log4perl::Appender::Screen
323    log4perl.appender.ScreenApp.stderr   = 0
324    log4perl.appender.ScreenApp.layout   = PatternLayout
325    log4perl.appender.ScreenApp.layout.ConversionPattern = %d> %m%n
326
327The configuration file above is assuming that both appenders are
328active in the same logger hierarchy, in this case the C<root> category.
329But even if you've got file loggers defined in several parts of your system,
330belonging to different logger categories,
331each logging to different files, you can gobble up all logged messages
332by defining a root logger with a screen appender, which would duplicate
333messages from all your file loggers to the screen due to Log4perl's
334appender inheritance. Check
335
336    http://www.perl.com/pub/a/2002/09/11/log4perl.html
337
338for details. Have fun!
339
340=head2 How can I make sure my application logs a message when it dies unexpectedly?
341
342Whenever you encounter a fatal error in your application, instead of saying
343something like
344
345    open FILE, "<blah" or die "Can't open blah -- bailing out!";
346
347just use Log::Log4perl's fatal functions instead:
348
349    my $log = get_logger("Some::Package");
350    open FILE, "<blah" or $log->logdie("Can't open blah -- bailing out!");
351
352This will both log the message with priority FATAL according to your current
353Log::Log4perl configuration and then call Perl's C<die()>
354afterwards to terminate the program. It works the same with
355stealth loggers (see L<Log::Log4perl/"Stealth Loggers">),
356all you need to do is call
357
358    use Log::Log4perl qw(:easy);
359    open FILE, "<blah" or LOGDIE "Can't open blah -- bailing out!";
360
361What can you do if you're using some library which doesn't use Log::Log4perl
362and calls C<die()> internally if something goes wrong? Use a
363C<$SIG{__DIE__}> pseudo signal handler
364
365    use Log::Log4perl qw(get_logger);
366
367    $SIG{__DIE__} = sub {
368        if($^S) {
369            # We're in an eval {} and don't want log
370            # this message but catch it later
371            return;
372        }
373        $Log::Log4perl::caller_depth++;
374        my $logger = get_logger("");
375        $logger->fatal(@_);
376        die @_; # Now terminate really
377    };
378
379This will catch every C<die()>-Exception of your
380application or the modules it uses. In case you want to
381It
382will fetch a root logger and pass on the C<die()>-Message to it.
383If you make sure you've configured with a root logger like this:
384
385    Log::Log4perl->init(\q{
386        log4perl.category         = FATAL, Logfile
387        log4perl.appender.Logfile = Log::Log4perl::Appender::File
388        log4perl.appender.Logfile.filename = fatal_errors.log
389        log4perl.appender.Logfile.layout = \
390                   Log::Log4perl::Layout::PatternLayout
391        log4perl.appender.Logfile.layout.ConversionPattern = %F{1}-%L (%M)> %m%n
392    });
393
394then all C<die()> messages will be routed to a file properly. The line
395
396     $Log::Log4perl::caller_depth++;
397
398in the pseudo signal handler above merits a more detailed explanation. With
399the setup above, if a module calls C<die()> in one of its functions,
400the fatal message will be logged in the signal handler and not in the
401original function -- which will cause the %F, %L and %M placeholders
402in the pattern layout to be replaced by the filename, the line number
403and the function/method name of the signal handler, not the error-throwing
404module. To adjust this, Log::Log4perl has the C<$caller_depth> variable,
405which defaults to 0, but can be set to positive integer values
406to offset the caller level. Increasing
407it by one will cause it to log the calling function's parameters, not
408the ones of the signal handler.
409See L<Log::Log4perl/"Using Log::Log4perl from wrapper classes"> for more
410details.
411
412=head2 How can I hook up the LWP library with Log::Log4perl?
413
414Or, to put it more generally: How can you utilize a third-party
415library's embedded logging and debug statements in Log::Log4perl?
416How can you make them print
417to configurable appenders, turn them on and off, just as if they
418were regular Log::Log4perl logging statements?
419
420The easiest solution is to map the third-party library logging statements
421to Log::Log4perl's stealth loggers via a typeglob assignment.
422
423As an example, let's take LWP, one of the most popular Perl modules,
424which makes handling WWW requests and responses a breeze.
425Internally, LWP uses its own logging and debugging system,
426utilizing the following calls
427inside the LWP code (from the LWP::Debug man page):
428
429        # Function tracing
430    LWP::Debug::trace('send()');
431
432        # High-granular state in functions
433    LWP::Debug::debug('url ok');
434
435        # Data going over the wire
436    LWP::Debug::conns("read $n bytes: $data");
437
438First, let's assign Log::Log4perl priorities
439to these functions: I'd suggest that
440C<debug()> messages have priority C<INFO>,
441C<trace()> uses C<DEBUG> and C<conns()> also logs with C<DEBUG> --
442although your mileage may certainly vary.
443
444Now, in order to transpartently hook up LWP::Debug with Log::Log4perl,
445all we have to do is say
446
447    package LWP::Debug;
448    use Log::Log4perl qw(:easy);
449
450    *trace = *INFO;
451    *conns = *DEBUG;
452    *debug = *DEBUG;
453
454    package main;
455    # ... go on with your regular program ...
456
457at the beginning of our program. In this way, every time the, say,
458C<LWP::UserAgent> module calls C<LWP::Debug::trace()>, it will implicitely
459call INFO(), which is the C<info()> method of a stealth logger defined for
460the Log::Log4perl category C<LWP::Debug>. Is this cool or what?
461
462Here's a complete program:
463
464    use LWP::UserAgent;
465    use HTTP::Request::Common;
466    use Log::Log4perl qw(:easy);
467
468    Log::Log4perl->easy_init(
469        { category => "LWP::Debug",
470          level    => $DEBUG,
471          layout   => "%r %p %M-%L %m%n",
472        });
473
474    package LWP::Debug;
475    use Log::Log4perl qw(:easy);
476    *trace = *INFO;
477    *conns = *DEBUG;
478    *debug = *DEBUG;
479
480    package main;
481    my $ua = LWP::UserAgent->new();
482    my $resp = $ua->request(GET "http://amazon.com");
483
484    if($resp->is_success()) {
485        print "Success: Received ",
486              length($resp->content()), "\n";
487    } else {
488        print "Error: ", $resp->code(), "\n";
489    }
490
491This will generate the following output on STDERR:
492
493    174 INFO LWP::UserAgent::new-164 ()
494    208 INFO LWP::UserAgent::request-436 ()
495    211 INFO LWP::UserAgent::send_request-294 GET http://amazon.com
496    212 DEBUG LWP::UserAgent::_need_proxy-1123 Not proxied
497    405 INFO LWP::Protocol::http::request-122 ()
498    859 DEBUG LWP::Protocol::collect-206 read 233 bytes
499    863 DEBUG LWP::UserAgent::request-443 Simple response: Found
500    869 INFO LWP::UserAgent::request-436 ()
501    871 INFO LWP::UserAgent::send_request-294
502     GET http://www.amazon.com:80/exec/obidos/gateway_redirect
503    872 DEBUG LWP::UserAgent::_need_proxy-1123 Not proxied
504    873 INFO LWP::Protocol::http::request-122 ()
505    1016 DEBUG LWP::UserAgent::request-443 Simple response: Found
506    1020 INFO LWP::UserAgent::request-436 ()
507    1022 INFO LWP::UserAgent::send_request-294
508     GET http://www.amazon.com/exec/obidos/subst/home/home.html/
509    1023 DEBUG LWP::UserAgent::_need_proxy-1123 Not proxied
510    1024 INFO LWP::Protocol::http::request-122 ()
511    1382 DEBUG LWP::Protocol::collect-206 read 632 bytes
512    ...
513    2605 DEBUG LWP::Protocol::collect-206 read 77 bytes
514    2607 DEBUG LWP::UserAgent::request-443 Simple response: OK
515    Success: Received 42584
516
517Of course, in this way, the embedded logging and debug statements within
518LWP can be utilized in any Log::Log4perl way you can think of. You can
519have them sent to different appenders, block them based on the
520category and everything else Log::Log4perl has to offer.
521
522Only drawback of this method: Steering logging behaviour via category
523is always based on the C<LWP::Debug> package. Although the logging
524statements reflect the package name of the issuing module properly,
525the stealth loggers in C<LWP::Debug> are all of the category C<LWP::Debug>.
526This implies that you can't control the logging behaviour based on the
527package that's I<initiating> a log request (e.g. LWP::UserAgent) but only
528based on the package that's actually I<executing> the logging statement,
529C<LWP::Debug> in this case.
530
531To work around this conundrum, we need to write a wrapper function and
532plant it into the C<LWP::Debug> package. It will determine the caller and
533create a logger bound to a category with the same name as the caller's
534package:
535
536    package LWP::Debug;
537
538    use Log::Log4perl qw(:levels get_logger);
539
540    sub l4p_wrapper {
541        my($prio, @message) = @_;
542        $Log::Log4perl::caller_depth += 2;
543        get_logger(scalar caller(1))->log($prio, @message);
544        $Log::Log4perl::caller_depth -= 2;
545    }
546
547    no warnings 'redefine';
548    *trace = sub { l4p_wrapper($INFO, @_); };
549    *debug = *conns = sub { l4p_wrapper($DEBUG, @_); };
550
551    package main;
552    # ... go on with your main program ...
553
554This is less performant than the previous approach, because every
555log request will request a reference to a logger first, then call
556the wrapper, which will in turn call the appropriate log function.
557
558This hierarchy shift has to be compensated for by increasing
559C<$Log::Log4perl::caller_depth> by 2 before calling the log function
560and decreasing it by 2 right afterwards. Also, the C<l4p_wrapper>
561function shown above calls C<caller(1)> which determines the name
562of the package I<two> levels down the calling hierarchy (and
563therefore compensates for both the wrapper function and the
564anonymous subroutine calling it).
565
566C<no warnings 'redefine'> suppresses a warning Perl would generate
567otherwise
568upon redefining C<LWP::Debug>'s C<trace()>, C<debug()> and C<conns()>
569functions. In case you use a perl prior to 5.6.x, you need
570to manipulate C<$^W> instead.
571
572To make things easy for you when dealing with LWP, Log::Log4perl 0.47
573introduces C<Log::Log4perl-E<gt>infiltrate_lwp()> which does exactly the
574above.
575
576=head2 What if I need dynamic values in a static Log4perl configuration file?
577
578Say, your application uses Log::Log4perl for logging and
579therefore comes with a Log4perl configuration file, specifying the logging
580behaviour.
581But, you also want it to take command line parameters to set values
582like the name of the log file.
583How can you have
584both a static Log4perl configuration file and a dynamic command line
585interface?
586
587As of Log::Log4perl 0.28, every value in the configuration file
588can be specified as a I<Perl hook>. So, instead of saying
589
590    log4perl.appender.Logfile.filename = test.log
591
592you could just as well have a Perl subroutine deliver the value
593dynamically:
594
595    log4perl.appender.Logfile.filename = sub { logfile(); };
596
597given that C<logfile()> is a valid function in your C<main> package
598returning a string containing the path to the log file.
599
600Or, think about using the value of an environment variable:
601
602    log4perl.appender.DBI.user = sub { $ENV{USERNAME} };
603
604When C<Log::Log4perl-E<gt>init()> parses the configuration
605file, it will notice the assignment above because of its
606C<sub {...}> pattern and treat it in a special way:
607It will evaluate the subroutine (which can contain
608arbitrary Perl code) and take its return value as the right side
609of the assignment.
610
611A typical application would be called like this on the command line:
612
613    app                # log file is "test.log"
614    app -l mylog.txt   # log file is "mylog.txt"
615
616Here's some sample code implementing the command line interface above:
617
618    use Log::Log4perl qw(get_logger);
619    use Getopt::Std;
620
621    getopt('l:', \our %OPTS);
622
623    my $conf = q(
624    log4perl.category.Bar.Twix         = WARN, Logfile
625    log4perl.appender.Logfile          = Log::Log4perl::Appender::File
626    log4perl.appender.Logfile.filename = sub { logfile(); };
627    log4perl.appender.Logfile.layout   = SimpleLayout
628    );
629
630    Log::Log4perl::init(\$conf);
631
632    my $logger = get_logger("Bar::Twix");
633    $logger->error("Blah");
634
635    ###########################################
636    sub logfile {
637    ###########################################
638        if(exists $OPTS{l}) {
639            return $OPTS{l};
640        } else {
641            return "test.log";
642        }
643    }
644
645Every Perl hook may contain arbitrary perl code,
646just make sure to fully qualify eventual variable names
647(e.g. C<%main::OPTS> instead of C<%OPTS>).
648
649B<SECURITY NOTE>: this feature means arbitrary perl code
650can be embedded in the config file.  In the rare case
651where the people who have access to your config file
652are different from the people who write your code and
653shouldn't have execute rights, you might want to call
654
655    $Log::Log4perl::Config->allow_code(0);
656
657before you call init(). This will prevent Log::Log4perl from
658executing I<any> Perl code in the config file (including
659code for custom conversion specifiers
660(see L<Log::Log4perl::Layout::PatternLayout/"Custom cspecs">).
661
662=head2 How can I roll over my logfiles automatically at midnight?
663
664Long-running applications tend to produce ever-increasing logfiles.
665For backup and cleanup purposes, however, it is often desirable to move
666the current logfile to a different location from time to time and
667start writing a new one.
668
669This is a non-trivial task, because it has to happen in sync with
670the logging system in order not to lose any messages in the process.
671
672Luckily, I<Mark Pfeiffer>'s C<Log::Dispatch::FileRotate> appender
673works well with Log::Log4perl to rotate your logfiles in a variety of ways.
674
675Note, however, that having the application deal with rotating a log
676file is not cheap. Among other things, it requires locking the log file
677with every write to avoid race conditions.
678There are good reasons to use external rotators like C<newsyslog>
679instead.
680See the entry C<How can I rotate a logfile with newsyslog?> in the
681FAQ for more information on how to configure it.
682
683When using C<Log::Dispatch::FileRotate>,
684all you have to do is specify it in your Log::Log4perl configuration file
685and your logfiles will be rotated automatically.
686
687You can choose between rolling based on a maximum size ("roll if greater
688than 10 MB") or based on a date pattern ("roll everyday at midnight").
689In both cases, C<Log::Dispatch::FileRotate> allows you to define a
690number C<max> of saved files to keep around until it starts overwriting
691the oldest ones. If you set the C<max> parameter to 2 and the name of
692your logfile is C<test.log>, C<Log::Dispatch::FileRotate> will
693move C<test.log> to C<test.log.1> on the first rollover. On the second
694rollover, it will move C<test.log.1> to C<test.log.2> and then C<test.log>
695to C<test.log.1>. On the third rollover, it will move C<test.log.1> to
696C<test.log.2> (therefore discarding the old C<test.log.2>) and
697C<test.log> to C<test.log.1>. And so forth. This way, there's always
698going to be a maximum of 2 saved log files around.
699
700Here's an example of a Log::Log4perl configuration file, defining a
701daily rollover at midnight (date pattern C<yyyy-MM-dd>), keeping
702a maximum of 5 saved logfiles around:
703
704    log4perl.category         = WARN, Logfile
705    log4perl.appender.Logfile = Log::Dispatch::FileRotate
706    log4perl.appender.Logfile.filename    = test.log
707    log4perl.appender.Logfile.max         = 5
708    log4perl.appender.Logfile.DatePattern = yyyy-MM-dd
709    log4perl.appender.Logfile.TZ          = PST
710    log4perl.appender.Logfile.layout = \
711        Log::Log4perl::Layout::PatternLayout
712    log4perl.appender.Logfile.layout.ConversionPattern = %d %m %n
713
714Please see the C<Log::Dispatch::FileRotate> documentation for details.
715C<Log::Dispatch::FileRotate> is available on CPAN.
716
717=head2 What's the easiest way to turn off all logging, even with a lengthy Log4perl configuration file?
718
719In addition to category-based levels and appender thresholds,
720Log::Log4perl supports system-wide logging thresholds. This is the
721minimum level the system will require of any logging events in order for them
722to make it through to any configured appenders.
723
724For example, putting the line
725
726    log4perl.threshold = ERROR
727
728anywhere in your configuration file will limit any output to any appender
729to events with priority of ERROR or higher (ERROR or FATAL that is).
730
731However, in order to suppress all logging entirely, you need to use a
732priority that's higher than FATAL: It is simply called C<OFF>, and it is never
733used by any logger. By definition, it is higher than the highest
734defined logger level.
735
736Therefore, if you keep the line
737
738    log4perl.threshold = OFF
739
740somewhere in your Log::Log4perl configuration, the system will be quiet
741as a graveyard. If you deactivate the line (e.g. by commenting it out),
742the system will, upon config reload, snap back to normal operation, providing
743logging messages according to the rest of the configuration file again.
744
745=head2 I keep getting duplicate log messages! What's wrong?
746
747Having several settings for related categories in the Log4perl
748configuration file sometimes leads to a phenomenon called
749"message duplication". It can be very confusing at first,
750but if thought through properly, it turns out that Log4perl behaves
751as advertised. But, don't despair, of course there's a number of
752ways to avoid message duplication in your logs.
753
754Here's a sample Log4perl configuration file that produces the
755phenomenon:
756
757    log4perl.logger.Cat        = ERROR, Screen
758    log4perl.logger.Cat.Subcat = WARN, Screen
759
760    log4perl.appender.Screen   = Log::Log4perl::Appender::Screen
761    log4perl.appender.Screen.layout = SimpleLayout
762
763It defines two loggers, one for category C<Cat> and one for
764C<Cat::Subcat>, which is obviously a subcategory of C<Cat>.
765The parent logger has a priority setting of ERROR, the child
766is set to the lower C<WARN> level.
767
768Now imagine the following code in your program:
769
770    my $logger = get_logger("Cat.Subcat");
771    $logger->warn("Warning!");
772
773What do you think will happen? An unexperienced Log4perl user
774might think: "Well, the message is being sent with level WARN, so the
775C<Cat::Subcat> logger will accept it and forward it to the
776attached C<Screen> appender. Then, the message will percolate up
777the logger hierarchy, find
778the C<Cat> logger, which will suppress the message because of its
779ERROR setting."
780But, perhaps surprisingly, what you'll get with the
781code snippet above is not one but two log messages written
782to the screen:
783
784    WARN - Warning!
785    WARN - Warning!
786
787What happened? The culprit is that once the logger C<Cat::Subcat>
788decides to fire, it will forward the message I<unconditionally>
789to all directly or indirectly attached appenders. The C<Cat> logger
790will never be asked if it wants the message or not -- the message
791will just be pushed through to the appender attached to C<Cat>.
792
793One way to prevent the message from bubbling up the logger
794hierarchy is to set the C<additivity> flag of the subordinate logger to
795C<0>:
796
797    log4perl.logger.Cat            = ERROR, Screen
798    log4perl.logger.Cat.Subcat     = WARN, Screen
799    log4perl.additivity.Cat.Subcat = 0
800
801    log4perl.appender.Screen   = Log::Log4perl::Appender::Screen
802    log4perl.appender.Screen.layout = SimpleLayout
803
804The message will now be accepted by the C<Cat::Subcat> logger,
805forwarded to its appender, but then C<Cat::Subcat> will suppress
806any further action. While this setting avoids duplicate messages
807as seen before, it is often not the desired behaviour. Messages
808percolating up the hierarchy are a useful Log4perl feature.
809
810If you're defining I<different> appenders for the two loggers,
811one other option is to define an appender threshold for the
812higher-level appender. Typically it is set to be
813equal to the logger's level setting:
814
815    log4perl.logger.Cat           = ERROR, Screen1
816    log4perl.logger.Cat.Subcat    = WARN, Screen2
817
818    log4perl.appender.Screen1   = Log::Log4perl::Appender::Screen
819    log4perl.appender.Screen1.layout = SimpleLayout
820    log4perl.appender.Screen1.Threshold = ERROR
821
822    log4perl.appender.Screen2   = Log::Log4perl::Appender::Screen
823    log4perl.appender.Screen2.layout = SimpleLayout
824
825Since the C<Screen1> appender now blocks every message with
826a priority less than ERROR, even if the logger in charge
827lets it through, the message percolating up the hierarchy is
828being blocked at the last minute and I<not> appended to C<Screen1>.
829
830So far, we've been operating well within the boundaries of the
831Log4j standard, which Log4perl adheres to. However, if
832you would really, really like to use a single appender
833and keep the message percolation intact without having to deal
834with message duplication, there's a non-standard solution for you:
835
836    log4perl.logger.Cat        = ERROR, Screen
837    log4perl.logger.Cat.Subcat = WARN, Screen
838
839    log4perl.appender.Screen   = Log::Log4perl::Appender::Screen
840    log4perl.appender.Screen.layout = SimpleLayout
841
842    log4perl.oneMessagePerAppender = 1
843
844The C<oneMessagePerAppender> flag will suppress duplicate messages
845to the same appender. Again, that's non-standard. But way cool :).
846
847=head2 How can I configure Log::Log4perl to send me email if something happens?
848
849Some incidents require immediate action. You can't wait until someone
850checks the log files, you need to get notified on your pager right away.
851
852The easiest way to do that is by using the C<Log::Dispatch::Email::MailSend>
853module as an appender. It comes with the C<Log::Dispatch> bundle and
854allows you to specify recipient and subject of outgoing emails in the Log4perl
855configuration file:
856
857    log4perl.category = FATAL, Mailer
858    log4perl.appender.Mailer         = Log::Dispatch::Email::MailSend
859    log4perl.appender.Mailer.to      = drone@pageme.net
860    log4perl.appender.Mailer.subject = Something's broken!
861    log4perl.appender.Mailer.layout  = SimpleLayout
862
863The message of every log incident this appender gets
864will then be forwarded to the given
865email address. Check the C<Log::Dispatch::Email::MailSend> documentation
866for details. And please make sure there's not a flood of email messages
867sent out by your application, filling up the receipient's inbox.
868
869There's one caveat you need to know about: The C<Log::Dispatch::Email>
870hierarchy of appenders turns on I<buffering> by default. This means that
871the appender will not send out messages right away but wait until a
872certain threshold has been reached. If you'd rather have your alerts
873sent out immeditately, use
874
875    log4perl.appender.Mailer.buffered = 0
876
877to turn buffering off.
878
879=head2 How can I write my own appender?
880
881First off, Log::Log4perl comes with a set of standard appenders. Then,
882there's a lot of Log4perl-compatible appenders already
883available on CPAN: Just run a search for C<Log::Dispatch> on
884http://search.cpan.org and chances are that what you're looking for
885has already been developed, debugged and been used successfully
886in production -- no need for you to reinvent the wheel.
887
888Also, Log::Log4perl ships with a nifty database appender named
889Log::Log4perl::Appender::DBI -- check it out if talking to databases is your
890desire.
891
892But if you're up for a truly exotic task, you might have to write
893an appender yourself. That's very easy -- it takes no longer
894than a couple of minutes.
895
896Say, we wanted to create an appender of the class
897C<ColorScreenAppender>, which logs messages
898to the screen in a configurable color. Just create a new class
899in C<ColorScreenAppender.pm>:
900
901    package ColorScreenAppender;
902
903Now let's assume that your Log::Log4perl
904configuration file C<test.conf> looks like this:
905
906    log4perl.logger = INFO, ColorApp
907
908    log4perl.appender.ColorApp=ColorScreenAppender
909    log4perl.appender.ColorApp.color=blue
910
911    log4perl.appender.ColorApp.layout = PatternLayout
912    log4perl.appender.ColorApp.layout.ConversionPattern=%d %m %n
913
914This will cause Log::Log4perl on C<init()> to look for a class
915ColorScreenAppender and call its constructor new(). Let's add
916new() to ColorScreenAppender.pm:
917
918    sub new {
919        my($class, %options) = @_;
920
921        my $self = { %options };
922        bless $self, $class;
923
924        return $self;
925    }
926
927To initialize this appender, Log::Log4perl will call
928and pass all attributes of the appender as defined in the configuration
929file to the constructor as name/value pairs (in this case just one):
930
931    ColorScreenAppender->new(color => "blue");
932
933The new() method listed above stores the contents of the
934%options hash in the object's
935instance data hash (referred to by $self).
936That's all for initializing a new appender with Log::Log4perl.
937
938Second, ColorScreenAppender needs to expose a
939C<log()> method, which will be called by Log::Log4perl
940every time it thinks the appender should fire. Along with the
941object reference (as usual in Perl's object world), log()
942will receive a list of name/value pairs, of which only the one
943under the key C<message> shall be of interest for now since it is the
944message string to be logged. At this point, Log::Log4perl has already taken
945care of joining the message to be a single string.
946
947For our special appender ColorScreenAppender, we're using the
948Term::ANSIColor module to colorize the output:
949
950    use Term::ANSIColor;
951
952    sub log {
953        my($self, %params) = @_;
954
955        print colored($params{message},
956                      $self->{color});
957    }
958
959The color (as configured in the Log::Log4perl configuration file)
960is available as $self-E<gt>{color} in the appender object. Don't
961forget to return
962
963    1;
964
965at the end of ColorScreenAppender.pm and you're done. Install the new appender
966somewhere where perl can find it and try it with a test script like
967
968    use Log::Log4perl qw(:easy);
969    Log::Log4perl->init("test.conf");
970    ERROR("blah");
971
972to see the new colored output. Is this cool or what?
973
974And it gets even better: You can write dynamically generated appender
975classes using the C<Class::Prototyped> module. Here's an example of
976an appender prepending every outgoing message with a configurable
977number of bullets:
978
979    use Class::Prototyped;
980
981    my $class = Class::Prototyped->newPackage(
982      "MyAppenders::Bulletizer",
983      bullets => 1,
984      log     => sub {
985        my($self, %params) = @_;
986        print "*" x $self->bullets(),
987              $params{message};
988      },
989    );
990
991    use Log::Log4perl qw(:easy);
992
993    Log::Log4perl->init(\ q{
994      log4perl.logger = INFO, Bully
995
996      log4perl.appender.Bully=MyAppenders::Bulletizer
997      log4perl.appender.Bully.bullets=3
998
999      log4perl.appender.Bully.layout = PatternLayout
1000      log4perl.appender.Bully.layout.ConversionPattern=%m %n
1001    });
1002
1003        # ... prints: "***Boo!\n";
1004    INFO "Boo!";
1005
1006=head2 How can I drill down on references before logging them?
1007
1008If you've got a reference to a nested structure or object, then
1009you probably don't want to log it as C<HASH(0x81141d4)> but rather
1010dump it as something like
1011
1012    $VAR1 = {
1013              'a' => 'b',
1014              'd' => 'e'
1015            };
1016
1017via a module like Data::Dumper. While it's syntactically correct to say
1018
1019    $logger->debug(Data::Dumper::Dumper($ref));
1020
1021this call imposes a huge performance penalty on your application
1022if the message is suppressed by Log::Log4perl, because Data::Dumper
1023will perform its expensive operations in any case, because it doesn't
1024know that its output will be thrown away immediately.
1025
1026As of Log::Log4perl 0.28, there's a better way: Use the
1027message output filter format as in
1028
1029    $logger->debug( {filter => \&Data::Dumper::Dumper,
1030                     value  => $ref} );
1031
1032and Log::Log4perl won't call the filter function unless the message really
1033gets written out to an appender. Just make sure to pass the whole slew as a
1034reference to a hash specifying a filter function (as a sub reference)
1035under the key C<filter> and the value to be passed to the filter function in
1036C<value>).
1037When it comes to logging, Log::Log4perl will call the filter function,
1038pass the C<value> as an argument and log the return value.
1039Saves you serious cycles.
1040
1041=head2 How can I collect all FATAL messages in an extra log file?
1042
1043Suppose you have employed Log4perl all over your system and you've already
1044activated logging in various subsystems. On top of that, without disrupting
1045any other settings, how can you collect all FATAL messages all over the system
1046and send them to a separate log file?
1047
1048If you define a root logger like this:
1049
1050    log4perl.logger                  = FATAL, File
1051    log4perl.appender.File           = Log::Log4perl::Appender::File
1052    log4perl.appender.File.filename  = /tmp/fatal.txt
1053    log4perl.appender.File.layout    = PatternLayout
1054    log4perl.appender.File.layout.ConversionPattern= %d %m %n
1055        # !!! Something's missing ...
1056
1057you'll be surprised to not only receive all FATAL messages
1058issued anywhere in the system,
1059but also everything else -- gazillions of
1060ERROR, WARN, INFO and even DEBUG messages will end up in
1061your fatal.txt logfile!
1062Reason for this is Log4perl's (or better: Log4j's) appender additivity.
1063Once a
1064lower-level logger decides to fire, the message is going to be forwarded
1065to all appenders upstream -- without further priority checks with their
1066attached loggers.
1067
1068There's a way to prevent this, however: If your appender defines a
1069minimum threshold, only messages of this priority or higher are going
1070to be logged. So, just add
1071
1072    log4perl.appender.File.Threshold = FATAL
1073
1074to the configuration above, and you'll get what you wanted in the
1075first place: An overall system FATAL message collector.
1076
1077=head2 How can I bundle several log messages into one?
1078
1079Would you like to tally the messages arriving at your appender and
1080dump out a summary once they're exceeding a certain threshold?
1081So that something like
1082
1083    $logger->error("Blah");
1084    $logger->error("Blah");
1085    $logger->error("Blah");
1086
1087won't be logged as
1088
1089    Blah
1090    Blah
1091    Blah
1092
1093but as
1094
1095    [3] Blah
1096
1097instead? If you'd like to hold off on logging a message until it has been
1098sent a couple of times, you can roll that out by creating a buffered
1099appender.
1100
1101Let's define a new appender like
1102
1103    package TallyAppender;
1104
1105    sub new {
1106        my($class, %options) = @_;
1107
1108        my $self = { maxcount => 5,
1109                     %options
1110                   };
1111
1112        bless $self, $class;
1113
1114        $self->{last_message}        = "";
1115        $self->{last_message_count}  = 0;
1116
1117        return $self;
1118    }
1119
1120with two additional instance variables C<last_message> and
1121C<last_message_count>, storing the content of the last message sent
1122and a counter of how many times this has happened. Also, it features
1123a configuration parameter C<maxcount> which defaults to 5 in the
1124snippet above but can be set in the Log4perl configuration file like this:
1125
1126    log4perl.logger = INFO, A
1127    log4perl.appender.A=TallyAppender
1128    log4perl.appender.A.maxcount = 3
1129
1130The main tallying logic lies in the appender's C<log> method,
1131which is called every time Log4perl thinks a message needs to get logged
1132by our appender:
1133
1134    sub log {
1135        my($self, %params) = @_;
1136
1137            # Message changed? Print buffer.
1138        if($self->{last_message} and
1139           $params{message} ne $self->{last_message}) {
1140            print "[$self->{last_message_count}]: " .
1141                  "$self->{last_message}";
1142            $self->{last_message_count} = 1;
1143            $self->{last_message} = $params{message};
1144            return;
1145        }
1146
1147        $self->{last_message_count}++;
1148        $self->{last_message} = $params{message};
1149
1150            # Threshold exceeded? Print, reset counter
1151        if($self->{last_message_count} >=
1152           $self->{maxcount}) {
1153            print "[$self->{last_message_count}]: " .
1154                  "$params{message}";
1155            $self->{last_message_count} = 0;
1156            $self->{last_message}       = "";
1157            return;
1158        }
1159    }
1160
1161We basically just check if the oncoming message in C<$param{message}>
1162is equal to what we've saved before in the C<last_message> instance
1163variable. If so, we're increasing C<last_message_count>.
1164We print the message in two cases: If the new message is different
1165than the buffered one, because then we need to dump the old stuff
1166and store the new. Or, if the counter exceeds the threshold, as
1167defined by the C<maxcount> configuration parameter.
1168
1169Please note that the appender always gets the fully rendered message and
1170just compares it as a whole -- so if there's a date/timestamp in there,
1171that might confuse your logic. You can work around this by specifying
1172%m %n as a layout and add the date later on in the appender. Or, make
1173the comparison smart enough to omit the date.
1174
1175At last, don't forget what happens if the program is being shut down.
1176If there's still messages in the buffer, they should be printed out
1177at that point. That's easy to do in the appender's DESTROY method,
1178which gets called at object destruction time:
1179
1180    sub DESTROY {
1181        my($self) = @_;
1182
1183        if($self->{last_message_count}) {
1184            print "[$self->{last_message_count}]: " .
1185                  "$self->{last_message}";
1186            return;
1187        }
1188    }
1189
1190This will ensure that none of the buffered messages are lost.
1191Happy buffering!
1192
1193=head2 I want to log ERROR and WARN messages to different files! How can I do that?
1194
1195Let's assume you wanted to have each logging statement written to a
1196different file, based on the statement's priority. Messages with priority
1197C<WARN> are supposed to go to C</tmp/app.warn>, events prioritized
1198as C<ERROR> should end up in C</tmp/app.error>.
1199
1200Now, if you define two appenders C<AppWarn> and C<AppError>
1201and assign them both to the root logger,
1202messages bubbling up from any loggers below will be logged by both
1203appenders because of Log4perl's message propagation feature. If you limit
1204their exposure via the appender threshold mechanism and set
1205C<AppWarn>'s threshold to C<WARN> and C<AppError>'s to C<ERROR>, you'll
1206still get C<ERROR> messages in C<AppWarn>, because C<AppWarn>'s C<WARN>
1207setting will just filter out messages with a I<lower> priority than
1208C<WARN> -- C<ERROR> is higher and will be allowed to pass through.
1209
1210What we need for this is a Log4perl I<Custom Filter>, available with
1211Log::Log4perl 0.30.
1212
1213Both appenders need to verify that
1214the priority of the oncoming messages exactly I<matches> the priority
1215the appender is supposed to log messages of. To accomplish this task,
1216let's define two custom filters, C<MatchError> and C<MatchWarn>, which,
1217when attached to their appenders, will limit messages passed on to them
1218to those matching a given priority:
1219
1220    log4perl.logger = WARN, AppWarn, AppError
1221
1222        # Filter to match level ERROR
1223    log4perl.filter.MatchError = Log::Log4perl::Filter::LevelMatch
1224    log4perl.filter.MatchError.LevelToMatch  = ERROR
1225    log4perl.filter.MatchError.AcceptOnMatch = true
1226
1227        # Filter to match level WARN
1228    log4perl.filter.MatchWarn  = Log::Log4perl::Filter::LevelMatch
1229    log4perl.filter.MatchWarn.LevelToMatch  = WARN
1230    log4perl.filter.MatchWarn.AcceptOnMatch = true
1231
1232        # Error appender
1233    log4perl.appender.AppError = Log::Log4perl::Appender::File
1234    log4perl.appender.AppError.filename = /tmp/app.err
1235    log4perl.appender.AppError.layout   = SimpleLayout
1236    log4perl.appender.AppError.Filter   = MatchError
1237
1238        # Warning appender
1239    log4perl.appender.AppWarn = Log::Log4perl::Appender::File
1240    log4perl.appender.AppWarn.filename = /tmp/app.warn
1241    log4perl.appender.AppWarn.layout   = SimpleLayout
1242    log4perl.appender.AppWarn.Filter   = MatchWarn
1243
1244The appenders C<AppWarn> and C<AppError> defined above are logging to C</tmp/app.warn> and
1245C</tmp/app.err> respectively and have the custom filters C<MatchWarn> and C<MatchError>
1246attached.
1247This setup will direct all WARN messages, issued anywhere in the system, to /tmp/app.warn (and
1248ERROR messages to /tmp/app.error) -- without any overlaps.
1249
1250=head2 On our server farm, Log::Log4perl configuration files differ slightly from host to host. Can I roll them all into one?
1251
1252You sure can, because Log::Log4perl allows you to specify attribute values
1253dynamically. Let's say that one of your appenders expects the host's IP address
1254as one of its attributes. Now, you could certainly roll out different
1255configuration files for every host and specify the value like
1256
1257    log4perl.appender.MyAppender    = Log::Log4perl::Appender::SomeAppender
1258    log4perl.appender.MyAppender.ip = 10.0.0.127
1259
1260but that's a maintenance nightmare. Instead, you can have Log::Log4perl
1261figure out the IP address at configuration time and set the appender's
1262value correctly:
1263
1264        # Set the IP address dynamically
1265    log4perl.appender.MyAppender    = Log::Log4perl::Appender::SomeAppender
1266    log4perl.appender.MyAppender.ip = sub { \
1267       use Sys::Hostname; \
1268       use Socket; \
1269       return inet_ntoa(scalar gethostbyname hostname); \
1270    }
1271
1272If Log::Log4perl detects that an attribute value starts with something like
1273C<"sub {...">, it will interpret it as a perl subroutine which is to be executed
1274once at configuration time (not runtime!) and its return value is
1275to be used as the attribute value. This comes in handy
1276for rolling out applications whichs Log::Log4perl configuration files
1277show small host-specific differences, because you can deploy the unmodified
1278application distribution on all instances of the server farm.
1279
1280=head2 Log4perl doesn't interpret my backslashes correctly!
1281
1282If you're using Log4perl's feature to specify the configuration as a
1283string in your program (as opposed to a separate configuration file),
1284chances are that you've written it like this:
1285
1286    # *** WRONG! ***
1287
1288    Log::Log4perl->init( \ <<END_HERE);
1289        log4perl.logger = WARN, A1
1290        log4perl.appender.A1 = Log::Log4perl::Appender::Screen
1291        log4perl.appender.A1.layout = \
1292            Log::Log4perl::Layout::PatternLayout
1293        log4perl.appender.A1.layout.ConversionPattern = %m%n
1294    END_HERE
1295
1296    # *** WRONG! ***
1297
1298and you're getting the following error message:
1299
1300    Layout not specified for appender A1 at .../Config.pm line 342.
1301
1302What's wrong? The problem is that you're using a here-document with
1303substitution enabled (C<E<lt>E<lt>END_HERE>) and that Perl won't
1304interpret backslashes at line-ends as continuation characters but
1305will essentially throw them out. So, in the code above, the layout line
1306will look like
1307
1308    log4perl.appender.A1.layout =
1309
1310to Log::Log4perl which causes it to report an error. To interpret the backslash
1311at the end of the line correctly as a line-continuation character, use
1312the non-interpreting mode of the here-document like in
1313
1314    # *** RIGHT! ***
1315
1316    Log::Log4perl->init( \ <<'END_HERE');
1317        log4perl.logger = WARN, A1
1318        log4perl.appender.A1 = Log::Log4perl::Appender::Screen
1319        log4perl.appender.A1.layout = \
1320            Log::Log4perl::Layout::PatternLayout
1321        log4perl.appender.A1.layout.ConversionPattern = %m%n
1322    END_HERE
1323
1324    # *** RIGHT! ***
1325
1326(note the single quotes around C<'END_HERE'>) or use C<q{...}>
1327instead of a here-document and Perl will treat the backslashes at
1328line-end as intended.
1329
1330=head2 I want to suppress certain messages based on their content!
1331
1332Let's assume you've plastered all your functions with Log4perl
1333statements like
1334
1335    sub some_func {
1336
1337        INFO("Begin of function");
1338
1339        # ... Stuff happens here ...
1340
1341        INFO("End of function");
1342    }
1343
1344to issue two log messages, one at the beginning and one at the end of
1345each function. Now you want to suppress the message at the beginning
1346and only keep the one at the end, what can you do? You can't use the category
1347mechanism, because both messages are issued from the same package.
1348
1349Log::Log4perl's custom filters (0.30 or better) provide an interface for the
1350Log4perl user to step in right before a message gets logged and decide if
1351it should be written out or suppressed, based on the message content or other
1352parameters:
1353
1354    use Log::Log4perl qw(:easy);
1355
1356    Log::Log4perl::init( \ <<'EOT' );
1357        log4perl.logger             = INFO, A1
1358        log4perl.appender.A1        = Log::Log4perl::Appender::Screen
1359        log4perl.appender.A1.layout = \
1360            Log::Log4perl::Layout::PatternLayout
1361        log4perl.appender.A1.layout.ConversionPattern = %m%n
1362
1363        log4perl.filter.M1 = Log::Log4perl::Filter::StringMatch
1364        log4perl.filter.M1.StringToMatch = Begin
1365        log4perl.filter.M1.AcceptOnMatch = false
1366
1367        log4perl.appender.A1.Filter = M1
1368EOT
1369
1370The last four statements in the configuration above are defining a custom
1371filter C<M1> of type C<Log::Log4perl::Filter::StringMatch>, which comes with
1372Log4perl right out of the box and allows you to define a text pattern to match
1373(as a perl regular expression) and a flag C<AcceptOnMatch> indicating
1374if a match is supposed to suppress the message or let it pass through.
1375
1376The last line then assigns this filter to the C<A1> appender, which will
1377call it every time it receives a message to be logged and throw all
1378messages out I<not> matching the regular expression C<Begin>.
1379
1380Instead of using the standard C<Log::Log4perl::Filter::StringMatch> filter,
1381you can define your own, simply using a perl subroutine:
1382
1383    log4perl.filter.ExcludeBegin  = sub { !/Begin/ }
1384    log4perl.appender.A1.Filter   = ExcludeBegin
1385
1386For details on custom filters, check L<Log::Log4perl::Filter>.
1387
1388=head2 My new module uses Log4perl -- but what happens if the calling program didn't configure it?
1389
1390If a Perl module uses Log::Log4perl, it will typically rely on the
1391calling program to initialize it. If it is using Log::Log4perl in C<:easy>
1392mode, like in
1393
1394    package MyMod;
1395    use Log::Log4perl qw(:easy);
1396
1397    sub foo {
1398        DEBUG("In foo");
1399    }
1400
1401    1;
1402
1403and the calling program doesn't initialize Log::Log4perl at all (e.g. because
1404it has no clue that it's available), Log::Log4perl will silently
1405ignore all logging messages. However, if the module is using Log::Log4perl
1406in regular mode like in
1407
1408    package MyMod;
1409    use Log::Log4perl qw(get_logger);
1410
1411    sub foo {
1412        my $logger = get_logger("");
1413        $logger->debug("blah");
1414    }
1415
1416    1;
1417
1418and the main program is just using the module like in
1419
1420    use MyMode;
1421    MyMode::foo();
1422
1423then Log::Log4perl will also ignore all logging messages but
1424issue a warning like
1425
1426    Log4perl: Seems like no initialization happened.
1427    Forgot to call init()?
1428
1429(only once!) to remind novice users to not forget to initialize
1430the logging system before using it.
1431However, if you want to suppress this message, just
1432add the C<:nowarn> target to the module's C<use Log::Log4perl> call:
1433
1434    use Log::Log4perl qw(get_logger :nowarn);
1435
1436This will have Log::Log4perl silently ignore all logging statements if
1437no initialization has taken place.
1438
1439If the module wants to figure out if some other program part has
1440already initialized Log::Log4perl, it can do so by calling
1441
1442    Log::Log4perl::initialized()
1443
1444which will return a true value in case Log::Log4perl has been initialized
1445and a false value if not.
1446
1447=head2 How can I synchronize access to an appender?
1448
1449If you're using the same instance of an appender in multiple processes,
1450and each process is passing on messages to the appender in parallel,
1451you might end up with overlapping log entries.
1452
1453Typical scenarios include a file appender that you create in the main
1454program, and which will then be shared between the parent and a
1455forked child process. Or two separate processes, each initializing a
1456Log4perl file appender on the same logfile.
1457
1458Log::Log4perl won't synchronize access to the shared logfile by
1459default. Depending on your operating system's flush mechanism,
1460buffer size and the size of your messages, there's a small chance of
1461an overlap.
1462
1463The easiest way to prevent overlapping messages in logfiles written to
1464by multiple processes is setting the
1465file appender's C<syswrite> flag along with a file write mode of C<"append">.
1466This makes sure that
1467C<Log::Log4perl::Appender::File> uses C<syswrite()> (which is guaranteed
1468to run uninterrupted) instead of C<print()> which might buffer
1469the message or get interrupted by the OS while it is writing. And in
1470C<"append"> mode, the OS kernel ensures that multiple processes share
1471one end-of-file marker, ensuring that each process writes to the I<real>
1472end of the file. (The value of C<"append">
1473for the C<mode> parameter is the default setting in Log4perl's file
1474appender so you don't have to set it explicitely.)
1475
1476      # Guarantees atomic writes
1477
1478    log4perl.category.Bar.Twix          = WARN, Logfile
1479
1480    log4perl.appender.Logfile           = Log::Log4perl::Appender::File
1481    log4perl.appender.Logfile.mode      = append
1482    log4perl.appender.Logfile.syswrite  = 1
1483    log4perl.appender.Logfile.filename  = test.log
1484    log4perl.appender.Logfile.layout    = SimpleLayout
1485
1486Another guaranteed way of having messages separated with any kind of
1487appender is putting a Log::Log4perl::Appender::Synchronized composite
1488appender in between Log::Log4perl and the real appender. It will make
1489sure to let messages pass through this virtual gate one by one only.
1490
1491Here's a sample configuration to synchronize access to a file appender:
1492
1493    log4perl.category.Bar.Twix          = WARN, Syncer
1494
1495    log4perl.appender.Logfile           = Log::Log4perl::Appender::File
1496    log4perl.appender.Logfile.autoflush = 1
1497    log4perl.appender.Logfile.filename  = test.log
1498    log4perl.appender.Logfile.layout    = SimpleLayout
1499
1500    log4perl.appender.Syncer            = Log::Log4perl::Appender::Synchronized
1501    log4perl.appender.Syncer.appender   = Logfile
1502
1503C<Log::Log4perl::Appender::Synchronized> uses
1504the C<IPC::Shareable> module and its semaphores, which will slow down writing
1505the log messages, but ensures sequential access featuring atomic checks.
1506Check L<Log::Log4perl::Appender::Synchronized> for details.
1507
1508=head2 Can I use Log::Log4perl with log4j's Chainsaw?
1509
1510Yes, Log::Log4perl can be configured to send its events to log4j's
1511graphical log UI I<Chainsaw>.
1512
1513=for html
1514<p>
1515<TABLE><TR><TD>
1516<A HREF="http://log4perl.sourceforge.net/images/chainsaw2.jpg"><IMG SRC="http://log4perl.sourceforge.net/images/chainsaw2s.jpg"></A>
1517<TR><TD>
1518<I>Figure 1: Chainsaw receives Log::Log4perl events</I>
1519</TABLE>
1520<p>
1521
1522=for text
1523Figure1: Chainsaw receives Log::Log4perl events
1524
1525Here's how it works:
1526
1527=over 4
1528
1529=item *
1530
1531Get Guido Carls' E<lt>gcarls@cpan.orgE<gt> Log::Log4perl extension
1532C<Log::Log4perl::Layout::XMLLayout> from CPAN and install it:
1533
1534    perl -MCPAN -eshell
1535    cpan> install Log::Log4perl::Layout::XMLLayout
1536
1537=item *
1538
1539Install and start Chainsaw, which is part of the C<log4j> distribution now
1540(see http://jakarta.apache.org/log4j ). Create a configuration file like
1541
1542  <log4j:configuration debug="true">
1543    <plugin name="XMLSocketReceiver"
1544            class="org.apache.log4j.net.XMLSocketReceiver">
1545      <param name="decoder" value="org.apache.log4j.xml.XMLDecoder"/>
1546      <param name="Port" value="4445"/>
1547    </plugin>
1548    <root> <level value="debug"/> </root>
1549  </log4j:configuration>
1550
1551and name it e.g. C<config.xml>. Then start Chainsaw like
1552
1553  java -Dlog4j.debug=true -Dlog4j.configuration=config.xml \
1554    -classpath ".:log4j-1.3alpha.jar:log4j-chainsaw-1.3alpha.jar" \
1555    org.apache.log4j.chainsaw.LogUI
1556
1557and watch the GUI coming up.
1558
1559=item *
1560
1561Configure Log::Log4perl to use a socket appender with an XMLLayout, pointing
1562to the host/port where Chainsaw (as configured above) is waiting with its
1563XMLSocketReceiver:
1564
1565  use Log::Log4perl qw(get_logger);
1566  use Log::Log4perl::Layout::XMLLayout;
1567
1568  my $conf = q(
1569    log4perl.category.Bar.Twix          = WARN, Appender
1570    log4perl.appender.Appender          = Log::Log4perl::Appender::Socket
1571    log4perl.appender.Appender.PeerAddr = localhost
1572    log4perl.appender.Appender.PeerPort = 4445
1573    log4perl.appender.Appender.layout   = Log::Log4perl::Layout::XMLLayout
1574  );
1575
1576  Log::Log4perl::init(\$conf);
1577
1578    # Nasty hack to suppress encoding header
1579  my $app = Log::Log4perl::appenders->{"Appender"};
1580  $app->layout()->{enc_set} = 1;
1581
1582  my $logger = get_logger("Bar.Twix");
1583  $logger->error("One");
1584
1585The nasty hack shown in the code snippet above is currently (October 2003)
1586necessary, because Chainsaw expects XML messages to arrive in a format like
1587
1588  <log4j:event logger="Bar.Twix"
1589               timestamp="1066794904310"
1590               level="ERROR"
1591               thread="10567">
1592    <log4j:message><![CDATA[Two]]></log4j:message>
1593    <log4j:NDC><![CDATA[undef]]></log4j:NDC>
1594    <log4j:locationInfo class="main"
1595      method="main"
1596      file="./t"
1597      line="32">
1598    </log4j:locationInfo>
1599  </log4j:event>
1600
1601without a preceding
1602
1603  <?xml version = "1.0" encoding = "iso8859-1"?>
1604
1605which Log::Log4perl::Layout::XMLLayout applies to the first event sent
1606over the socket.
1607
1608=back
1609
1610See figure 1 for a screenshot of Chainsaw in action, receiving events from
1611the Perl script shown above.
1612
1613Many thanks to Chainsaw's
1614Scott Deboy <sdeboy@comotivsystems.com> for his support!
1615
1616=head2 How can I run Log::Log4perl under mod_perl?
1617
1618In persistent environments it's important to play by the rules outlined
1619in section L<Log::Log4perl/"Initialize once and only once">.
1620If you haven't read this yet, please go ahead and read it right now. It's
1621very important.
1622
1623And no matter if you use a startup handler to init() Log::Log4perl or use the
1624init_once() strategy (added in 0.42), either way you're very likely to have
1625unsynchronized writes to logfiles.
1626
1627If Log::Log4perl is configured with a log file appender, and it is
1628initialized via
1629the Apache startup handler, the file handle created initially will be
1630shared among all Apache processes. Similarly, with the init_once()
1631approach: although every process has a separate L4p configuration,
1632processes are gonna share the appender file I<names> instead, effectively
1633opening several different file handles on the same file.
1634
1635Now, having several appenders using the same file handle or having
1636several appenders logging to the same file unsynchronized, this might
1637result in overlapping messages. Sometimes, this is acceptable. If it's
1638not, here's two strategies:
1639
1640=over 4
1641
1642=item *
1643
1644Use the L<Log::Log4perl::Appender::Synchronized> appender to connect to
1645your file appenders. Here's the writeup:
1646http://log4perl.sourceforge.net/releases/Log-Log4perl/docs/html/Log/Log4perl/FAQ.html#23804
1647
1648=item *
1649
1650Use a different logfile for every process like in
1651
1652     #log4perl.conf
1653     ...
1654     log4perl.appender.A1.filename = sub { "mylog.$$.log" }
1655
1656=back
1657
1658=head2 My program already uses warn() and die(). How can I switch to Log4perl?
1659
1660If your program already uses Perl's C<warn()> function to spew out
1661error messages and you'd like to channel those into the Log4perl world,
1662just define a C<__WARN__> handler where your program or module resides:
1663
1664    use Log::Log4perl qw(:easy);
1665
1666    $SIG{__WARN__} = sub {
1667        local $Log::Log4perl::caller_depth =
1668            $Log::Log4perl::caller_depth + 1;
1669        WARN @_;
1670    };
1671
1672Why the C<local> setting of C<$Log::Log4perl::caller_depth>?
1673If you leave that out,
1674C<PatternLayout> conversion specifiers like C<%M> or C<%F> (printing
1675the current function/method and source filename) will refer
1676to where the __WARN__ handler resides, not the environment
1677Perl's C<warn()> function was issued from. Increasing C<caller_depth>
1678adjusts for this offset. Having it C<local>, makes sure the level
1679gets set back after the handler exits.
1680
1681Once done, if your program does something like
1682
1683    sub some_func {
1684        warn "Here's a warning";
1685    }
1686
1687you'll get (depending on your Log::Log4perl configuration) something like
1688
1689    2004/02/19 20:41:02-main::some_func: Here's a warning at ./t line 25.
1690
1691in the appropriate appender instead of having a screen full of STDERR
1692messages. It also works with the C<Carp> module and its C<carp()>
1693and C<cluck()> functions.
1694
1695If, on the other hand, catching C<die()> and friends is
1696required, a C<__DIE__> handler is appropriate:
1697
1698    $SIG{__DIE__} = sub {
1699        if($^S) {
1700            # We're in an eval {} and don't want log
1701            # this message but catch it later
1702            return;
1703        }
1704        $Log::Log4perl::caller_depth++;
1705        LOGDIE @_;
1706    };
1707
1708This will call Log4perl's C<LOGDIE()> function, which will log a fatal
1709error and then call die() internally, causing the program to exit. Works
1710equally well with C<Carp>'s C<croak()> and C<confess()> functions.
1711
1712=head2 Some module prints messages to STDERR. How can I funnel them to Log::Log4perl?
1713
1714If a module you're using doesn't use Log::Log4perl but prints logging
1715messages to STDERR instead, like
1716
1717    ########################################
1718    package IgnorantModule;
1719    ########################################
1720
1721    sub some_method {
1722        print STDERR "Parbleu! An error!\n";
1723    }
1724
1725    1;
1726
1727there's still a way to capture these messages and funnel them
1728into Log::Log4perl, even without touching the module. What you need is
1729a trapper module like
1730
1731    ########################################
1732    package Trapper;
1733    ########################################
1734
1735    use Log::Log4perl qw(:easy);
1736
1737    sub TIEHANDLE {
1738        my $class = shift;
1739        bless [], $class;
1740    }
1741
1742    sub PRINT {
1743        my $self = shift;
1744        $Log::Log4perl::caller_depth++;
1745        DEBUG @_;
1746        $Log::Log4perl::caller_depth--;
1747    }
1748
1749and a C<tie> command in the main program to tie STDERR to the trapper
1750module along with regular Log::Log4perl initialization:
1751
1752    ########################################
1753    package main;
1754    ########################################
1755
1756    use Log::Log4perl qw(:easy);
1757
1758    Log::Log4perl->easy_init(
1759        {level  => $DEBUG,
1760         file   => 'stdout',   # make sure not to use stderr here!
1761         layout => "%d %M: %m%n",
1762        });
1763
1764    tie *STDERR, Trapper;
1765
1766Make sure not to use STDERR as Log::Log4perl's file appender
1767here (which would be the default in C<:easy> mode), because it would
1768end up in an endless recursion.
1769
1770Now, calling
1771
1772    IgnorantModule::some_method();
1773
1774will result in the desired output
1775
1776    2004/05/06 11:13:04 IgnorantModule::some_method: Parbleu! An error!
1777
1778=head2 How come PAR (Perl Archive Toolkit) creates executables which then can't find their Log::Log4perl appenders?
1779
1780If not instructed otherwise, C<Log::Log4perl> dynamically pulls in
1781appender classes found in its configuration. If you specify
1782
1783    #!/usr/bin/perl
1784    # mytest.pl
1785
1786    use Log::Log4perl qw(get_logger);
1787
1788    my $conf = q(
1789      log4perl.category.Bar.Twix = WARN, Logfile
1790      log4perl.appender.Logfile  = Log::Log4perl::Appender::Screen
1791      log4perl.appender.Logfile.layout = SimpleLayout
1792    );
1793
1794    Log::Log4perl::init(\$conf);
1795    my $logger = get_logger("Bar::Twix");
1796    $logger->error("Blah");
1797
1798then C<Log::Log4perl::Appender::Screen> will be pulled in while the program
1799runs, not at compile time. If you have PAR compile the script above to an
1800executable binary via
1801
1802    pp -o mytest mytest.pl
1803
1804and then run C<mytest> on a machine without having Log::Log4perl installed,
1805you'll get an error message like
1806
1807    ERROR: can't load appenderclass 'Log::Log4perl::Appender::Screen'
1808    Can't locate Log/Log4perl/Appender/Screen.pm in @INC ...
1809
1810Why? At compile time, C<pp> didn't realize that
1811C<Log::Log4perl::Appender::Screen> would be needed later on and didn't
1812wrap it into the executable created. To avoid this, either say
1813C<use Log::Log4perl::Appender::Screen> in the script explicitely or
1814compile it with
1815
1816    pp -o mytest -M Log::Log4perl::Appender::Screen mytest.pl
1817
1818to make sure the appender class gets included.
1819
1820=head2 How can I access a custom appender defined in the configuration?
1821
1822Any appender defined in the configuration file or somewhere in the code
1823can be accessed later via
1824C<Log::Log4perl-E<gt>appender_by_name("appender_name")>,
1825which returns a reference the the appender object.
1826
1827Once you've got a hold of the object, it can be queried or modified to
1828your liking. For example, see the custom C<IndentAppender> defined below:
1829After calling C<init()> to define the Log4perl settings, the
1830appender object is retrieved to call its C<indent_more()> and C<indent_less()>
1831methods to control indentation of messages:
1832
1833    package IndentAppender;
1834
1835    sub new {
1836        bless { indent => 0 }, $_[0];
1837    }
1838
1839    sub indent_more  { $_[0]->{indent}++ }
1840    sub indent_less  { $_[0]->{indent}-- }
1841
1842    sub log {
1843        my($self, %params) = @_;
1844        print " " x $self->{indent}, $params{message};
1845    }
1846
1847    package main;
1848
1849    use Log::Log4perl qw(:easy);
1850
1851    my $conf = q(
1852    log4perl.category          = DEBUG, Indented
1853    log4perl.appender.Indented = IndentAppender
1854    log4perl.appender.Indented.layout = Log::Log4perl::Layout::SimpleLayout
1855    );
1856
1857    Log::Log4perl::init(\$conf);
1858
1859    my $appender = Log::Log4perl->appender_by_name("Indented");
1860
1861    DEBUG "No identation";
1862    $appender->indent_more();
1863    DEBUG "One more";
1864    $appender->indent_more();
1865    DEBUG "Two more";
1866    $appender->indent_less();
1867    DEBUG "One less";
1868
1869As you would expect, this will print
1870
1871    DEBUG - No identation
1872     DEBUG - One more
1873      DEBUG - Two more
1874     DEBUG - One less
1875
1876because the very appender used by Log4perl is modified dynamically at
1877runtime.
1878
1879=head2 I don't know if Log::Log4perl is installed. How can I prepare my script?
1880
1881In case your script needs to be prepared for environments that may or may
1882not have Log::Log4perl installed, there's a trick.
1883
1884If you put the following BEGIN blocks at the top of the program,
1885you'll be able to use the DEBUG(), INFO(), etc. macros in
1886Log::Log4perl's C<:easy> mode.
1887If Log::Log4perl
1888is installed in the target environment, the regular Log::Log4perl rules
1889apply. If not, all of DEBUG(), INFO(), etc. are "stubbed" out, i.e. they
1890turn into no-ops:
1891
1892    use warnings;
1893    use strict;
1894
1895    BEGIN {
1896        eval { require Log::Log4perl; };
1897
1898        if($@) {
1899            print "Log::Log4perl not installed - stubbing.\n";
1900            no strict qw(refs);
1901            *{"main::$_"} = sub { } for qw(DEBUG INFO WARN ERROR FATAL);
1902        } else {
1903            no warnings;
1904            print "Log::Log4perl installed - life is good.\n";
1905            require Log::Log4perl::Level;
1906            Log::Log4perl::Level->import(__PACKAGE__);
1907            Log::Log4perl->import(qw(:easy));
1908            Log::Log4perl->easy_init($main::DEBUG);
1909        }
1910    }
1911
1912        # The regular script begins ...
1913    DEBUG "Hey now!";
1914
1915This snippet will first probe for Log::Log4perl, and if it can't be found,
1916it will alias DEBUG(), INFO(), with empty subroutines via typeglobs.
1917If Log::Log4perl is available, its level constants are first imported
1918(C<$DEBUG>, C<$INFO>, etc.) and then C<easy_init()> gets called to initialize
1919the logging system.
1920
1921=head2 Can file appenders create files with different permissions?
1922
1923Typically, when C<Log::Log4perl::Appender::File> creates a new file,
1924its permissions are set to C<rw-r--r-->. Why? Because your
1925environment's I<umask> most likely defaults to
1926C<0022>, that's the standard setting.
1927
1928What's a I<umask>, you're asking? It's a template that's applied to
1929the permissions of all newly created files. While calls like
1930C<open(FILE, "E<gt>foo")> will always try to create files in C<rw-rw-rw-
1931> mode, the system will apply the current I<umask> template to
1932determine the final permission setting. I<umask> is a bit mask that's
1933inverted and then applied to the requested permission setting, using a
1934bitwise AND:
1935
1936    $request_permission &~ $umask
1937
1938So, a I<umask> setting of 0000 (the leading 0 simply indicates an
1939octal value) will create files in C<rw-rw-rw-> mode, a setting of 0277
1940will use C<r-------->, and the standard 0022 will use C<rw-r--r-->.
1941
1942As an example, if you want your log files to be created with
1943C<rw-r--rw-> permissions, use a I<umask> of C<0020> before
1944calling Log::Log4perl->init():
1945
1946    use Log::Log4perl;
1947
1948    umask 0020;
1949        # Creates log.out in rw-r--rw mode
1950    Log::Log4perl->init(\ q{
1951        log4perl.logger = WARN, File
1952        log4perl.appender.File = Log::Log4perl::Appender::File
1953        log4perl.appender.File.filename = log.out
1954        log4perl.appender.File.layout = SimpleLayout
1955    });
1956
1957=head2 Using Log4perl in an END block causes a problem!
1958
1959It's not easy to get to this error, but if you write something like
1960
1961    END { Log::Log4perl::get_logger()->debug("Hey there."); }
1962
1963    use Log::Log4perl qw(:easy);
1964    Log::Log4perl->easy_init($DEBUG);
1965
1966it won't work. The reason is that C<Log::Log4perl> defines an
1967END block that cleans up all loggers. And perl will run END blocks
1968in the reverse order as they're encountered in the compile phase,
1969so in the scenario above, the END block will run I<after> Log4perl
1970has cleaned up its loggers.
1971
1972Placing END blocks using Log4perl I<after>
1973a C<use Log::Log4perl> statement fixes the problem:
1974
1975    use Log::Log4perl qw(:easy);
1976    Log::Log4perl->easy_init($DEBUG);
1977
1978    END { Log::Log4perl::get_logger()->debug("Hey there."); }
1979
1980In this scenario, the shown END block is executed I<before> Log4perl
1981cleans up and the debug message will be processed properly.
1982
1983=head2 Help! My appender is throwing a "Wide character in print" warning!
1984
1985This warning shows up when Unicode strings are printed without
1986precautions. The warning goes away if the complaining appender is
1987set to utf-8 mode:
1988
1989      # Either in the log4perl configuration file:
1990  log4perl.appender.Logfile.filename = test.log
1991  log4perl.appender.Logfile.utf8     = 1
1992
1993      # Or, in easy mode:
1994  Log::Log4perl->easy_init( {
1995    level => $DEBUG,
1996    file  => ":utf8> test.log"
1997  } );
1998
1999If the complaining appender is a screen appender, C<binmode> does the trick:
2000
2001      # Either STDOUT ...
2002    binmode(STDOUT, ":utf8);
2003
2004      # ... or STDERR.
2005    binmode(STDERR, ":utf8);
2006
2007Some background on this: Perl's strings are either byte strings or
2008Unicode strings. C<"Mike"> is a byte string.
2009C<"\x{30DE}\x{30A4}\x{30AF}"> is a Unicode string. Unicode strings are
2010marked specially and are UTF-8 encoded internally.
2011
2012If you print a byte string to STDOUT,
2013all is well, because STDOUT is by default set to byte mode. However,
2014if you print a Unicode string to STDOUT without precautions, C<perl>
2015will try to transform the Unicode string back to a byte string before
2016printing it out. This is troublesome if the Unicode string contains
2017'wide' characters which can't be represented in Latin-1.
2018
2019For example, if you create a Unicode string with three japanese Katakana
2020characters as in
2021
2022    perl -le 'print "\x{30DE}\x{30A4}\x{30AF}"'
2023
2024(coincidentally pronounced Ma-i-ku, the japanese pronounciation of
2025"Mike"), STDOUT is in byte mode and the warning
2026
2027    Wide character in print at ./script.pl line 14.
2028
2029appears. Setting STDOUT to UTF-8 mode as in
2030
2031    perl -le 'binmode(STDOUT, ":utf8"); print "\x{30DE}\x{30A4}\x{30AF}"'
2032
2033will silently print the Unicode string to STDOUT in UTF-8. To see the
2034characters printed, you'll need a UTF-8 terminal with a font including
2035japanese Katakana characters.
2036
2037=head2 How can I send errors to the screen, and debug messages to a file?
2038
2039Let's assume you want to maintain a detailed DEBUG output in a file
2040and only messages of level ERROR and higher should be printed on the
2041screen. Often times, developers come up with something like this:
2042
2043     # Wrong!!!
2044    log4perl.logger = DEBUG, FileApp
2045    log4perl.logger = ERROR, ScreenApp
2046     # Wrong!!!
2047
2048This won't work, however. Logger definitions aren't additive, and the
2049second statement will overwrite the first one. Log4perl versions
2050below 1.04 were silently accepting this, leaving people confused why
2051it wouldn't work as expected.
2052As of 1.04, this will throw a I<fatal error> to notify the user of
2053the problem.
2054
2055What you want to do instead, is this:
2056
2057    log4perl.logger                    = DEBUG, FileApp, ScreenApp
2058
2059    log4perl.appender.FileApp          = Log::Log4perl::Appender::File
2060    log4perl.appender.FileApp.filename = test.log
2061    log4perl.appender.FileApp.layout   = SimpleLayout
2062
2063    log4perl.appender.ScreenApp          = Log::Log4perl::Appender::Screen
2064    log4perl.appender.ScreenApp.stderr   = 0
2065    log4perl.appender.ScreenApp.layout   = SimpleLayout
2066       ### limiting output to ERROR messages
2067    log4perl.appender.ScreenApp.Threshold = ERROR
2068       ###
2069
2070Note that without the second appender's C<Threshold> setting, both appenders
2071would receive all messages prioritized DEBUG and higher. With the
2072threshold set to ERROR, the second appender will filter the messages
2073as required.
2074
2075=head2 Where should I put my logfiles?
2076
2077Your log files may go anywhere you want them, but the effective
2078user id of the calling process must have write access.
2079
2080If the log file doesn't exist at program start, Log4perl's file appender
2081will create it. For this, it needs write access to the directory where
2082the new file will be located in. If the log file already exists at startup,
2083the process simply needs write access to the file. Note that it will
2084need write access to the file's directory if you're encountering situations
2085where the logfile gets recreated, e.g. during log rotation.
2086
2087If Log::Log4perl is used by a web server application (e.g. in a CGI script
2088or mod_perl), then the webserver's user (usually C<nobody> or C<www>)
2089must have the permissions mentioned above.
2090
2091To prepare your web server to use log4perl, we'd recommend:
2092
2093    webserver:~$ su -
2094    webserver:~# mkdir /var/log/cgiapps
2095    webserver:~# chown nobody:root /var/log/cgiapps/
2096    webserver:~# chown nobody:root -R /var/log/cgiapps/
2097    webserver:~# chmod 02755 -R /var/log/cgiapps/
2098
2099Then set your /etc/log4perl.conf file to include:
2100
2101    log4perl.appender.FileAppndr1.filename =
2102        /var/log/cgiapps/<app-name>.log
2103
2104=head2 How can my file appender deal with disappearing log files?
2105
2106The file appender that comes with Log4perl, L<Log::Log4perl::Appender::File>,
2107will open a specified log file at initialization time and will
2108keep writing to it via a file handle.
2109
2110In case the associated file goes way, messages written by a
2111long-running process will still be written
2112to the file handle. In case the file has been moved to a different
2113location on the same file system, the writer will keep writing to
2114it under the new filename. In case the file has been removed from
2115the file system, the log messages will end up in nowhere land. This
2116is not a bug in Log4perl, this is how Unix works. There is
2117no error message in this case, because the writer has no idea that
2118the file handle is not associated with a visible file.
2119
2120To prevent the loss of log messages when log files disappear, the
2121file appender's C<recreate> option needs to be set to a true value:
2122
2123    log4perl.appender.Logfile.recreate = 1
2124
2125This will instruct the file appender to check in regular intervals
2126(default: 30 seconds) if the log file is still there. If it finds
2127out that the file is missing, it will recreate it.
2128
2129Continuously checking if the log file still exists is fairly
2130expensive. For this reason it is only performed every 30 seconds. To
2131change this interval, the option C<recreate_check_interval> can be set
2132to the number of seconds between checks. In the extreme case where the
2133check should be performed before every write, it can even be set to 0:
2134
2135    log4perl.appender.Logfile.recreate = 1
2136    log4perl.appender.Logfile.recreate_check_interval = 0
2137
2138To avoid having to check the file system so frequently, a signal
2139handler can be set up:
2140
2141    log4perl.appender.Logfile.recreate = 1
2142    log4perl.appender.Logfile.recreate_check_signal = USR1
2143
2144This will install a signal handler which will recreate a missing log file
2145immediatly when it receives the defined signal.
2146
2147Note that the init_and_watch() method for Log4perl's initialization
2148can also be instructed to install a signal handler, usually using the
2149HUP signal. Make sure to use a different signal if you're using both
2150of them at the same time.
2151
2152=head2 How can I rotate a logfile with newsyslog?
2153
2154Here's a few things that need to be taken care of when using the popular
2155log file rotating utilty C<newsyslog>
2156(http://www.courtesan.com/newsyslog) with Log4perl's file appender
2157in long-running processes.
2158
2159For example, with a newsyslog configuration like
2160
2161    # newsyslog.conf
2162    /tmp/test.log 666  12  5  *  B
2163
2164and a call to
2165
2166    # newsyslog -f /path/to/newsyslog.conf
2167
2168C<newsyslog> will take action if C</tmp/test.log> is larger than the
2169specified 5K in size. It will move the current log file C</tmp/test.log> to
2170C</tmp/test.log.0> and create a new and empty C</tmp/test.log> with
2171the specified permissions (this is why C<newsyslog> needs to run as root).
2172An already existing C</tmp/test.log.0> would be moved to
2173C</tmp/test.log.1>, C</tmp/test.log.1> to C</tmp/test.log.2>, and so
2174forth, for every one of a max number of 12 archived logfiles that have
2175been configured in C<newsyslog.conf>.
2176
2177Although a new file has been created, from Log4perl's appender's point
2178of view, this situation is identical to the one described in the
2179previous FAQ entry, labeled C<How can my file appender deal with
2180disappearing log files>.
2181
2182To make sure that log messages are written to the new log file and not
2183to an archived one or end up in nowhere land,
2184the appender's C<recreate> and C<recreate_check_interval> have to be
2185configured to deal with the 'disappearing' log file.
2186
2187The situation gets interesting when C<newsyslog>'s option
2188to compress archived log files is enabled. This causes the
2189original log file not to be moved, but to disappear. If the
2190file appender isn't configured to recreate the logfile in this situation,
2191log messages will actually be lost without warning. This also
2192applies for the short time frame of C<recreate_check_interval> seconds
2193in between the recreator's file checks.
2194
2195To make sure that no messages get lost, one option is to set the
2196interval to
2197
2198    log4perl.appender.Logfile.recreate_check_interval = 0
2199
2200However, this is fairly expensive. A better approach is to define
2201a signal handler:
2202
2203    log4perl.appender.Logfile.recreate = 1
2204    log4perl.appender.Logfile.recreate_check_signal  = USR1
2205    log4perl.appender.Logfile.recreate_pid_write = /tmp/myappid
2206
2207As a service for C<newsyslog> users, Log4perl's file appender writes
2208the current process ID to a PID file specified by the C<recreate_pid_write>
2209option.  C<newsyslog> then needs to be configured as in
2210
2211    # newsyslog.conf configuration for compressing archive files and
2212    # sending a signal to the Log4perl-enabled application
2213    /tmp/test.log 666  12  5  *  B /tmp/myappid 30
2214
2215to send the defined signal (30, which is USR1 on FreeBSD) to the
2216application process at rotation time. Note that the signal number
2217is different on Linux, where USR1 denotes as 10. Check C<man signal>
2218for details.
2219
2220=head2 How can a process under user id A log to a file under user id B?
2221
2222This scenario often occurs in configurations where processes run under
2223various user IDs but need to write to a log file under a fixed, but
2224different user id.
2225
2226With a traditional file appender, the log file will probably be created
2227under one user's id and appended to under a different user's id. With
2228a typical umask of 0002, the file will be created with -rw-rw-r--
2229permissions. If a user who's not in the first user's group
2230subsequently appends to the log file, it will fail because of a
2231permission problem.
2232
2233Two potential solutions come to mind:
2234
2235=over 4
2236
2237=item *
2238
2239Creating the file with a umask of 0000 will allow all users to append
2240to the log file. Log4perl's file appender C<Log::Log4perl::Appender::File>
2241has an C<umask> option that can be set to support this:
2242
2243    log4perl.appender.File = Log::Log4perl::Appender::File
2244    log4perl.appender.File.umask = sub { 0000 };
2245
2246This way, the log file will be created with -rw-rw-rw- permissions and
2247therefore has world write permissions. This might open up the logfile
2248for unwanted manipulations by arbitrary users, though.
2249
2250=item *
2251
2252Running the process under an effective user id of C<root> will allow
2253it to write to the log file, no matter who started the process.
2254However, this is not a good idea, because of security concerns.
2255
2256=back
2257
2258Luckily, under Unix, there's the syslog daemon which runs as root and
2259takes log requests from user processes over a socket and writes them
2260to log files as configured in C</etc/syslog.conf>.
2261
2262By modifying C</etc/syslog.conf> and HUPing the syslog daemon, you can
2263configure new log files:
2264
2265    # /etc/syslog.conf
2266    ...
2267    user.* /some/path/file.log
2268
2269Using the C<Log::Dispatch::Syslog> appender, which comes with the
2270C<Log::Log4perl> distribution, you can then send messages via syslog:
2271
2272    use Log::Log4perl qw(:easy);
2273
2274    Log::Log4perl->init(\<<EOT);
2275        log4perl.logger = DEBUG, app
2276        log4perl.appender.app=Log::Dispatch::Syslog
2277        log4perl.appender.app.Facility=user
2278        log4perl.appender.app.layout=SimpleLayout
2279    EOT
2280
2281        # Writes to /some/path/file.log
2282    ERROR "Message!";
2283
2284This way, the syslog daemon will solve the permission problem.
2285
2286Note that while it is possible to use syslog() without Log4perl (syslog
2287supports log levels, too), traditional syslog setups have a
2288significant drawback.
2289
2290Without Log4perl's ability to activate logging in only specific
2291parts of a system, complex systems will trigger log events all over
2292the place and slow down execution to a crawl at high debug levels.
2293
2294Remote-controlling logging in the hierarchical parts of an application
2295via Log4perl's categories is one of its most distinguished features.
2296It allows for enabling high debug levels in specified areas without
2297noticable performance impact.
2298
2299=head2 I want to use UTC instead of the local time!
2300
2301If a layout defines a date, Log::Log4perl uses local time to populate it.
2302If you want UTC instead, set
2303
2304    $Log::Log4perl::DateFormat::GMTIME = 1;
2305
2306in your program before the first log statement.
2307
2308=head2 Can Log4perl intercept messages written to a filehandle?
2309
2310You have a function that prints to a filehandle. You want to tie
2311into that filehandle and forward all arriving messages to a
2312Log4perl logger.
2313
2314First, let's write a package that ties a file handle and forwards it
2315to a Log4perl logger:
2316
2317    package FileHandleLogger;
2318    use Log::Log4perl qw(:levels get_logger);
2319
2320    sub TIEHANDLE {
2321       my($class, %options) = @_;
2322
2323       my $self = {
2324           level    => $DEBUG,
2325           category => '',
2326           %options
2327       };
2328
2329       $self->{logger} = get_logger($self->{category}),
2330       bless $self, $class;
2331    }
2332
2333    sub PRINT {
2334        my($self, @rest) = @_;
2335        $Log::Log4perl::caller_depth++;
2336        $self->{logger}->log($self->{level}, @rest);
2337        $Log::Log4perl::caller_depth--;
2338    }
2339
2340    sub PRINTF {
2341        my($self, $fmt, @rest) = @_;
2342        $Log::Log4perl::caller_depth++;
2343        $self->PRINT(sprintf($fmt, @rest));
2344        $Log::Log4perl::caller_depth--;
2345    }
2346
2347    1;
2348
2349Now, if you have a function like
2350
2351    sub function_printing_to_fh {
2352        my($fh) = @_;
2353        printf $fh "Hi there!\n";
2354    }
2355
2356which takes a filehandle and prints something to it, it can be used
2357with Log4perl:
2358
2359    use Log::Log4perl qw(:easy);
2360    usa FileHandleLogger;
2361
2362    Log::Log4perl->easy_init($DEBUG);
2363
2364    tie *SOMEHANDLE, 'FileHandleLogger' or
2365        die "tie failed ($!)";
2366
2367    function_printing_to_fh(*SOMEHANDLE);
2368        # prints "2007/03/22 21:43:30 Hi there!"
2369
2370If you want, you can even specify a different log level or category:
2371
2372    tie *SOMEHANDLE, 'FileHandleLogger',
2373        level => $INFO, category => "Foo::Bar" or die "tie failed ($!)";
2374
2375=head2 I want multiline messages rendered line-by-line!
2376
2377With the standard C<PatternLayout>, if you send a multiline message to
2378an appender as in
2379
2380    use Log::Log4perl qw(:easy);
2381    Log
2382
2383it gets rendered this way:
2384
2385    2007/04/04 23:23:39 multi
2386    line
2387    message
2388
2389If you want each line to be rendered separately according to
2390the layout use C<Log::Log4perl::Layout::PatternLayout::Multiline>:
2391
2392    use Log::Log4perl qw(:easy);
2393
2394    Log::Log4perl->init(\<<EOT);
2395      log4perl.category         = DEBUG, Screen
2396      log4perl.appender.Screen = Log::Log4perl::Appender::Screen
2397      log4perl.appender.Screen.layout = \\
2398        Log::Log4perl::Layout::PatternLayout::Multiline
2399      log4perl.appender.Screen.layout.ConversionPattern = %d %m %n
2400    EOT
2401
2402    DEBUG "some\nmultiline\nmessage";
2403
2404and you'll get
2405
2406    2007/04/04 23:23:39 some
2407    2007/04/04 23:23:39 multiline
2408    2007/04/04 23:23:39 message
2409
2410instead.
2411
2412=head2 I'm on Windows and I'm getting all these 'redefined' messages!
2413
2414If you're on Windows and are getting warning messages like
2415
2416  Constant subroutine Log::Log4perl::_INTERNAL_DEBUG redefined at
2417    C:/Programme/Perl/lib/constant.pm line 103.
2418  Subroutine import redefined at
2419    C:/Programme/Perl/site/lib/Log/Log4Perl.pm line 69.
2420  Subroutine initialized redefined at
2421    C:/Programme/Perl/site/lib/Log/Log4Perl.pm line 207.
2422
2423then chances are that you're using 'Log::Log4Perl' (wrong uppercase P)
2424instead of the correct 'Log::Log4perl'. Perl on Windows doesn't
2425handle this error well and spits out a slew of confusing warning
2426messages. But now you know, just use the correct module name and
2427you'll be fine.
2428
2429=cut
2430
2431=head1 SEE ALSO
2432
2433Log::Log4perl
2434
2435=head1 AUTHOR
2436
2437Mike Schilli, E<lt>log4perl@perlmeister.comE<gt>
2438
2439=cut
2440