1 / 88

Smart Logging With Log4perl

Smart Logging With Log4perl. Mike Schilli, Yahoo! YAPC, 06/27/2007. Grab A T-Shirt!. Smart Logging With Log4perl. Mike Schilli, Yahoo! YAPC, 06/27/2007. Logging – why?. Go back in time and figure out what happened. Measure performance Trace activity on live systems

duer
Download Presentation

Smart Logging With Log4perl

An Image/Link below is provided (as is) to download presentation Download Policy: Content on the Website is provided to you AS IS for your information and personal use and may not be sold / licensed / shared on other websites without getting consent from its author. Content is provided to you AS IS for your information and personal use only. Download presentation by click this link. While downloading, if for some reason you are not able to download a presentation, the publisher may have deleted the file from their server. During download, if you can't get a presentation, the file might be deleted by the publisher.

E N D

Presentation Transcript

  1. Smart Logging With Log4perl Mike Schilli, Yahoo! YAPC, 06/27/2007 Grab A T-Shirt!

  2. Smart Logging With Log4perl Mike Schilli, Yahoo! YAPC, 06/27/2007

  3. Logging – why? • Go back in time and figure out what happened. • Measure performance • Trace activity on live systems • Debug during development

  4. Log4perl and Log4j • Log::Log4perl ports Log4j to Perl • Log4j: de facto Java loggingstandard, by Ceki Gülcü • Latest development: ‘logback’ • http://logging.apache.org/log4j • Log::Log4perl adds perlisms demanded by users

  5. Log4perl History • 0.01 release 2002 • Current release 1.11 (06/2007) • Authors: Mike Schilli, Kevin Goess • Used by major banks, target.com, fedex.com, Yahoo!, Google, … • Several CPAN modules support it (e.g. Catalyst, Net::Amazon, …)

  6. Log4perl Release History

  7. Design Goals • Easy to use in small scripts • Scales easily with growing architecture • Log4perl-enabled CPAN modules can be used with and without Log4perl initialization • Optimized for Speed • Open Architecture, extensible

  8. Why Log4perl and not one of the 20 Logging modules on CPAN? • Write once, and L4p-enabled scripts/modules can be used • with any logging configuration you desire • by changing loggers, appenders and layouts independently • Target specific areas of your application only • No need to change your source code to change the logging behaviour • Log4perl is aimed to be the last logging module you’ll ever install

  9. Log::Log4perl for Simple Scripts #!/usr/bin/perl –w use strict; use Log::Log4perl qw(:easy); Log::Log4perl->easy_init($INFO); DEBUG "Won't make it"; INFO "Will go through"; ERROR "Will also go through"; $ easy.pl 2004/10/19 10:56:56 Will go through 2004/10/19 10:56:56 Will also go through

  10. Log::Log4perl for CPAN Modules use strict; use YourCPANModule; use Log::Log4perl qw(:easy); Log::Log4perl->easy_init( $INFO); YourCPANModule::somefunc(); package YourCPANModule; use strict; use Log::Log4perl qw(:easy); sub somefunc { DEBUG "Won't make it"; INFO "Will go through"; }

  11. Log::Log4perl for CPAN Modules use strict; use YourCPANModule; YourCPANModule::somefunc(); package YourCPANModule; use strict; use Log::Log4perl qw(:easy); sub somefunc { DEBUG "Won't make it"; INFO "Won’t make it"; }

  12. Log::Log4perl Building Blocks Loggers Layouts Appenders

  13. Log::Log4perl Building Blocks Loggers Log it or suppress it Layouts Format it Appenders Write it out

  14. Log::Log4perl Building Blocks DEBUG “Starting up”); or my $log = get_logger(); $log->debug(“Starting up”); Loggers Layouts “Starting up” => 2007-06-21 07:30:33 Foo.pm-123 Starting up … Appenders Log File Database

  15. Easy vs. Standard Mode use Log::Log4perl qw(:easy); sub somefunc { DEBUG “Debug Message”; INFO “Info Message”; } use Log::Log4perl qw(get_logger); sub somefunc { my $logger = get_logger(); $logger->debug(“Debug message”); $logger->info(“Info message”); }

  16. Log4perl Operation • Initialize once, at startup: • Define which loggers should fire base on • message priority (DEBUG, INFO, …) • location (Foo::Bar, …) • Define where messages should end up at • Loggers planted in program code get activated

  17. Easy Init vs. Standard Init use Log::Log4perl qw(:easy); Log::Log4perl->easy_init($INFO); use Log::Log4perl; Log::Log4perl->init(“l4p.conf”); #l4p.conf log4perl.category = INFO, Screen log4perl.appender.Screen = \ Log::Log4perl::Appender::Screen log4perl.appender.Screen.stderr = 1 log4perl.appender.Logfile.layout = \ Log::Log4perl::Layout::SimpleLayout

  18. Mix&Match: Standard Init with Easy Functions use Log::Log4perl qw(:easy); Log::Log4perl->init(“l4p.conf”); DEBUG “Debug Message”; INFO “Info Message”; #l4p.conf log4perl.category = WARN, Logfile log4perl.appender.Logfile = \ Log::Log4perl::Appender::File log4perl.appender.Logfile.filename = test.log log4perl.appender.Logfile.layout = \ Log::Log4perl::Layout::SimpleLayout

  19. Mix and Match

  20. Categories or: What the hell does this logo mean?

  21. Categories: Areas of your App package Bar::Twix; use Log::Log4perl qw(get_logger); sub eat { # Gets a Bar::Twix logger my $logger = get_logger(); $logger->debug(“Debug Message”); } #l4p.conf 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::SimpleLayout

  22. Categories (Easy Mode) package Bar::Twix; use Log::Log4perl qw(:easy); sub eat { # Has a Bar::Twix logger DEBUG “Debug Message”; } #l4p.conf 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::SimpleLayout

  23. Loggers • Have a • category (e.g. “Net::Amazon” ) • priority (e.g. $DEBUG ) • Take a message (e.g. “Starting” )

  24. Loggers • Pass on their message if • logging has been configured for • their category ( “Net::Amazon”) or • a parent category ( “Net”, “” ) • and (!) the message priority (e.g. $DEBUG) is greater or equal than the configured log level (e.g. $DEBUG) for the category

  25. Limit Throughput: Levels and Categories • Categoriesdetermine which parts of the system are addressed. my $log = get_logger(“Net::Amazon”); or simply package Net::Amazon; DEBUG “…”; • Levelsindicate the message priority. $log->debug(“Request sent ($bytes bytes)”;

  26. Log Levels • Levels • $TRACE • $DEBUG • $INFO • $WARN • $ERROR • $FATAL • $OFF

  27. Log Levels • Methods • $log->trace(“$bytes bytes transferred”); • $log->debug(“HTTP get OK”); • $log->info(“Starting up”); • $log->warn(“HTTP get failed, retrying”); • $log->error(“Out of retries!”); • $log->fatal(“Panic! Shutting down.”);

  28. Log Levels • Macros • TRACE(“$bytes bytes transferred”); • DEBUG(“HTTP get OK”); • INFO(“Starting up”); • WARN(“HTTP get failed, retrying”); • ERROR(“Out of retries!”); • FATAL(“Panic! Shutting down.”);

  29. Remote Control via Categories l4p.conf log4perl.category = DEBUG, Screen #!/usr/bin/perl use Net::Amazon; Log::Log4perl->init(“l4p.conf”); DEBUG “Makes it through!” my $amzn = Net::Amazon->new(); package Net::Amazon; ERROR “Makes it through!”; DEBUG “Makes it through”;

  30. Remote Control via Categories l4p.conf Log4perl.category = ERROR, Screen #!/usr/bin/perl use Net::Amazon; Log::Log4perl->init(“l4p.conf”); DEBUG “Gets blocked!” my $amzn = Net::Amazon->new(); package Net::Amazon; ERROR “Makes it through!”; DEBUG “Gets blocked”;

  31. Remote Control via Categories l4p.conf Log4perl.category = FATAL, Screen #!/usr/bin/perl use Net::Amazon; Log::Log4perl->init(“l4p.conf”); DEBUG “Gets blocked!” my $amzn = Net::Amazon->new(); package Net::Amazon; ERROR “Gets blocked!”; DEBUG “Gets blocked”;

  32. Remote Control via Categories l4p.conf Log4perl.category.main = DEBUG, Screen Log4perl.category.Net.Amazon = ERROR, Screen #!/usr/bin/perl use Net::Amazon; Log::Log4perl->init(“l4p.conf”); DEBUG “Makes it through!” my $amzn = Net::Amazon->new(); package Net::Amazon; ERROR “Makes it through!”; DEBUG “Gets blocked”;

  33. Remote Control via Categories l4p.conf Log4perl.category.main = ERROR, Screen Log4perl.category.Net.Amazon = DEBUG, Screen #!/usr/bin/perl use Net::Amazon; Log::Log4perl->init(“l4p.conf”); DEBUG “Gets blocked”; my $amzn = Net::Amazon->new(); package Net::Amazon; ERROR “Makes it through!”; DEBUG “Makes it through!”;

  34. Category Inheritance (1) l4p.conf Log4perl.category.main = DEBUG, Screen Log4perl.category.Net = ERROR, Screen #!/usr/bin/perl use Net::Amazon; Log::Log4perl->init(“l4p.conf”); DEBUG “Makes it through!” my $amzn = Net::Amazon->new(); package Net::Amazon; ERROR “Makes it through!”; DEBUG “Gets blocked”;

  35. Category Inheritance (2) l4p.conf Log4perl.category.main = DEBUG, Screen Log4perl.category = ERROR, Screen #!/usr/bin/perl use Net::Amazon; Log::Log4perl->init(“l4p.conf”); DEBUG “Makes it through!” my $amzn = Net::Amazon->new(); package Net::Amazon; ERROR “Makes it through!”; DEBUG “Gets blocked”;

  36. Appender Appender Appender Log4perl Flow Application sends a log message (Category, Priority) Log4perl Configuration decides go/no go, based on Category and Priority ? Layout

  37. l4p.conf: Screen Appender log4perl.category.main = DEBUG, ScreenLog4perl.category.Net.Amazon = INFO, Screen log4perl.appender.Screen = \ Log::Log4perl::Appender::Screen …

  38. l4p.conf: File Appender log4perl.category.main = DEBUG, Logfile Log4perl.category.Net.Amazon = INFO, Logfile log4perl.appender.Logfile = \ Log::Log4perl::Appender::File log4perl.appender.Logfile.filename = test.log …

  39. l4p.conf: Two appenders log4perl.category.main = DEBUG, Logfile Log4perl.category.Net.Amazon = INFO, Screen log4perl.appender.Logfile = \ Log::Log4perl::Appender::File log4perl.appender.Logfile.filename = test.log log4perl.appender.Screen = \ Log::Log4perl::Appender::Screen …

  40. Init and Watch • Log::Log4perl->init(“l4p.conf”); • Log::Log4perl->init(\$conf_string); • Log::Log4perl->init_and_watch(“l4p.conf”, 30); • Log::Log4perl->init_and_watch(“l4p.conf”, ‘HUP’ );

  41. Demo

  42. Appenders • Appenders are output sinks • Get called if a message passes category and level hurdles

  43. Appenders • Log::Log4perl::Appender::Screen Log::Log4perl::Appender::File Log::Log4perl::Appender::Socket Log::Log4perl::Appender::DBI Log::Log4perl::Appender::Synchronized Log::Log4perl::Appender::RRDs • Log::Dispatch provides even more:

  44. Log::Dispatch Appenders • Log::Dispatch::ApacheLog Log::Dispatch::DBI, Log::Dispatch::Email, Log::Dispatch::Email::MIMELite Log::Dispatch::File Log::Dispatch::FileRotate Log::Dispatch::Screen Log::Dispatch::Syslog, Log::Dispatch::Tk

  45. Example: Rotating Log File Appender • Keep 5 days of logfiles, then delete: log4perl.category = WARN, Logfile log4perl.appender.Logfile = Log::Dispatch::FileRotate log4perl.appender.Logfile.filename = test.log log4perl.appender.Logfile.max = 5 log4perl.appender.Logfile.DatePattern = yyyy-MM-dd log4perl.appender.Logfile.TZ = PST log4perl.appender.Logfile.layout = \ Log::Log4perl::Layout::SimpleLayout

  46. Rotating Files • Rotating File Appender: • Log::Dispatch::FileRotate • Single request pays for rotation • Rotation runs as particular user • External Rotators (e.g. newsyslog): • recreate flag makes sure file appender adjusts • recreate_check_interval saves on stat() calls

  47. Write Your Own Appender (1) package ColorScreenAppender; our @ISA = qw(Log::Log4perl::Appender); use Term::ANSIColor; sub new { my($class, %options) = @_; my $self = {%options, …}; bless $self, $class; } sub log { my($self, %params) = @_; print colored($params{message}, $self->{color}); }

  48. Write Your Own Appender (2) log4perl.logger = INFO, ColorApp log4perl.appender.ColorApp=ColorScreenAppender log4perl.appender.ColorApp.color = red log4perl.appender.ColorApp.layout = SimpleLayout

  49. Layouts • SimpleLayout $log->debug(“Sending Mail”); DEBUG – Sending Mail log4perl.appender.Screen = \ Log::Log4perl::Appender::Screen log4perl.appender.Screen.layout = SimpleLayout

  50. Layouts • PatternLayout $log->debug(“Sending Mail”); 2004/10/17 18:47:25 l4ptest.pl:25> Sending Mail log4perl.appender.Logfile.layout = \ Log::Log4perl::Layout::PatternLayout log4perl.appender.Logfile.layout.ConversionPattern = \ %d %F{1}:%L> %m %n

More Related