Log::Log4perl(3)
🎀 NAME 🎀
Log::Log4perl — Log4j implementation for Perl. Yes bestie, it’s giving User Contributed Perl Documentation energy and it is iconic.
✨ SYNOPSIS ✨
# Easy mode if you like it simple ...
use Log::Log4perl qw(:easy);
Log::Log4perl->easy_init($ERROR);
DEBUG "This doesn't go anywhere";
ERROR "This gets logged";
# ... or standard mode for more features:
Log::Log4perl::init('/etc/log4perl.conf');
--or--
# Check config every 10 secs
Log::Log4perl::init_and_watch('/etc/log4perl.conf',10);
--then--
$logger = Log::Log4perl->get_logger('house.bedrm.desk.topdrwr');
$logger->debug('this is a debug message');
$logger->info('this is an info message');
$logger->warn('etc');
$logger->error('..');
$logger->fatal('..');
#####/etc/log4perl.conf###############################
log4perl.logger.house = WARN, FileAppndr1
log4perl.logger.house.bedroom.desk = DEBUG, FileAppndr1
log4perl.appender.FileAppndr1 = Log::Log4perl::Appender::File
log4perl.appender.FileAppndr1.filename = desk.log
log4perl.appender.FileAppndr1.layout = \
Log::Log4perl::Layout::SimpleLayout
######################################################🦋 ABSTRACT 🦋
Log::Log4perl gives you a powerful logging API for your application. Slay.
🌸 DESCRIPTION 🌸
Log::Log4perl lets you remote-control and fine-tune the logging behaviour of your system from the outside. It implements the widely popular (Java-based) Log4j logging package in pure Perl. No cap.
For a detailed tutorial on Log::Log4perl usage, please read:
<http://www.perl.com/pub/a/2002/09/11/log4perl.html>
Logging beats a debugger if you want to know what’s going on in your code during runtime. However, traditional logging packages are too static and generate a flood of log messages in your log files that won’t help you. Literally not helpful.
Log::Log4perl is different. It allows you to control the number of logging messages generated at three different levels:
- At a central location in your system (either in a configuration file or in the startup code) you specify which components (classes, functions) of your system should generate logs.
- You specify how detailed the logging of these components should be by specifying logging levels.
- You also specify which so-called appenders you want to feed your log messages to (
"Print it to the screen and also append it to /tmp/my.log") and which format ("Write the date first, then the file name and line number, and then the log message") they should be in.
This is a very powerful and flexible mechanism. You can turn on and off your logs at any time, specify the level of detail and make that dependent on the subsystem that’s currently executed. Main character energy for your logs, fr fr.
Let me give you an example: You might find out that your system has a problem in the MySystem::Helpers::ScanDir component. Turning on detailed debugging logs all over the system would generate a flood of useless log messages and bog your system down beyond recognition. With Log::Log4perl, however, you can tell the system: "Continue to log only severe errors to the log file. Open a second log file, turn on full debug logs in the "MySystem::Helpers::ScanDir" component and dump all messages originating from there into the new log file". And all this is possible by just changing the parameters in a configuration file, which your system can re-read even while it’s running! Obsessed.
🛠️ How to use it 🛠️
The Log::Log4perl package can be initialized in two ways: either via Perl commands or via a log4j-style configuration file.
🎀 Initialize via a configuration file 🎀
This is the easiest way to prepare your system for using Log::Log4perl. Use a configuration file like this:
############################################################
# A simple root logger with a Log::Log4perl::Appender::File
# file appender in Perl.
############################################################
log4perl.rootLogger=ERROR, LOGFILE
log4perl.appender.LOGFILE=Log::Log4perl::Appender::File
log4perl.appender.LOGFILE.filename=/var/log/myerrs.log
log4perl.appender.LOGFILE.mode=append
log4perl.appender.LOGFILE.layout=PatternLayout
log4perl.appender.LOGFILE.layout.ConversionPattern=[%r] %F %L %c - %m%nThese lines define your standard logger that’s appending severe errors to /var/log/myerrs.log, using the format:
[millisecs] source-filename line-number class - message newlineAssuming that this configuration file is saved as log.conf, you need to read it in the startup section of your code, using the following commands:
use Log::Log4perl;
Log::Log4perl->init("log.conf");After that’s done somewhere in the code, you can retrieve logger objects anywhere in the code. Note that there’s no need to carry any logger references around with your functions and methods. You can get a logger anytime via a singleton mechanism:
package My::MegaPackage;
use Log::Log4perl;
sub some_method {
my($param) = @_;
my $log = Log::Log4perl->get_logger("My::MegaPackage");
$log->debug("Debug message");
$log->info("Info message");
$log->error("Error message");
...
}With the configuration file above, Log::Log4perl will write Error message to the specified log file, but won’t do anything for the debug() and info() calls, because the log level has been set to ERROR for all components in the first line of configuration file shown above.
Why Log::Log4perl->get_logger and not Log::Log4perl->new? We don’t want to create a new object every time. Usually in OO-Programming, you create an object once and use the reference to it to call its methods. However, this requires that you pass around the object to all functions and the last thing we want is pollute each and every function/method we’re using with a handle to the Logger:
sub function { # Brrrr!!
my($logger, $some, $other, $parameters) = @_;
}Instead, if a function/method wants a reference to the logger, it just calls the Logger’s static get_logger($category) method to obtain a reference to the one and only possible logger object of a certain category. That’s called a singleton if you’re a Gamma fan. 💅
How does the logger know which messages it is supposed to log and which ones to suppress? Log::Log4perl works with inheritance: The config file above didn’t specify anything about My::MegaPackage. And yet, we’ve defined a logger of the category My::MegaPackage. In this case, Log::Log4perl will walk up the namespace hierarchy (My and then we’re at the root) to figure out if a log level is defined somewhere. In the case above, the log level at the root (root always defines a log level, but not necessarily an appender) defines that the log level is supposed to be ERROR — meaning that DEBUG and INFO messages are suppressed. Note that this ‘inheritance’ is unrelated to Perl’s class inheritance, it is merely related to the logger namespace. By the way, if you’re ever in doubt about what a logger’s category is, use $logger->category() to retrieve it.
Root always defines a log level, but not necessarily an appender — important little vibe check.
🔥 Log Levels 🔥
There are six predefined log levels: FATAL, ERROR, WARN, INFO, DEBUG, and TRACE (in descending priority). Your configured logging level has to at least match the priority of the logging message.
If your configured logging level is WARN, then messages logged with info(), debug(), and trace() will be suppressed. fatal(), error() and warn() will make their way through, because their priority is higher or equal than the configured setting.
Instead of calling the methods:
$logger->trace("..."); # Log a trace message
$logger->debug("..."); # Log a debug message
$logger->info("..."); # Log a info message
$logger->warn("..."); # Log a warn message
$logger->error("..."); # Log a error message
$logger->fatal("..."); # Log a fatal messageyou could also call the log() method with the appropriate level using the constants defined in Log::Log4perl::Level:
use Log::Log4perl::Level;
$logger->log($TRACE, "...");
$logger->log($DEBUG, "...");
$logger->log($INFO, "...");
$logger->log($WARN, "...");
$logger->log($ERROR, "...");
$logger->log($FATAL, "...");This form is rarely used, but it comes in handy if you want to log at different levels depending on an exit code of a function:
$logger->log( $exit_level{ $rc }, "...");As for needing more logging levels than these predefined ones: It’s usually best to steer your logging behaviour via the category mechanism instead.
If you need to find out if the currently configured logging level would allow a logger’s logging statement to go through, use the logger’s is_level() methods:
$logger->is_trace() # True if trace messages would go through
$logger->is_debug() # True if debug messages would go through
$logger->is_info() # True if info messages would go through
$logger->is_warn() # True if warn messages would go through
$logger->is_error() # True if error messages would go through
$logger->is_fatal() # True if fatal messages would go throughExample: $logger->is_warn() returns true if the logger’s current level, as derived from either the logger’s category (or, in absence of that, one of the logger’s parent’s level setting) is $WARN, $ERROR or $FATAL.
Also available are a series of more Java-esque functions which return the same values. These are of the format isLevelEnabled(), so $logger->isDebugEnabled() is synonymous to $logger->is_debug().
These level checking functions will come in handy later, when we want to block unnecessary expensive parameter construction in case the logging level is too low to log the statement anyway, like in:
if($logger->is_error()) {
$logger->error("Erroneous array: @super_long_array");
}If we had just written:
$logger->error("Erroneous array: @super_long_array");then Perl would have interpolated @super_long_array into the string via an expensive operation only to figure out shortly after that the string can be ignored entirely because the configured logging level is lower than $ERROR. Not me wasting CPU for no reason 😭
The to-be-logged message passed to all of the functions described above can consist of an arbitrary number of arguments, which the logging functions just chain together to a single string. Therefore:
$logger->debug("Hello ", "World", "!"); # and
$logger->debug("Hello World!");are identical. Periodt. 💖
Ok so this next bit is important — don't get it twisted 💅
Note that even if one of the methods above hands you back a true value, that does not automatically mean your message is actually gonna get logged. What is_debug() checks is just that the logger you're using is configured to let a message of that given priority (DEBUG) through. But after that check, Log4perl is still gonna apply whatever custom filters you've got and forward the message along to one or more appenders. None of that gets checked by is_xxx() — and honestly for the simplest reason ever: it's literally impossible to know what a custom filter does with a message without having the actual message, and impossible to know what an appender does with a message without, like, actually having it log it. 🙈
🫶 Log and die or warn
Okay so when you croak / carp / warn / die, you usually want those messages logged too. Instead of doing this kind of thing:
$logger->fatal($err) && die($err);you can just do:
$logger->logdie($err);And instead of doing
warn($message);
$logger->warn($message);— which both fires off a warning through Perl's own warn() mechanism and tries to get the same message into your log file — just use:
$logger->logwarn($message);Now, since there's an ERROR level sitting right between WARN and FATAL, there's two extra helper functions for when you feel like using ERROR for either warn() or die():
$logger->error_warn();
$logger->error_die();And finally ✨ there's the Carp family, which — besides logging — also hands the stringified message over to their besties in the Carp package:
$logger->logcarp(); # warn w/ 1-level stack trace
$logger->logcluck(); # warn w/ full stack trace
$logger->logcroak(); # die w/ 1-level stack trace
$logger->logconfess(); # die w/ full stack trace🎀 Appenders
Real talk: if you don't define any appenders, literally nothing happens. Appenders get triggered whenever the configured logging level says a message needs to be logged and not suppressed. That's the whole vibe check.
Log::Log4perl does not define any appenders by default — not even the root logger has one. Nada. Zero. 🫥
But good news, Log::Log4perl already ships with a whole standard set of appenders:
Log::Log4perl::Appender::Screen
Log::Log4perl::Appender::ScreenColoredLevels
Log::Log4perl::Appender::File
Log::Log4perl::Appender::Socket
Log::Log4perl::Appender::DBI
Log::Log4perl::Appender::Synchronized
Log::Log4perl::Appender::RRDs…so you can log to the screen, to files, and to databases. Obsessed honestly. 💖
Over on CPAN you can also find extra appenders like
Log::Log4perl::Layout::XMLLayoutby Guido Carls <gcarls@cpan.org>. That one lets you hook Log::Log4perl up with the graphical Log Analyzer Chainsaw — see "Can I use Log::Log4perl with log4j's Chainsaw?" in Log::Log4perl::FAQ if you wanna go down that rabbit hole. 🔥
🌈 Additional Appenders via Log::Dispatch
Log::Log4perl also plays nice with Dave Rolsky's absolutely excellent Log::Dispatch framework, which implements a whole wide variety of different appenders.
Here's the list of appender modules currently available via Log::Dispatch:
Log::Dispatch::ApacheLog
Log::Dispatch::DBI (by Tatsuhiko Miyagawa)
Log::Dispatch::Email,
Log::Dispatch::Email::MailSend,
Log::Dispatch::Email::MailSendmail,
Log::Dispatch::Email::MIMELite
Log::Dispatch::File
Log::Dispatch::FileRotate (by Mark Pfeiffer)
Log::Dispatch::Handle
Log::Dispatch::Screen
Log::Dispatch::Syslog
Log::Dispatch::Tk (by Dominique Dumont)Heads up bestie — to use any of these additional appenders, you have to grab Log::Dispatch from CPAN and install it. And also, whichever particular appender you're using might require installing that particular module too. No shortcuts. 😭
For even more deets on appenders, go check the Log::Log4perl::Appender manual page.
🦋 Appender Example
Okay so let's say we want to log info() or higher-priority messages in the Foo::Bar category to both STDOUT and to a log file — let's call it test.log. In the initialization section of your system, you just define two appenders using the readily available Log::Log4perl::Appender::File and Log::Log4perl::Appender::Screen modules:
use Log::Log4perl;
# Configuration in a string ...
my $conf = q(
log4perl.category.Foo.Bar = INFO, Logfile, Screen
log4perl.appender.Logfile = Log::Log4perl::Appender::File
log4perl.appender.Logfile.filename = test.log
log4perl.appender.Logfile.layout = Log::Log4perl::Layout::PatternLayout
log4perl.appender.Logfile.layout.ConversionPattern = [%r] %F %L %m%n
log4perl.appender.Screen = Log::Log4perl::Appender::Screen
log4perl.appender.Screen.stderr = 0
log4perl.appender.Screen.layout = Log::Log4perl::Layout::SimpleLayout
);
# ... passed as a reference to init()
Log::Log4perl::init( \$conf );Once that initialization has happened even once — usually in the startup code of your system — you can just use the logger you defined anywhere in your system, like:
##########################
# ... in some function ...
##########################
my $log = Log::Log4perl::get_logger("Foo::Bar");
# Logs both to STDOUT and to the file test.log
$log->info("Important Info!");The layout settings you specified in the config section are what defines the format the message is gonna get logged in by that appender. The format shown for the file appender is logging not just the message, but also the number of milliseconds since the program started (%r), the name of the file the call to the logger happened in and the line number there (%F and %L), the message itself (%m), and an OS-specific newline character (%n):
[187] ./myscript.pl 27 Important Info!The screen appender up above, though, uses a SimpleLayout, which logs the debug level, a hyphen (-), and then the log message:
INFO - Important Info!For more detailed info on layout formats, see "Log Layouts". ✨
In the config sample above, we chose to define a category logger (Foo::Bar). That means only messages originating from this specific category logger get logged in the defined format and locations. Very main character of it.
🌸 Logging newlines
There's a whole controversy between different logging systems about when and where newlines are supposed to be added to logged messages. Drama. 💀
The Log4perl way is that a logging statement should not contain a newline:
$logger->info("Some message");
$logger->info("Another message");If that's supposed to end up in a log file like
Some message
Another messagethen an appropriate appender layout like "%m%n" will handle adding a newline at the end of each message, so every message gets printed on its own line. Slay.
Other logging systems — Log::Dispatch in particular — recommend adding the newline to the log statement itself. But that doesn't work well if you, say, replace your file appender with a database appender, and suddenly all those newlines scattered around your code make zero sense anymore. 😭
Assigning matching layouts to different appenders and leaving newlines out of the code solves this problem entirely. And if you inherited code that has logging statements with newlines in them and you want to make it work with Log4perl, read the Log::Log4perl::Layout::PatternLayout documentation on how to pull that off. 🫶
🧚 Configuration files
Like shown above, you can define Log::Log4perl loggers both from within your Perl code or from configuration files. The latter have the unbeatable advantage that you can modify your system's logging behaviour without interfering with the code at all. So even if your code is being run by somebody who's totally oblivious to Perl, they can still adapt the module's logging behaviour to their needs. Iconic, honestly. 👑
Log::Log4perl was designed to understand Log4j configuration files — the ones used by the original Java implementation. So instead of me reiterating the format description in [2], let me just list three examples (also derived from [2]) that should illustrate how it works:
log4j.rootLogger=DEBUG, A1
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-4r %-5p %c %x - %m%nThis one enables messages of priority "DEBUG" or higher in the root hierarchy and has the system write them out to the console. ConsoleAppender is a Java appender, but Log::Log4perl jumps through a significant number of hoops internally to map these over to their corresponding Perl classes — Log::Log4perl::Appender::Screen in this case. 🎀
Second example:
log4perl.rootLogger=DEBUG, A1
log4perl.appender.A1=Log::Log4perl::Appender::Screen
log4perl.appender.A1.layout=PatternLayout
log4perl.appender.A1.layout.ConversionPattern=%d %-5p %c - %m%n
log4perl.logger.com.foo=WARNThis defines two loggers: the root logger and the com.foo logger. The root logger gets easily triggered by debug messages, but the com.foo logger makes sure that messages issued within the Com::Foo component and below only get forwarded to the appender if they're of priority warning or higher.
Note that the com.foo logger doesn't define an appender. So it just propagates the message up the hierarchy until the root logger picks it up and forwards it to the one and only appender of the root category, using the format defined for it. ✨
Third example:
log4j.rootLogger=DEBUG, stdout, R
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%5p (%F:%L) - %m%n
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.File=example.log
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=%p %c - %m%nThe root logger defines two appenders here: stdout, which uses org.apache.log4j.ConsoleAppender (ultimately mapped by Log::Log4perl to Log::Log4perl::Appender::Screen) to write to the screen. And R, an org.apache.log4j.RollingFileAppender (mapped by Log::Log4perl to Log::Dispatch::FileRotate with the File attribute specifying the log file. 🔥
See Log::Log4perl::Config for more examples and syntax explanations.
💜 Log Layouts
So when the logging engine passes a message to an appender because it thinks it should be logged, the appender doesn't just write it out haphazardly. Nope. There's ways to tell the appender how to format the message and add all sorts of interesting data to it: the date and time when the event happened, the file, the line number, the debug level of the logger, and others.
There's currently two layouts defined in Log::Log4perl: Log::Log4perl::Layout::SimpleLayout and Log::Log4perl::Layout::PatternLayout:
Log::Log4perl::SimpleLayout— this one keeps it cute and simple: it just slaps the debug level in front of your message with a hyphen, like"$level - $message". Example of what it spits out:"FATAL - Can't open password file". Low effort, but honestly iconic for quick-and-dirty logging.Log::Log4perl::Layout::PatternLayout— okay bestie, this is the main character. It's super powerful and gives you a wildly flexible,printf-style format. Your format string can hold a whole bunch of placeholders, and the logging engine swaps them out for the real deal when it's time to log:
%c Category of the logging event.
%C Fully qualified package (or class) name of the caller
%d Current date in yyyy/MM/dd hh:mm:ss format
%F File where the logging event occurred
%H Hostname (if Sys::Hostname is available)
%l Fully qualified name of the calling method followed by the
callers source the file name and line number between
parentheses.
%L Line number within the file where the log statement was issued
%m The message to be logged
%m{chomp} The message to be logged, stripped off a trailing newline
%M Method or function where the logging request was issued
%n Newline (OS-independent)
%p Priority of the logging event
%P pid of the current process
%r Number of milliseconds elapsed from program start to logging
event
%R Number of milliseconds elapsed from last logging event to
current logging event
%T A stack trace of functions called
%x The topmost NDC (see below)
%X{key} The entry 'key' of the MDC (see below)
%% A literal percent (%) signNDC and MDC get their whole moment in "Nested Diagnostic Context (NDC)" and "Mapped Diagnostic Context (MDC)" — go peek at those.
Also, %d is not done slaying: you can fine-tune it to show only certain bits of a date, following the SimpleDateFormat rules from the Java world (<http://java.sun.com/j2se/1.3/docs/api/java/text/SimpleDateFormat.html>).
So like, %d{HH:mm} shows you only the hours and minutes of the current date, and %d{yy, EEEE} gives you a two-digit year followed by the day spelled out in full (think "Wednesday"). Obsessed.
Same kind of shrinking magic works for the category or for limiting file/path components: %F{1} prints just the source file name with no path components at all, while plain %F logs the whole entire path. And %c{2} logs only the last two components of the current category — "Foo::Bar::Baz" turns into "Bar::Baz" and saves you so much space. Periodt.
And if those placeholders still aren't enough for you (greedy 💅), you can define your own right there in the config file, like this:
log4perl.PatternLayout.cspec.U = sub { return "UID $<" }More deets on customized specifiers live over in Log::Log4perl::Layout::PatternLayout.
Heads up bestie: any subroutines you define this way are going to run in the "main" namespace, so make sure you fully qualify your functions and variables if they live in any other package. No shortcuts there, fr fr.
SECURITY NOTE: this feature means arbitrary perl code can be embedded in the config file. In the rare case where the people who have access to your config file are different from the people who write your code and shouldn't have execute rights, you might want to call
Log::Log4perl::Config->allow_code(0);before you call init(). Alternatively you can supply a restricted set of Perl opcodes that can be embedded in the config file, as described in "Restricting what Opcodes can be in a Perl Hook". Stay safe out there 🫶
All the placeholders are quantifiable too, just like in printf. Following that tradition, "%-20c" reserves 20 chars for the category and left-justifies it. Chef's kiss.
For more details on logging and how to use the flexible and the simple format, check out the original "log4j" website under
SimpleLayout <http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/SimpleLayout.html>
and PatternLayout <http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/PatternLayout.html>
💸 Penalties 💸
Logging comes with a price tag, sorry to say 😭. "Log::Log4perl" has been optimized to allow for maximum performance, both with logging enabled and disabled.
But you do need to be aware that there's a small hit every single time your code encounters a log statement — no matter if logging is enabled or not. "Log::Log4perl" has been designed to keep that hit so low that it'll be unnoticeable to most applications. Slay.
Here's a couple of tricks which help "Log::Log4perl" avoid unnecessary delays:
You can save serious time if you're logging something like
# Expensive in non-debug mode!
for (@super_long_array) {
$logger->debug("Element: $_");
}and @super_long_array is fairly big, so looping through it is pretty expensive. Only you, the programmer, knows that going through that "for" loop can be skipped entirely if the current logging level for the actual component is higher than "debug". In that case, use this instead:
# Cheap in non-debug mode!
if($logger->is_debug()) {
for (@super_long_array) {
$logger->debug("Element: $_");
}
}If you're afraid that generating the parameters to the logging function is fairly expensive, use closures:
# Passed as subroutine ref
use Data::Dumper;
$logger->debug(sub { Dumper($data) } );This won't unravel $data via Dumper() unless it's actually needed because it's logged. Which is honestly so efficient of it 💅.
Also, Log::Log4perl lets you specify arguments to logger functions in message output filter syntax:
$logger->debug("Structure: ",
{ filter => \&Dumper,
value => $someref });In this way, shortly before Log::Log4perl sends the message out to any appenders, it will be searching all arguments for hash references and treat them in a special way:
It will invoke the function given as a reference with the "filter" key (Data::Dumper::Dumper()) and pass it the value that came with the key named "value" as an argument. The anonymous hash in the call above will be replaced by the return value of the filter function. Iconic behavior honestly 🎀
💖 Categories 💖
Okay so first things first: categories are also called "Loggers" in Log4perl — same thing, and the docs use both words interchangeably, so don't let that trip you up, bestie. Log::Log4perl uses categories to figure out whether a log statement in some component should actually run or get suppressed at the current logging level. And like, most of the time these categories are literally just the classes the log statements live in:
package Candy::Twix;
sub new {
my $logger = Log::Log4perl->get_logger("Candy::Twix");
$logger->debug("Creating a new Twix bar");
bless {}, shift;
}
# ...
package Candy::Snickers;
sub new {
my $logger = Log::Log4perl->get_logger("Candy.Snickers");
$logger->debug("Creating a new Snickers bar");
bless {}, shift;
}
# ...
package main;
Log::Log4perl->init("mylogdefs.conf");
# => "LOG> Creating a new Snickers bar"
my $first = Candy::Snickers->new();
# => "LOG> Creating a new Twix bar"
my $second = Candy::Twix->new();Not me using a twix/snickers example, the vibes are immaculate. 🍫
Also, key detail: you can separate your category hierarchy levels using either dots like in Java (.) or double-colons (::) like in Perl. Both notations are equivalent and get handled the same way internally. Slay.
But here's the actual tea ☕ — categories are only there to make use of inheritance: if you invoke a logger in a sub-category, it bubbles up the hierarchy and calls the appropriate appenders. Internally, categories are not related to the class hierarchy of the program at all — they're purely virtual. So you can use arbitrary categories, like in this program which isn't oo-style at all but procedural:
sub print_portfolio {
my $log = Log::Log4perl->get_logger("user.portfolio");
$log->debug("Quotes requested: @_");
for(@_) {
print "$_: ", get_quote($_), "\n";
}
}
sub get_quote {
my $log = Log::Log4perl->get_logger("internet.quotesystem");
$log->debug("Fetching quote: $_[0]");
return yahoo_quote($_[0]);
}The logger in the first function, print_portfolio, is assigned the (virtual) user.portfolio category. Depending on the Log4perl configuration, this will either call a user.portfolio appender, a user appender, or an appender assigned to root — and user.portfolio has zero relevance to the class system used in the program. Meanwhile the logger in the second function reps the internet.quotesystem category — again, maybe because it's bundled with other Internet functions, but not because there'd be a class of this name somewhere. Virtual categories, no cap. ✨
But be careful, don't go overboard 🫶 — if you're developing a system in object-oriented style, using the class hierarchy is usually your best choice. Think about the people taking over your code one day: the class hierarchy is probably what they know right up front, so it's easy for them to tune the logging to their needs.
🚫 Turn off a component 🚫
Log4perl doesn't only let you selectively switch on a category of log messages — you can also use the same mechanism to selectively disable logging in certain components while logging stays turned on in higher-level categories. This comes in so handy when you bump up the logging level of a high-level (i.e. close to root) category and suddenly one component is logging way more than it should. 💀
Here's how it works:
############################################################
# Turn off logging in a lower-level category while keeping
# it active in higher-level categories.
############################################################
log4perl.rootLogger=DEBUG, LOGFILE
log4perl.logger.deep.down.the.hierarchy = ERROR, LOGFILE
# ... Define appenders ...So this way, log messages issued from within Deep::Down::The::Hierarchy and below get logged only if they're ERROR or worse, while in all other system components even DEBUG messages will be logged. Selective muting, we love to see it. 🙈
🎀 Return Values 🎀
Every single logging method returns a value telling you whether its message actually reached one or more appenders. If the message got suppressed because of level constraints, undef is returned.
For example,
my $ret = $logger->info("Message");will return undef if the system debug level for the current category is not INFO or more permissive. If Log::Log4perl forwarded the message to one or more appenders, the number of appenders is returned.
And if appenders decide to veto the message with an appender threshold, the log method's return value will have them excluded. Which means: if you've got one appender holding an appender threshold and you're logging a message that passes the system's log level hurdle but not the appender threshold, 0 will be returned by the log function. Zero. Nothing. The call said "mm, no." 😭
So the bottom line is: logging functions return a true value if the message made it through to one or more appenders, and a false value if it didn't. Which is literally what makes constructs like this possible:
$logger->fatal("@_") or print STDERR "@_\n";That one right there ensures the fatal message isn't lost if the current level is lower than FATAL, and isn't printed twice if the level is acceptable but an appender already points to STDERR. Chef's kiss, honestly. 👑
⚠️ Pitfalls with Categories ⚠️
Be careful with just blindly reusing the system's packages as categories, bestie. If you do, you'll get into trouble with inherited methods. Imagine the following class setup:
use Log::Log4perl;
###########################################
package Bar;
###########################################
sub new {
my($class) = @_;
my $logger = Log::Log4perl::get_logger(__PACKAGE__);
$logger->debug("Creating instance");
bless {}, $class;
}
###########################################
package Bar::Twix;
###########################################
our @ISA = qw(Bar);
###########################################
package main;
###########################################
Log::Log4perl->init(\ qq{
log4perl.category.Bar.Twix = DEBUG, Screen
log4perl.appender.Screen = Log::Log4perl::Appender::Screen
log4perl.appender.Screen.layout = SimpleLayout
});
my $bar = Bar::Twix->new();Bar::Twix just inherits everything from Bar, including the constructor new(). And contrary to what you might be thinking at first — this won't log anything. 😱
The reason is the get_logger() call inside package Bar, which will always get a logger of the Bar category, even if we call new() via the Bar::Twix package — which makes perl go up the inheritance tree to actually execute Bar::new(). And since we've only defined logging behaviour for Bar::Twix in the configuration file… nothing happens. Void. Silence. 🦗
This can be fixed by changing the get_logger() method in Bar::new() to obtain a logger of the category matching the actual class of the object, like in
# ... in Bar::new() ...
my $logger = Log::Log4perl::get_logger( $class );In a method other than the constructor, the class name of the actual object can be obtained by calling ref() on the object reference, so:
package BaseClass;
use Log::Log4perl qw( get_logger );
sub new {
bless {}, shift;
}
sub method {
my( $self ) = @_;
get_logger( ref $self )->debug( "message" );
}
package SubClass;
our @ISA = qw(BaseClass);…is the recommended pattern to make sure that
my $sub = SubClass->new();
$sub->meth();actually starts logging if the SubClass category (and not the BaseClass category) has logging enabled at the DEBUG level. Periodt. 💅
1️⃣ Initialize once and only once 1️⃣
It's super important to realize that Log::Log4perl gets initialized once and only once, typically at the start of a program or system. Calling init() more than once will cause it to clobber the existing configuration and replace it by the new one. Rude, but that's the deal.
If you're in a traditional CGI environment, where every request is handled by a new process, calling init() every time is fine — go off. But in persistent environments like mod_perl, Log::Log4perl should be initialized either at system startup time (Apache offers startup handlers for that) or via:
# Init or skip if already done
Log::Log4perl->init_once($conf_file);init_once() is identical to init(), just with the exception that it will leave a potentially existing configuration alone and will only call init() if Log::Log4perl hasn't been initialized yet. Protective queen behavior. 🫶
And if you're just curious whether Log::Log4perl has been initialized yet, this check right here:
if(Log::Log4perl->initialized()) {
# Yes, Log::Log4perl has already been initialized
} else {
# No, not initialized yet ...
}does the trick. ✨
If you're afraid that the components of your system are stepping on each other's toes, or if you're thinking that different components should initialize Log::Log4perl separately — try to consolidate your system to use a centralized Log4perl configuration file, and use Log4perl's categories to separate your components. Teamwork, but make it config.
🧚 Custom Filters 🧚
Log4perl allows the use of customized filters in its appenders to control the output of messages. These filters might grep for certain text chunks in a message, verify that its priority matches or exceeds a certain level, or that this is the 10th time the same message has been submitted — and then come to a log/no-log decision based on these circumstantial facts. Detective energy, honestly. 🔍
Check out Log::Log4perl::Filter for detailed instructions on how to use them. Go read it, iykyk.
⚡ Performance ⚡
The performance of Log::Log4perl calls obviously depends on a lot of things. But to give you a general idea, here's some rough numbers:
On a Pentium 4 Linux box at 2.4 GHz, you'll get through
- 500,000 suppressed log statements per second
- 30,000 logged messages per second (using an in-memory appender)
init_and_watchdelay mode: 300,000 suppressed, 30,000 logged.init_and_watchsignal mode: 450,000 suppressed, 30,000 logged.
Numbers depend on the complexity of the Log::Log4perl configuration. For a more detailed benchmark test, check the docs/benchmark.results.txt document in the Log::Log4perl distribution. Fast fast. 🏎️💨
🌈 Cool Tricks 🌈
Here's a collection of useful tricks for the advanced Log::Log4perl user. For more, check the FAQ, either in the distribution (Log::Log4perl::FAQ) or on http://log4perl.sourceforge.net. Main character resource, honestly. 👑
⭐ Shortcuts ⭐
When getting an instance of a logger, instead of saying
use Log::Log4perl;
my $logger = Log::Log4perl->get_logger();it's often more convenient to import the get_logger method from Log::Log4perl into the current namespace:
use Log::Log4perl qw(get_logger);
my $logger = get_logger();Okay bestie, this difference is lowkey important 💅: To obtain the root logger, please use get_logger(""). If you call it without parameters (get_logger()), you'll get the logger of a category named after the current package. And get_logger() is equivalent to get_logger(__PACKAGE__). Periodt. ✨
🌱 Alternative initialization 🌱
So instead of having init() read in a configuration file by specifying a file name or passing it a reference to an open filehandle (Log::Log4perl->init( \*FILE )), you can also pass in a reference to a string containing the content of the file:
Log::Log4perl->init( \$config_text );Also, if you've got the name=value pairs of the configuration in a hash, you can just as well initialize Log::Log4perl with a reference to it:
my %key_value_pairs = (
"log4perl.rootLogger" => "ERROR, LOGFILE",
"log4perl.appender.LOGFILE" => "Log::Log4perl::Appender::File",
...
);
Log::Log4perl->init( \%key_value_pairs );Or also you can use a URL, see below 👀:
🛰️ Using LWP to parse URLs 🛰️
(This section borrowed from XML::DOM::Parser by T.J. Mather).
The init() function now also supports URLs, e.g. http://www.erols.com/enno/xsa.xml. It uses LWP to download the file and then calls parse() on the resulting string. By default it will use a LWP::UserAgent that is created as follows:
use LWP::UserAgent;
$LWP_USER_AGENT = LWP::UserAgent->new;
$LWP_USER_AGENT->env_proxy;Note that env_proxy reads proxy settings from environment variables, which is what Log4perl needs to do to get through our firewall 🔥. If you want to use a different LWP::UserAgent, you can set it with
Log::Log4perl::Config::set_LWP_UserAgent($my_agent);Currently, LWP is used when the filename (passed to parsefile) starts with one of the following URL schemes: http, https, ftp, wais, gopher, or file (followed by a colon.)
🚨 Don't use this feature with init_and_watch(). Like, fr fr, just don't.
♻️ Automatic reloading of changed configuration files ♻️
Instead of just statically initializing Log::Log4perl via
Log::Log4perl->init($conf_file);there's a way to have Log::Log4perl periodically check for changes in the configuration and reload it if necessary:
Log::Log4perl->init_and_watch($conf_file, $delay);In this mode, Log::Log4perl will examine the configuration file $conf_file every $delay seconds for changes via the file's last modification timestamp. If the file has been updated, it will be reloaded and replace the current Log::Log4perl configuration.
The way this works is that with every logger function called (debug(), is_debug(), etc.), Log::Log4perl will check if the delay interval has expired. If so, it will run a -M file check on the configuration file. If its timestamp has been modified, the current configuration will be dumped and new content of the file will be loaded.
This convenience comes at a price, though: Calling time() with every logging function call, especially the ones that are "suppressed" (!), will slow down these Log4perl calls by about 40%. 😭
To alleviate this performance hit a bit, init_and_watch() can be configured to listen for a Unix signal to reload the configuration instead:
Log::Log4perl->init_and_watch($conf_file, 'HUP');This will set up a signal handler for SIGHUP and reload the configuration if the application receives this signal, e.g. via the kill command:
kill -HUP pidwhere "pid" is the process ID of the application. This will bring you back to about 85% of Log::Log4perl's normal execution speed for suppressed statements. For details, check out "Performance". For more info on the signal handler, look for "SIGNAL MODE" in Log::Log4perl::Config::Watch.
If you have a somewhat long delay set between physical config file checks or don't want to use the signal associated with the config file watcher, you can trigger a configuration reload at the next possible time by calling Log::Log4perl::Config->watcher->force_next_check().
One thing to watch out for: If the configuration file contains a syntax or other fatal error, a running application will stop with die if this damaged configuration will be loaded during runtime, triggered either by a signal or if the delay period expired and the change is detected. This behaviour might change in the future. 😬
To allow the application to intercept and control a configuration reload in init_and_watch mode, a callback can be specified:
Log::Log4perl->init_and_watch($conf_file, 10, {
preinit_callback => \&callback });If Log4perl determines that the configuration needs to be reloaded, it will call the "preinit_callback" function without parameters. If the callback returns a true value, Log4perl will proceed and reload the configuration. If the callback returns a false value, Log4perl will keep the old configuration and skip reloading it until the next time around. Inside the callback, an application can run all kinds of checks, including accessing the configuration file, which is available via "Log::Log4perl::Config->watcher()->file()".
🧃 Variable Substitution 🧃
To avoid having to retype the same expressions over and over again, Log::Log4perl's configuration files support simple variable substitution. New variables are defined simply by adding
varname = valuelines to the configuration file before using
${varname}afterwards to recall the assigned values. Here's an example:
layout_class = Log::Log4perl::Layout::PatternLayout
layout_pattern = %d %F{1} %L> %m %n
log4perl.category.Bar.Twix = WARN, Logfile, Screen
log4perl.appender.Logfile = Log::Log4perl::Appender::File
log4perl.appender.Logfile.filename = test.log
log4perl.appender.Logfile.layout = ${layout_class}
log4perl.appender.Logfile.layout.ConversionPattern = ${layout_pattern}
log4perl.appender.Screen = Log::Log4perl::Appender::Screen
log4perl.appender.Screen.layout = ${layout_class}
log4perl.appender.Screen.layout.ConversionPattern = ${layout_pattern}This is a convenient way to define two appenders with the same layout without having to retype the pattern definitions. Obsessed. 💖
Variable substitution via ${varname} will first try to find an explicitly defined variable. If that fails, it will check your shell's environment for a variable of that name. If that also fails, the program will die().
🪝 Perl Hooks in the Configuration File 🪝
If some of the values used in the Log4perl configuration file need to be dynamically modified by the program, use Perl hooks:
log4perl.appender.File.filename = \
sub { return getLogfileName(); }Each value starting with the string "sub {..." is interpreted as Perl code to be executed at the time the application parses the configuration via Log::Log4perl::init(). The return value of the subroutine is used by Log::Log4perl as the configuration value.
The Perl code is executed in the "main" package, functions in other packages have to be called in fully-qualified notation.
Here's another example, utilizing an environment variable as a username for a DBI appender:
log4perl.appender.DB.username = \
sub { $ENV{DB_USER_NAME } }However, please note the difference between these code snippets and those used for user-defined conversion specifiers as discussed in Log::Log4perl::Layout::PatternLayout: While the snippets above are run once when Log::Log4perl::init() is called, the conversion specifier snippets are executed each time a message is rendered according to the PatternLayout.
🔐 SECURITY NOTE: this feature means arbitrary perl code can be embedded in the config file. In the rare case where the people who have access to your config file are different from the people who write your code and shouldn't have execute rights, you might want to set
Log::Log4perl::Config->allow_code(0);before you call init(). Alternatively you can supply a restricted set of Perl opcodes that can be embedded in the config file as described in "Restricting what Opcodes can be in a Perl Hook".
🛡️ Restricting what Opcodes can be in a Perl Hook 🛡️
The value you pass to Log::Log4perl::Config->allow_code() determines whether the code that is embedded in the config file is eval'd unrestricted, or eval'd in a Safe compartment. By default, a value of '1' is assumed, which does a normal 'eval' without any restrictions. A value of '0' however prevents any embedded code from being evaluated.
If you would like fine-grained control over what can and cannot be included in embedded code, then please utilize the following methods:
Log::Log4perl::Config->allow_code( $allow );
Log::Log4perl::Config->allowed_code_ops($op1, $op2, ... );
Log::Log4perl::Config->vars_shared_with_safe_compartment( [ \%vars | $package, \@vars ] );
Log::Log4perl::Config->allowed_code_ops_convenience_map( [ \%map | $name, \@mask ] );Log::Log4perl::Config->allowed_code_ops() takes a list of opcode masks that are allowed to run in the compartment. The opcode masks must be specified as described in Opcode:
Log::Log4perl::Config->allowed_code_ops(':subprocess');This example would allow Perl operations like backticks, system, fork, and waitpid to be executed in the compartment. Of course, you probably don't want to use this mask -- it would allow exactly what the Safe compartment is designed to prevent. 💀
Log::Log4perl::Config->vars_shared_with_safe_compartment() takes the symbols which should be exported into the Safe compartment before the code is evaluated. The keys of this hash are the package names that the symbols are in, and the values are array references to the literal symbol names. For convenience, the default settings export the '%ENV' hash from the 'main' package into the compartment:
Log::Log4perl::Config->vars_shared_with_safe_compartment(
main => [ '%ENV' ],
);Log::Log4perl::Config->allowed_code_ops_convenience_map() is an accessor method to a map of convenience names to opcode masks. At present, the following convenience names are defined:
safe = [ ':browse' ]
restrictive = [ ':default' ]For convenience, if Log::Log4perl::Config->allow_code() is called with a value which is a key of the map previously defined with Log::Log4perl::Config->allowed_code_ops_convenience_map(), then the allowed opcodes are set according to the value defined in the map. If this is confusing, consider the following:
use Log::Log4perl;
my $config = <<'END';
log4perl.logger = INFO, Main
log4perl.appender.Main = Log::Log4perl::Appender::File
log4perl.appender.Main.filename = \
sub { "example" . getpwuid($<) . ".log" }
log4perl.appender.Main.layout = Log::Log4perl::Layout::SimpleLayout
END$Log::Log4perl::Config->allow_code('restrictive');
Log::Log4perl->init( \$config ); # will fail
$Log::Log4perl::Config->allow_code('safe');
Log::Log4perl->init( \$config ); # will succeedSo why does that first ->init() flop? 💀 Because the name 'restrictive' maps to an opcode mask of :default, and getpwuid() is not part of :default, so ->init() just gives up. Meanwhile 'safe' maps to an opcode mask of :browse, which does let getpwuid() run, so ->init() slays and succeeds. ✨
allowed_code_ops_convenience_map() can be called in several ways, bestie:
allowed_code_ops_convenience_map()— hands you the whole convenience name map back, as a hash reference in scalar context or a hash in list context.allowed_code_ops_convenience_map( \%map )— swaps the entire convenience name map out for the hash reference you pass in.allowed_code_ops_convenience_map( $name )— gives you the opcode mask for that convenience name, orundefif no such name exists in the map.allowed_code_ops_convenience_map( $name, \@mask )— adds that name/mask pair to the convenience name map. If the name's already in there, its value gets replaced with the new mask.
And vars_shared_with_safe_compartment() works the same way, lowkey:
vars_shared_with_safe_compartment()— returns the whole map of packages to variables, as a hash reference in scalar context or a hash in list context.vars_shared_with_safe_compartment( \%packages )— replaces the entire map of packages to variables with the hash reference you hand it.vars_shared_with_safe_compartment( $package )— returns the arrayref of variables to be shared for one specific package.vars_shared_with_safe_compartment( $package, \@vars )— adds that package / varlist pair to the map. If the package already exists in the map, its value gets replaced with the new arrayref of variable names.
Want the deep lore on opcodes and Safe Compartments? Go read Opcode and Safe. 🧠
🎚️ Changing the Log Level on a Logger
Log::Log4perl ships some internal functions so you can quickly adjust the log level from inside a running Perl program. 🏃♀️
Now, some people might argue you should adjust your levels from an external Log4perl configuration file instead — but bestie, Log4perl is everybody's darling. 💅
Typically you'd do this run-time level adjusting at the beginning, or in response to some external input (like a "more logging" runtime command for diagnostics). 🔍
You get the log level out of a logger object with:
$current_level = $logger->level();and you can set it with the exact same method — provided you first imported the log level constants, like this:
use Log::Log4perl::Level;Then you can set a logger's level to one of the constants:
$logger->level($ERROR); # one of DEBUG, INFO, WARN, ERROR, FATALWanna increase how much logging is happening? Use:
$logger->more_logging($delta);And to decrease it:
$logger->less_logging($delta);$delta must be a positive integer (for now, they may fix this later ;). ⚠️
There are also two equivalent functions:
$logger->inc_level($delta);
$logger->dec_level($delta);They exist so you get a choice in readability. Some folks will prefer more_logging/less_logging — they're pretty clear about what they do, and the programmer doesn't have to worry too much about what a Level even is, or whether a higher level means more or less logging. Other folks, though, who do understand levels and have lots of code dealing with them, will probably prefer inc_level() and dec_level(), since they want to work with Levels and not stress about whether that means more or less logging. :) 🫶
That whole diatribe aside, typically you'll use more_logging() or inc_level() like this:
my $v = 0; # default level of verbosity.
GetOptions("v+" => \$v, ...);
if( $v ) {
$logger->more_logging($v); # inc logging level once for each -v in ARGV
}🌈 Custom Log Levels
First off, let me tell you: creating custom levels is heavily deprecated by the log4j folks. 😬 For real — instead of stacking additional levels on top of the predefined DEBUG, INFO, WARN, ERROR and FATAL, you should use categories to control the amount of logging smartly, based on where the log-active code lives in the system.
Nevertheless, Log4perl does provide a nice way to create custom levels via the create_custom_level() routine function. But heads up — this has to happen before the first call to init() or get_logger(). 🕐 Say you want a NOTIFY logging level that comes after WARN (and therefore before INFO). You'd do it like this:
use Log::Log4perl;
use Log::Log4perl::Level;
Log::Log4perl::Logger::create_custom_level("NOTIFY", "WARN");And that's literally it! create_custom_level() creates these functions / variables for level FOO:
$FOO_INT # integer to use in L4p::Level::to_level()
$logger->foo() # log function to log if level = FOO
$logger->is_foo() # true if current level is >= FOOThese levels can be used in your config file too — but ngl, your config file probably won't be portable to another log4perl or log4j environment unless you've made the appropriate mods there as well. 📦
Since Log4perl translates log levels to syslog and Log::Dispatch when their appenders are used, you may add mappings for custom levels too:
Log::Log4perl::Level::add_priority("NOTIFY", "WARN",
$syslog_equiv, $log_dispatch_level);For example, if your new custom "NOTIFY" level is supposed to map to syslog level 2 ("LOG_NOTICE") and Log::Dispatch level 2 ("notice"), use:
Log::Log4perl::Logger::create_custom_level("NOTIFY", "WARN", 2, 2);🌍 System-wide log levels
As a fairly drastic move to decrease (or increase) the logging level all over the system with one single config option, use the "threshold" keyword in the Log4perl configuration file:
log4perl.threshold = ERRORThat sets the system-wide level (or hierarchy-wide, per the log4j docs) to ERROR, and therefore strips every logger in the system of its right to log lower-prio messages. 💀 Periodt.
🍼 Easy Mode
For teaching purposes (especially for [1]), they've put ":easy" mode into Log::Log4perl, which just initializes a single root logger with a defined priority and a screen appender, including some nice standard layout:
### Initialization Section
use Log::Log4perl qw(:easy);
Log::Log4perl->easy_init($ERROR); # Set priority of root logger to ERROR
### Application Section
my $logger = get_logger();
$logger->fatal("This will get logged.");
$logger->debug("This won't.");That dumps something like:
2002/08/04 11:43:09 ERROR> script.pl:16 main::function - This will get logged.straight to your screen. 🖥️ And yeah, this has been proven to work well for familiarizing people with "Log::Logperl" slowly, effectively avoiding clobbering them over the head with a plethora of different knobs to fiddle with (categories, appenders, levels, layout). But the overall mission of "Log::Log4perl" is to let people use categories right from the start so they get used to the concept. So let's keep this one fairly hidden in the man page (congrats on reading this far :). 🎀
🥷 Stealth loggers
Sometimes, people are lazy. 😴 If you're whipping up a 50-line script and want the comfort of Log::Log4perl without the burden of carrying a separate log4perl.conf file, or a 5-liner defining that you want your log statements appended to a file, you can use these features:
use Log::Log4perl qw(:easy);
Log::Log4perl->easy_init( { level => $DEBUG,
file => ">>test.log" } );
# Logs to test.log via stealth logger
DEBUG("Debug this!");
INFO("Info this!");
WARN("Warn this!");
ERROR("Error this!");
some_function();
sub some_function {
# Same here
FATAL("Fatal this!");
}In ":easy" mode, "Log::Log4perl" will instantiate a stealth logger and introduce the convenience functions "TRACE", DEBUG(), INFO(), WARN(), ERROR(), FATAL(), and "ALWAYS" into the package namespace. These functions simply take messages as arguments and forward them to the stealth logger's methods (debug(), info(), and so on). 🐱👤
If a message should never be blocked, regardless of the log level, use the "ALWAYS" function — it corresponds to a log level of "OFF":
ALWAYS "This will be printed regardless of the log level";The "easy_init" method can be called with a single level value to create a STDERR appender and a root logger, like:
Log::Log4perl->easy_init($DEBUG);Or, as shown below (and in the example above), with a reference to a hash specifying values for "level" (the logger's priority), "file" (the appender's data sink), "category" (the logger's category) and "layout" for the appender's pattern layout specification. All key-value pairs are optional — they default to $DEBUG for "level", "STDERR" for "file", "" (root category) for "category" and "%d %m%n" for "layout":
Log::Log4perl->easy_init( { level => $DEBUG,
file => ">test.log",
utf8 => 1,
category => "Bar::Twix",
layout => '%F{1}-%L-%M: %m%n' } );The "file" parameter takes file names preceded by ">" (overwrite) and ">>" (append) as arguments. This causes "Log::Log4perl::Appender::File" appenders to be created behind the scenes. Also, the keywords "STDOUT" and "STDERR" (no ">" or ">>") are recognized — those utilize and configure "Log::Log4perl::Appender::Screen" appropriately. The "utf8" flag, if set to a true value, runs a "binmode" command on the file handle to establish a utf8 line discipline on the file; otherwise you'll get a 'wide character in print' warning message and probably not what you'd expect as output. 🙈
The stealth loggers can be used in different packages — you just need to make sure you're calling the "use" function in every package where you're using "Log::Log4perl"'s easy services:
package Bar::Twix;
use Log::Log4perl qw(:easy);
sub eat { DEBUG("Twix mjam"); }
package Bar::Mars;
use Log::Log4perl qw(:easy);
sub eat { INFO("Mars mjam"); }
package main;
use Log::Log4perl qw(:easy);Log::Log4perl->easy_init( { level => $DEBUG,
file => ">>test.log",
category => "Bar::Twix",
layout => '%F{1}-%L-%M: %m%n' },
{ level => $DEBUG,
file => "STDOUT",
category => "Bar::Mars",
layout => '%m%n' },
);
Bar::Twix::eat();
Bar::Mars::eat();okay so literally the way this works is easy_init() will take any number of different logger definitions as hash references 🫶 — like, as many as you want, each one its own little hashref, no cap.
Also!! stealth loggers come with the functions LOGWARN(), LOGDIE(), and LOGEXIT(), and these bad boys combine a logging request with a subsequent Perl warn() or die() or exit() statement ✨. So like, for example:
if($all_is_lost) {
LOGDIE("Terrible Problem");
}will log the message if the package's logger is at least "FATAL" but die() (including the traditional output to STDERR) in any case afterwards 💀. Like, it logs and dies. Both. Always dies. iykyk.
See "Log and die or warn" for the similar logdie() and logwarn() functions of regular (i.e non-stealth) loggers.
Similarily, LOGCARP(), LOGCLUCK(), LOGCROAK(), and LOGCONFESS() are provided in :easy mode, facilitating the use of logcarp(), logcluck(), logcroak(), and logconfess() with stealth loggers 🎀.
When using Log::Log4perl in easy mode, please make sure you understand the implications of "Pitfalls with Categories". (fr fr, go read that one, it matters 🙈)
By the way — and this is the slay part — these convenience functions perform exactly as fast as the standard Log::Log4perl logger methods, there's no performance penalty whatsoever 👑. zero. nada. you're welcome.
🧵 Nested Diagnostic Context (NDC)
If you find that your application could use a global (thread-specific) data stack which your loggers throughout the system have easy access to, use Nested Diagnostic Contexts (NDCs) ✨. Also check out "Mapped Diagnostic Context (MDC)" — that one might turn out to be even more useful, lowkey.
For example, when handling a request of a web client, it's probably useful to have the user's IP address available in all log statements within code dealing with this particular request 🌸. Instead of passing this piece of data around between your application functions, you can just use the global (but thread-specific) NDC mechanism 💅. It lets you push data pieces (scalars usually) onto its stack via:
Log::Log4perl::NDC->push("San");
Log::Log4perl::NDC->push("Francisco");and have your loggers retrieve them again via the "%x" placeholder in the PatternLayout 🦋. With the stack values above and a PatternLayout format like "%x %m%n", the call
$logger->debug("rocks");will end up as
San Francisco rocksin the log appender 🔥. iconic behavior honestly.
The stack mechanism allows for nested structures. Just make sure that at the end of the request, you either decrease the stack one by one by calling
Log::Log4perl::NDC->pop();
Log::Log4perl::NDC->pop();or clear out the entire NDC stack by calling
Log::Log4perl::NDC->remove();Even if you should forget to do that, Log::Log4perl won't grow the stack indefinitely, but limit it to a maximum, defined in "Log::Log4perl::NDC" (currently 5) ⭐. A call to push() on a full stack will just replace the topmost element by the new value, so like… it self-regulates, bestie 💅.
Again, the stack is always available via the "%x" placeholder in the Log::Log4perl::Layout::PatternLayout class whenever a logger fires 🎀. It will replace "%x" by the blank-separated list of the values on the stack. It does that by just calling
Log::Log4perl::NDC->get();internally. See details on how this standard log4j feature is implemented in Log::Log4perl::NDC 🫶.
🗺️ Mapped Diagnostic Context (MDC)
Just like the previously discussed NDC stores thread-specific information in a stack structure, the MDC implements a hash table to store key/value pairs in 🔑.
The static method
Log::Log4perl::MDC->put($key, $value);stores $value under a key $key, with which it can be retrieved later (possibly in a totally different part of the system 👀) by calling the "get" method:
my $value = Log::Log4perl::MDC->get($key);If no value has been stored previously under $key, the "get" method will return "undef" 😭.
Typically, MDC values are retrieved later on via the "%X{...}" placeholder in "Log::Log4perl::Layout::PatternLayout" ✨. If the get() method returns "undef", the placeholder will expand to the string "[undef]".
An application taking a web request might store the remote host like
Log::Log4perl::MDC->put("remote_host", $r->headers("HOST"));at its beginning and if the appender's layout looks something like
log4perl.appender.Logfile.layout.ConversionPattern = %X{remote_host}: %m%nthen a log statement like
DEBUG("Content delivered");will log something like
adsl-63.dsl.snf.pacbell.net: Content deliveredlater on in the program 🌈. honestly chef's kiss.
For details, please check Log::Log4perl::MDC.
🧟 Resurrecting hidden Log4perl Statements
Sometimes scripts need to be deployed in environments without having Log::Log4perl installed yet 🙈. On the other hand, you don't want to live without your Log4perl statements — they're gonna come in handy later, no cap.
So, just deploy your script with Log4perl statements commented out with the pattern "###l4p", like in
###l4p DEBUG "It works!";
# ...
###l4p INFO "Really!";If Log::Log4perl is available, use the :resurrect tag to have Log4perl resurrect those buried statements before the script starts running 🧚:
use Log::Log4perl qw(:resurrect :easy);
###l4p Log::Log4perl->easy_init($DEBUG);
###l4p DEBUG "It works!";
# ...
###l4p INFO "Really!";This will have a source filter kick in and indeed print
2004/11/18 22:08:46 It works!
2004/11/18 22:08:46 Really!In environments lacking Log::Log4perl, just comment out the first line and the script will run nevertheless (but of course without logging 😭):
# use Log::Log4perl qw(:resurrect :easy);
###l4p Log::Log4perl->easy_init($DEBUG);
###l4p DEBUG "It works!";
# ...
###l4p INFO "Really!";because everything's a regular comment now 💅. Alternatively, put the magic Log::Log4perl comment resurrection line into your shell's PERL5OPT environment variable, e.g. for bash:
set PERL5OPT=-MLog::Log4perl=:resurrect,:easy
export PERL5OPTThis will awaken the giant within an otherwise silent script like the following 🔥:
#!/usr/bin/perl
###l4p Log::Log4perl->easy_init($DEBUG);
###l4p DEBUG "It works!";As of "Log::Log4perl" 1.12, you can even force all modules loaded by a script to have their hidden Log4perl statements resurrected 👑. For this to happen, load "Log::Log4perl::Resurrector" before loading any modules:
use Log::Log4perl qw(:easy);
use Log::Log4perl::Resurrector;
use Foobar; # All hidden Log4perl statements in here will
# be uncommented before Foobar gets loaded.
Log::Log4perl->easy_init($DEBUG);
...Check the "Log::Log4perl::Resurrector" manpage for more details 🫶.
🔍 Access defined appenders
All appenders defined in the configuration file or via Perl code can be retrieved by the appender_by_name() class method ✨. This comes in handy if you want to manipulate or query appender properties after the Log4perl configuration has been loaded via init().
Note that internally, Log::Log4perl uses the "Log::Log4perl::Appender" wrapper class to control the real appenders (like "Log::Log4perl::Appender::File" or "Log::Dispatch::FileRotate") 🦋. The "Log::Log4perl::Appender" class has an "appender" attribute, pointing to the real appender.
The reason for this is that external appenders like "Log::Dispatch::FileRotate" don't support all of Log::Log4perl's appender control mechanisms (like appender thresholds) 😤.
The previously mentioned method appender_by_name() returns a reference to the real appender object. If you want access to the wrapper class (e.g. if you want to modify the appender's threshold), use the hash $Log::Log4perl::Logger::APPENDER_BY_NAME{...} instead, which holds references to all appender wrapper objects 💅.
🎚️ Modify appender thresholds
To set an appender's threshold, use its threshold() method:
$app->threshold( $FATAL );To conveniently adjust all appender thresholds (e.g. because a script uses more_logging()), use
# decrease thresholds of all appenders
Log::Log4perl->appender_thresholds_adjust(-1);This will decrease the thresholds of all appenders in the system by one level, i.e. WARN becomes INFO, INFO becomes DEBUG, etc. ⭐ To only modify selected ones, use
# decrease thresholds of selected appenders
Log::Log4perl->appender_thresholds_adjust(-1, ['AppName1', ...]);and pass the names of affected appenders in a ref to an array 🎀.
Advanced configuration within Perl 💅
okay so bestie, you can totally initialize Log::Log4perl from inside Perl itself. At last, this is literally what Log::Log4perl::Config is doing behind the scenes. Log::Log4perl's configuration file parsers use a publicly available API to set up its categories, appenders and layouts. ✨
Here's how to configure two appenders with the same layout in Perl, without using a configuration file at all:
########################
# Initialization section
########################
use Log::Log4perl;
use Log::Log4perl::Layout;
use Log::Log4perl::Level;
# Define a category logger
my $log = Log::Log4perl->get_logger("Foo::Bar");
# Define a layout
my $layout = Log::Log4perl::Layout::PatternLayout->new("[%r] %F %L %m%n");
# Define a file appender
my $file_appender = Log::Log4perl::Appender->new(
"Log::Log4perl::Appender::File",
name => "filelog",
filename => "/tmp/my.log");
# Define a stdout appender
my $stdout_appender = Log::Log4perl::Appender->new(
"Log::Log4perl::Appender::Screen",
name => "screenlog",
stderr => 0);
# Define a mixed stderr/stdout appender
my $mixed_stdout_stderr_appender = Log::Log4perl::Appender->new(
"Log::Log4perl::Appender::Screen",
name => "screenlog",
stderr => { ERROR => 1, FATAL => 1 });
# Have both appenders use the same layout (could be different)
$stdout_appender->layout($layout);
$file_appender->layout($layout);
$log->add_appender($stdout_appender);
$log->add_appender($file_appender);
$log->level($INFO);Please note that the class of the appender object is passed as a string to Log::Log4perl::Appender in the first argument. Behind the scenes, Log::Log4perl::Appender creates the necessary Log::Log4perl::Appender::* (or Log::Dispatch::*) object and passes along the name-value pairs we provided to Log::Log4perl::Appender->new() after the first argument. 🫶
The name value is optional, and if you don't provide one, Log::Log4perl::Appender->new() will create a unique one for you. The names and values of additional parameters depend on the requirements of the particular appender class, and you can look them up in their manual pages.
A side note: in case you're wondering if Log::Log4perl::Appender->new() will also take care of the min_level argument to the Log::Dispatch::* constructors called behind the scenes — yes, it does. This is because we want the Log::Dispatch objects to blindly log everything we send them (debug is their lowest setting), because we in Log::Log4perl want to call the shots and decide on when and what to log. 💀
The call to the appender's layout() method specifies the format (as a previously created Log::Log4perl::Layout::PatternLayout object) in which the message is being logged in the specified appender. If you don't specify a layout, the logger will fall back to Log::Log4perl::SimpleLayout, which logs the debug level, a hyphen (-) and the log message.
Layouts are objects, and here's how you create them:
# Create a simple layout
my $simple = Log::Log4perl::SimpleLayout();
# create a flexible layout:
# ("yyyy/MM/dd hh:mm:ss (file:lineno)> message\n")
my $pattern = Log::Log4perl::Layout::PatternLayout("%d (%F:%L)> %m%n");Every appender has exactly one layout assigned to it. You assign the layout to the appender using the appender's layout() object:
my $app = Log::Log4perl::Appender->new(
"Log::Log4perl::Appender::Screen",
name => "screenlog",
stderr => 0);
# Assign the previously defined flexible layout
$app->layout($pattern);
# Add the appender to a previously defined logger
$logger->add_appender($app);
# ... and you're good to go!
$logger->debug("Blah");
# => "2002/07/10 23:55:35 (test.pl:207)> Blah\n"It's also possible to remove appenders from a logger:
$logger->remove_appender($appender_name);That will remove an appender, specified by name, from a given logger. Please note that this does not remove an appender from the system. 🚨
To eradicate an appender from the system, you need to call Log::Log4perl->eradicate_appender($appender_name), which will first remove the appender from every logger in the system and then will delete all references Log4perl holds to it.
To remove a logger from the system, use Log::Log4perl->remove_logger($logger). After the remaining reference $logger goes away, the logger will self-destruct. If the logger in question is a stealth logger, all of its convenience shortcuts (DEBUG, INFO, etc) will turn into no-ops. ✨
How about Log::Dispatch::Config? 🦋
Tatsuhiko Miyagawa's Log::Dispatch::Config is a very clever simplified logger implementation, covering some of the log4j functionality. Among the things that Log::Log4perl can but Log::Dispatch::Config can't are:
- You can't assign categories to loggers. For small systems that's fine, but if you can't turn off and on detailed logging in only a tiny subsystem of your environment, you're missing out on a majorly useful log4j feature.
- Defining appender thresholds. Important if you want to solve problems like "log all messages of level FATAL to STDERR, plus log all DEBUG messages in "Foo::Bar" to a log file". If you don't have appenders thresholds, there's no way to prevent cluttering STDERR with DEBUG messages.
- PatternLayout specifications in accordance with the standard (e.g.
%d{HH:mm}).
Bottom line: Log::Dispatch::Config is fine for small systems with simple logging requirements. However, if you're designing a system with lots of subsystems which you need to control independently, you'll love the features of Log::Log4perl, which is equally easy to use. 👑
Using Log::Log4perl with wrapper functions and classes 🎀
If you don't use Log::Log4perl as described above, but from a wrapper function, the pattern layout will generate wrong data for %F, %C, %L, and the like. Reason for this is that Log::Log4perl's loggers assume a static caller depth to the application that's using them.
If you're using one (or more) wrapper functions, Log::Log4perl will indicate where your logger function called the loggers, not where your application called your wrapper:
use Log::Log4perl qw(:easy);
Log::Log4perl->easy_init({ level => $DEBUG,
layout => "%M %m%n" });
sub mylog {
my($message) = @_;
DEBUG $message;
}
sub func {
mylog "Hello";
}
func();prints
main::mylog Hellobut that's probably not what your application expects. Rather, you'd want
main::func Hellobecause the func function called your logging function.
But don't despair, there's a solution: just register your wrapper package with Log4perl beforehand. If Log4perl then finds that it's being called from a registered wrapper, it will automatically step up to the next call frame. 🧚
Log::Log4perl->wrapper_register(__PACKAGE__);
sub mylog {
my($message) = @_;
DEBUG $message;
}Alternatively, you can increase the value of the global variable $Log::Log4perl::caller_depth (defaults to 0) by one for every wrapper that's in between your application and Log::Log4perl, then Log::Log4perl will compensate for the difference:
sub mylog {
my($message) = @_;
local $Log::Log4perl::caller_depth =
$Log::Log4perl::caller_depth + 1;
DEBUG $message;
}Also, note that if you're writing a subclass of Log4perl, like
package MyL4pWrapper;
use Log::Log4perl;
our @ISA = qw(Log::Log4perl);and you want to call get_logger() in your code, like
use MyL4pWrapper;
sub get_logger {
my $logger = Log::Log4perl->get_logger();
}then the get_logger() call will get a logger for the MyL4pWrapper category, not for the package calling the wrapper class as in
package UserPackage;
my $logger = MyL4pWrapper->get_logger();To have the above call to get_logger return a logger for the UserPackage category, you need to tell Log4perl that MyL4pWrapper is a Log4perl wrapper class:
use MyL4pWrapper;
Log::Log4perl->wrapper_register(__PACKAGE__);
sub get_logger {
# Now gets a logger for the category of the calling package
my $logger = Log::Log4perl->get_logger();
}This feature works both for Log4perl-relaying classes like the wrapper described above, and for wrappers that inherit from Log4perl use Log4perl's get_logger function via inheritance, alike. 💖
Access to Internals 🔥
The following methods are only of use if you want to peek/poke in the internals of Log::Log4perl. Be careful not to disrupt its inner workings. 🙈
bestie, this is the "look but don't break it" zone, fr fr.
Log::Log4perl->appenders()
To find out which appenders are currently defined (not only for a particular logger, but overall), an appenders() method is available to return a reference to a hash mapping appender names to their Log::Log4perl::Appender object references. ⭐
💅 DIRTY TRICKS 💅
Okay bestie, this is the section where Log4perl stops being polite. These are the chaotic little hacks that make life so much easier — lowkey iconic, no cap.
🕵️ infiltrate_lwp()
So the famous LWP::UserAgent module? It is not Log::Log4perl-enabled. Not even a little. But when you're tracing Web-related problems, bestie, you really want to see what's going on inside LWP::UserAgent. Ideally it would just play along in the Log::Log4perl framework like a good little module.
A call to Log::Log4perl->infiltrate_lwp() does exactly that. And honestly? It does it in a very rude way — it pulls the rug right out from under LWP::UserAgent and transforms its debug/conn messages into debug() calls of loggers of the category LWP::UserAgent. Similarly, LWP::UserAgent's trace messages get turned into Log::Log4perl's info() method calls. Sneaky? Yes. Effective? Also yes. ✨
⚠️ Heads up bestie: this only works for LWP::UserAgent versions < 5.822, because this (and probably later) versions miss debugging functions entirely. Like, they just don't have them. Gone. 💀
🙈 Suppressing 'duplicate' LOGDIE messages
Picture this: a script with a simple Log4perl configuration uses logdie() to catch errors and stop processing, like so:
use Log::Log4perl qw(:easy) ;
Log::Log4perl->easy_init($DEBUG);
shaky_function() or LOGDIE "It failed!";And then you get a cosmetic problem — the message gets printed twice:
2005/07/10 18:37:14 It failed!
It failed! at ./t line 12Not me getting the same message twice 😭
The obvious solution is to use LOGEXIT() instead of LOGDIED()... okay, LOGDIE() — but there's also a special tag for Log4perl that suppresses the second message:
use Log::Log4perl qw(:no_extra_logdie_message);This causes logdie() and logcroak() to call exit() instead of die(). And if you want to modify the script exit code on these occasions, just set the variable $Log::Log4perl::LOGEXIT_CODE to whatever value you want — the default is 1. 🎀
🌀 Redefine values without causing errors
Log4perl's configuration file parser has a few basic safety mechanisms to make sure configurations are more or less sane. Very responsible of it, honestly.
One of these safety measures is catching redefined values. For example, if you first write:
log4perl.category = WARN, Logfileand then a couple of lines later:
log4perl.category = TRACE, Logfilethen you might have unintentionally overwritten the first value, and Log4perl will die on this with an error (suspicious configurations always throw an error — it's giving strict parent energy 👑).
But! There's a chance that this is intentional — for example when you're lumping together several configuration files and actually want the first value to overwrite the second. In that case, use:
use Log::Log4perl qw(:nostrict);to put Log4perl in a more permissive mode. Slay, live your truth. 💅
🪄 Prevent croak/confess from stringifying
The logcroak/logconfess functions stringify their arguments before they pass them to Carp's croak/confess functions. That can absolutely get in the way if you want to throw an object or a hashref as an exception — in which case, use:
$Log::Log4perl::STRINGIFY_DIE_MESSAGE = 0;
eval {
# throws { foo => "bar" }
# without stringification
$logger->logcroak( { foo => "bar" } );
};🌈 EXAMPLE 🌈
A simple example to cut-and-paste and get started — literally just take it, bestie:
use Log::Log4perl qw(get_logger);
my $conf = q(
log4perl.category.Bar.Twix = WARN, Logfile
log4perl.appender.Logfile = Log::Log4perl::Appender::File
log4perl.appender.Logfile.filename = test.log
log4perl.appender.Logfile.layout = \
Log::Log4perl::Layout::PatternLayout
log4perl.appender.Logfile.layout.ConversionPattern = %d %F{1} %L> %m %n
);
Log::Log4perl::init(\$conf);
my $logger = get_logger("Bar::Twix");
$logger->error("Blah");This will log something like:
2002/09/19 23:48:15 t1 25> Blahto the log file test.log, which Log4perl will append to — or create it if it doesn't exist already. Obsessed with a module that just handles it for you. 🫶
🧚 INSTALLATION 🧚
If you want to use external appenders provided with Log::Dispatch, you need to install Log::Dispatch (2.00 or better) from CPAN, which itself depends on Attribute-Handlers and Params-Validate. And a lot of other modules — that's the reason why we're now shipping Log::Log4perl with its own standard appenders, and only if you wish to use additional ones, you'll have to go through the Log::Dispatch installation process. RIP to your CPAN patience in advance. 😭
Log::Log4perl needs Test::More, Test::Harness and File::Spec, but they already come with fairly recent versions of perl. If not, everything's automatically fetched from CPAN if you're using the CPAN shell (CPAN.pm), because they're listed as dependencies. The system got you. ✨
Time::HiRes (1.20 or better) is required only if you need the fine-grained time stamps of the %r parameter in Log::Log4perl::Layout::PatternLayout. Conditional dependency, we love to see it.
Manual installation works as usual with:
perl Makefile.PL
make
make test
make install🔥 DEVELOPMENT 🔥
Log::Log4perl is still being actively developed. We will always make sure the test suite (approx. 500 cases) will pass, but there might still be bugs. Please check <http://github.com/mschilli/log4perl> for the latest release. The api has reached a mature state — we will not change it unless for a good reason. It's giving stable main character energy. 👑
Bug reports and feedback are always welcome, just email them to our mailing list shown in the AUTHORS section. We're usually addressing them immediately. Fr fr, they're fast.
📚 REFERENCES 📚
- [1] Michael Schilli, "Retire your debugger, log smartly with Log::Log4perl!", Tutorial on perl.com, 09/2002, <http://www.perl.com/pub/a/2002/09/11/log4perl.html>
- [2] Ceki Gülcü, "Short introduction to log4j", <http://logging.apache.org/log4j/1.2/manual.html>
- [3] Vipan Singla, "Don't Use System.out.println! Use Log4j.", <http://www.vipan.com/htdocs/log4jhelp.html>
- [4] The Log::Log4perl project home page: <http://log4perl.com>
👀 SEE ALSO 👀
Go read these next, bestie — they're all part of the family:
Log::Log4perl::ConfigLog::Log4perl::AppenderLog::Log4perl::Layout::PatternLayoutLog::Log4perl::Layout::SimpleLayoutLog::Log4perl::LevelLog::Log4perl::JavaMapLog::Log4perl::NDC
💖 AUTHORS 💖
Please contribute patches to the project on Github — the door is open, come through:
http://github.com/mschilli/log4perlSend bug reports or requests for enhancements to the authors via our
MAILING LIST (questions, bug reports, suggestions/patches): log4perl-devel@lists.sourceforge.net
Authors (please contact them via the list above, not directly): Mike Schilli <m@perlmeister.com>, Kevin Goess <cpan@goess.org>
Contributors (in alphabetical order): Ateeq Altaf, Cory Bennett, Jens Berthold, Jeremy Bopp, Hutton Davidson, Chris R. Donnelly, Matisse Enzer, Hugh Esco, Anthony Foiani, James FitzGibbon, Carl Franks, Dennis Gregorovic, Andy Grundman, Paul Harrington, Alexander Hartmaier, David Hull, Robert Jacobson, Jason Kohles, Jeff Macdonald, Markus Peter, Brett Rann, Peter Rabbitson, Erik Selberg, Aaron Straup Cope, Lars Thegler, David Viner, Mac Yang.
Look at that contributor list — absolute legends, every single one. 🌟
🎀 LICENSE 🎀
Copyright 2002-2013 by Mike Schilli <m@perlmeister.com> and Kevin Goess <cpan@goess.org>.
This library is free software; you can redistribute it and/or modify it under the same terms as Perl itself.
And that's the whole page, bestie — you made it to the very end 🎉 This little masterpiece is Log::Log4perl(3), shipped as part of perl v5.42.0 and dated 2022-10-22. Go forth and log smartly, and remember: no print statements in production, iykyk 💜✨
📦 where this page comes from
- opensuse-leap 16.0: perl-Log-Log4perl 1.57-160000.2.2 · Artistic-1.0 OR GPL-1.0-or-later
- 💖 girlified by deepseek-ai/DeepSeek-V4.1-Flash-1017 on : a language model's rewrite of the original, under its terms