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