Stop Being A Caveman! use Log::Log4perl;

1. Stop Being A Caveman!use Log::Log4perl; by Eric Andreychek eric@openthought.net

2. A long time ago... • in a galaxy far, far away • people debugged Perl code • using print and warn statements • some of these Perl coders even used • the legendary and infamous Perl debugger • these hard working Perl coders were known as ... • Cavemen

3. Put These To Rest Log4perl can help us make ideas like print, warn, and the Perl debugger artifacts of history

4. Lets get this part out of the way... • Log4perl lets you log stuff • In Perl • And it's really cool

5. All You Need... • Define a logging level • Define where and what to log • Use the (so-simple-it's-silly) interface

6. fatal error warn info debug Log Levels Highest Lowest

7. Logger Objects • Logger objects ($logger) do the work • Retrieved using Log4perl's get_logger() method • Logging may occur in any sub in your program • No need to pass $logger to each sub • Messy and Annoying • Log4perl stores the logger object internally • A call to get_logger() returns that stored object • Called a singleton

8. $logger = get_logger(); # Logs when warn, info, or debug $logger->warn(“Help me Obi-Wan, you're my only hope”); # Remains dormant when error or fatal! Logging Example

9. # To set up logging, you could use the following: use Log::Log4perl qw( :easy ); Log::Log4perl->easy_init( $ERROR ); Initializing Log4perl

10. # To set up logging, you could use the following: use Log::Log4perl qw( :easy ); Log::Log4perl->easy_init( $ERROR ); Not!We don't need no steenking “easy”

11. # Darth.pl use Darth(); use Log::Log4perl(); $config = get_my_config(); Log::Log4perl::init( $config ); Initializing Log4perl: /The Real (:?wo)?man's Way/

12. package Darth; use Log::Log4perl qw( get_logger ); sub new { my ( $class, $name ) = @_; my $logger = get_logger(); $logger->debug(“Creating Darth $name”); return bless( { darth => $name }, $class ); } Using Log4perl

13. sub get_lightsaber { my $self = shift; my $logger = get_logger(); $logger->debug(“Fetching lightsaber from the armory”); my $saber = $self->_saber_type || “Red Single-Sided Saber”; $logger->warn(“Giving Darth his light saber: $saber”); return $saber; } Using Log4perl

14. Log4perl Return Values • Logging functions return the number of places they were logged • If message logged: return true • If no message logged: return undef • $total = $logger->warn( $message ); • Being at the WARN level doesn't necessarily mean $logger->warn($message) will be logged • Log4perl could suppress the message • A suppressed message would return undef

15. # Later on in darth.pl my $saber = $darth->get_lightsaber; unless ( $saber ) { my $error = “Nothing to defend against the good guys with, ” . “not even an electronic sausage!” # This will often work, but tends to be a really bad idea $logger->fatal( $error ) && die( $error ) # This utility method doesn't depend on the return value of # $logger->fatal, it will always die $logger->logdie( $error ) } Using Log4perl: Errors

16. Future of Internet Keyboards

17. Configuring The Beast • Configuring Log4perl: TMTOWTDI • Perl • Config files • Both

18. use Log::Log4perl qw( get_logger ); Log::Log4perl::init( “log4perl.conf” ); my $logger = get_logger(); Config Files (my favorite)

19. log4perl.logger = INFO, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout Config File ExampleContents of log4perl.conf

20. log4perl.logger = INFO, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout Config File: CategoryThis config applies to my what?

21. log4perl.logger = INFO, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout Config File: AppenderYou want me to log where?

22. log4perl.logger = INFO, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout Config File: Message LayoutYou want me to log how?

23. Appender (log) Methods • Log4perl uses Log::Dispatch to perform logging • Log::Dispatch supports a number of locations • ApacheLog • DBI • Email • Files • STDOUT / STDERR (Screen) • Syslog • Jabber • Anything else you write

24. log4perl.logger = INFO, Screen log4perl.appender.Screen = Log::Dispatch::File log4perl.appender.Screen.Filename = myfile.log log4perl.appender.Screen.layout = SimpleLayout Appender Location: Log to FileChange From Screen to File

25. log4perl.logger = INFO, FileLog log4perl.appender.FileLog = Log::Dispatch::File log4perl.appender.FileLog.Filename = myfile.log log4perl.appender.FileLog.layout = SimpleLayout Appender NameShould Make Sense!

26. log4perl.logger = INFO, Screen, FileLog log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout log4perl.appender.FileLog = Log::Dispatch::File log4perl.appender.FileLog.filename = myfile.log log4perl.appender.FileLog.layout = SimpleLayout Logging To Multiple LocationsChange to File and Screen with Two Appenders

27. log4perl.logger = INFO, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = PatternLayout log4perl.appender.Screen.layout.ConversionPattern=%F %L: %m%n Changing The Log Format

28. %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 %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 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 %x The topmost NDC (see below) %X{key} The entry 'key' of the MDC (see below) %% A literal percent (%) sign Available Placeholders (16 total)

29. # Define a conversion specifier (cspec) in the config file: log4perl.logger = INFO, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = PatternLayout log4perl.appender.Screen.layout.ConversionPattern=%O: %F %L %m%n log4perl.PatternLayout.cspec.O = sub { return "OS $^O" } Custom Placeholders

30. # Programmatically get the filename and layout log4perl.logger = INFO, FileLog log4perl.appender.FileLog = Log::Dispatch::File log4perl.appender.FileLog.Filename = \ sub { getFileName(); } log4perl.appender.FileLog.layout = \ sub { getLayout(); } Perl Code In Config File

31. Code in the Config File: Notes • We can put any code into the config file • This code is run within the main namespace • Some might consider this a security risk • This feature can be disabled with: $Log::Log4perl::ALLOW_CODE_IN_CONFIG_FILE = 0;

32. Everyone take a break, and allow Patrick a few moments to catch up Take a Break

33. Putting Categories to UseGoing Beyond the System Defined Root Logger • One of Log4perl's key features is categories • Enable extra logging for just one portion of your application • Remainder of application produces typical output • Category name: often the name of the current package / class • You've seen the default, root category • To use your own, pass a parameter into get_logger() $logger = get_logger( $category_name );

34. # This is the root category / logger log4perl.logger = WARN, Screen # Create a new category like so: log4perl.logger.CategoryName = DEBUG, Screen Using Categories: Config File

35. Using Categories: Class ExampleSkywalker Class Hierarchy

36. Log Using Multiple Categories • Leia knows what she wants • Vader is set in his ways • We can put these two at a normal log level of “warn” • Luke has issues • He should be put at a log level of “debug”

37. log4perl.logger.Skywalker = WARN, Screen log4perl.logger.Skywalker.Luke = DEBUG, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout Multiple Categories ExampleTwo categories: Log Skywalkers to Screen

38. log4perl.logger.Skywalker = WARN, FileLog log4perl.logger.Skywalker.Luke = DEBUG, Screen log4perl.appender.FileLog = Log::Dispatch::File log4perl.appender.FileLog.layout = SimpleLayout log4perl.appender.FileLog.Filename = myfile.log log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout Multiple Categories ExampleLog base class to File, sub class to Screen and File

39. In package Skywalker: my $logger = get_logger( 'Skywalker' ); In package Skywalker::Leia: my $logger = get_logger( 'Skywalker::Leia' ); In package Skywalker::Luke: my $logger = get_logger( 'Skywalker::Luke' ); Or just... my $logger = get_logger( __PACKAGE__ ); Tell Log4perl Your CategoryPass in Your Class Name

40. Now, Pay Attention!

41. Important Logging Behavior • Once a logger decides to log a message, it does a few things • The message is first logged using each appender attached to thatlogger • Then, the message is unconditionally logged using every appender attached to the logger's parents

42. log4perl.logger = ERROR, Syslog log4perl.logger.Skywalker.Luke = DEBUG, Screen log4perl.appender.Syslog = Log::Dispatch::Syslog log4perl.appender.Syslog.layout = SimpleLayout log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = SimpleLayout Important Logging BehaviorExample Config File

43. Important Logging Behavior root logger Log::Dispatch::Syslog ERROR Skywalker ERROR (inherited) Log::Dispatch::Screen Skywalker::Luke Skywalker::Leia ERROR (inherited) DEBUG

44. Lets take a look at how logging will work throughout the hierarchy What This Means

45. Category root logger (when no category is defined) Properties Defines level: ERROR, location: Syslog Code $logger->error( $light_saber ); Result Logs $light_saber to a syslog Logging Behavior: root logger

46. Category Skywalker and Skywalker::Leia Properties InheritsERROR and Syslog from root logger Code $logger->error( $light_saber ); Result Logs $light_saber to syslog Logging Behavior:Skywalker, Skywalker::Leia

47. Category Skywalker::Luke Properties Defines level: DEBUG, location: Screen Code $logger->error( $light_saber ); Result Logs $light_saber to the screen Logs $light_saber to syslog Logging Behavior: Skywalker::Luke

48. Category Skywalker::Luke Properties Defines level: DEBUG, location: Screen Code $logger->debug( $light_saber ); Result(even though parents are at ERROR) Logs $light_saber to the screen Logs $light_saber to syslog Logging Behavior: Skywalker::Luke

49. Logging Behavior • Might be unnecessarily duplicating the logs • Luke's debug messages all going to syslog • Take advantage of Log4perl! • Continue to log all debugging messages to the screen • Be more picky about what gets logged to syslog • Should all of Skywalker::Luke's debugging messages be in our system logs? • Remember, Luke has a lot of issues

50. Preventing Duplicate Logs • If this behavior isn't what you want, change it: • Set the additivity of a category to zero • Prevents messages from bubbling up • Do this to the Skywalker::Luke category • Set the threshold of an appender to some log level • Defines a minimum log level for oncoming messages • Do this to the root or parent category • Can also set a system-wide default threshold