Mit Log::Log4perl lassen sich Log-Anweisungen in Programme einbauen und schlafen legen. Meldet eine externe Konfigurationsdatei Bedarf an, erwachen die Schläfer und zeigen an, was das Programm so treibt, ohne dass man deswegen den Code ändern muss.
Log::Log4perl ist ein Perl-Port des aus der Java-Welt stammenden log4j-Systems, das auf drei Säulen steht: Logger lösen Lognachrichten aus, Prioritäten bestimmen, ob sie durchkommen und Appender leiten sie dann an konfigurierte Ausgabemedien weiter.
Prioritäten steuern, ob ein Logger die ihm übergebenen Nachrichten tatsächlich rausschreibt oder unterdrückt. Log::Log4perl bietet 5 Prioritäten: DEBUG, INFO, WARN, ERROR und FATAL. Sagt die Zentrale: ``Ich will nur Nachrichten der Priorität ERROR und höher sehen'', sorgt Log::Log4perl dafür, dass mit DEBUG, INFO oder WARN geloggte Nachrichten gar nicht erst auftauchen. Sie stehen zwar im Code, werden aber zur Laufzeit unterdrückt.
Logger gehören Kategorien an, die typischerweise nach der Klasse
benannt sind, in der sie ihre Dienste anbieten. Die Klasse Riegel::Twix
wird typischerweise eine Instanz des Loggers der Kategorie Riegel.Twix
nutzen.
Der Knüller: Alle Logger eines Systems (die wahrscheinlich in dutzenden von
verschiedenen Klassen liegen und demnach dutzenden von verschiedenen
Kategorien angehören) lassen sich von einer zentralen Stelle ansprechen
und fernsteuern. Treten Probleme in Riegel::Twix auf, muss nicht das
ganze System in den DEBUG-Modus geschaltet werden -- es reicht, detailliertes
Logging in der Kategorie Riegel anzuwerfen -- entsprechend springen die
Logger der Kategorien
Riegel und Riegel.Twix an. Dazu muss man nicht etwa den Code
ändern -- typischerweise reicht es, eine zentrale Konfigurationsdatei
anzupassen.
Das Tutorial auf [2] zeigt die Anwendung von Log::Log4perl im Detail. Heute wollen wir einmal ``Loggen für Faule'' durchnehmen -- alle Vorzüge von Log4perl ohne viel Aufwand.
Listing Building.pm zeigt eine typische Perl-Anwendung: Zwei Klassen,
die die Temperatur eines Atomkraftwerks regeln und in einer Wohnung
den Fernseher an- und ausschalten. Die Methoden sind gespickt mit
Logging-Anweisungen: DEBUG(), INFO(), ERROR() sind alles Funktionen
aus Log::Log4perl :easy-Fundus, die alle zunächst inaktiv sind.
Die Basisklasse Building definiert den Konstruktor new(), den
die abgeleiteten Klassen einfach erben. Die Klasse
Building::NuclearPowerPlant abstrahiert ein Atomkraftwerk mit den
Methoden temperature() zum Setzen und Abfragen der Reaktortemperatur
und is_ok() zur Prüfung, ob noch alles im grünen Bereich läuft.
Die Klasse Building::Residential ahmt ein Privathaus nach und
ist von der Basisklasse Building abgeleitet. Die Methode
tv("on"|"off") schaltet den Fernseher im Wohnzimmer an und aus.
Alle drei Klassen ziehen jeweils (!) Log::Log4perl qw(:easy) herein, um
hinter den Kulissen Default-Logger zu erzeugen, die einfach auf die
Kategorie des jeweiligen Klassennamens hören. Die ebenfalls
so exportierten Funktionen DEBUG(), INFO(), ERROR() etc.
gelangen ebenfalls über das :easy-Tag in den Namensraum der
jeweiligen Klasse.
01 #!/usr/bin/perl
02 ###########################################
03 # Mike Schilli, 2002 (m@perlmeister.com)
04 ###########################################
05 use warnings;
06 use strict;
07
08 ###########################################
09 package Building;
10 ###########################################
11 use Log::Log4perl qw(:easy);
12 sub new {
13 my($class) = @_;
14 DEBUG("Create new $class");
15 bless {}, $class;
16 }
17
18 ###########################################
19 package Building::NuclearPowerPlant;
20 ###########################################
21 use Log::Log4perl qw(:easy);
22 our @ISA = qw(Building);
23
24 ###########################################
25 sub temperature {
26 my($self, $temp) = @_;
27
28 if(defined $temp) {
29 DEBUG("Set temperature to $temp");
30 $self->{temp} = $temp;
31 $self->is_ok();
32 }
33
34 return $self->{temp};
35 }
36
37 ###########################################
38 sub is_ok {
39 my($self) = @_;
40 if(defined $self->{temp} and
41 $self->{temp} > 100) {
42 ERROR("I'm exploding!");
43 return 0;
44 }
45 INFO("OK");
46 return 1;
47 }
48
49 ###########################################
50 package Building::Residential;
51 ###########################################
52 use Log::Log4perl qw(:easy);
53 our @ISA = qw(Building);
54
55 ###########################################
56 sub tv {
57 my($self, $action) = @_;
58
59 if(defined $action) {
60 DEBUG("Set tv to $action");
61 $self->{tv} = $action;
62 }
63
64 INFO("TV is $self->{tv}");
65 return $self->{tv};
66 }
67
68 1;
Listing building.pl zeigt ein Skript, das die Klassen verwendet. Auf der
Kommandozeile nimmt es optional ein Argument entgegen, das die
Log4perl-Konfigurationsdatei bestimmt. Im Format von Java-Properties-Dateien
lässt sich Log4perl so bequem von außen fernsteuern. Findet building.pl
allerdings keine Angabe, wird Log::Log4perl nicht initialisiert, was
im :easy-Modus seit Log::Log4perl 0.25 einfach alle Log-Anweisungen
schlafen legt.
01 #!/usr/bin/perl
02 ###########################################
03 # Mike Schilli, 2002 (m@perlmeister.com)
04 ###########################################
05 use warnings;
06 use strict;
07
08 use Building;
09 use Log::Log4perl qw(:easy);
10
11 if($ARGV[0]) {
12 Log::Log4perl->init($ARGV[0]);
13 }
14
15 my $plant = Building::NuclearPowerPlant->new();
16 my $home = Building::Residential->new();
17
18 # Switch TV on
19 $home->tv("on");
20 # Overheat nuklear power plant
21 $plant->temperature(200);
Von der Kommandozeile ohne Argument aufgerufen, erledigt building.pl zwar seine
Aufgaben, zeigt aber nichts an:
$ building.pl
$
Interessiert hingegen, was so im Einzelnen abgeht, empfiehlt es sich,
eine Log4perl-Konfigurationsdatei nach info.conf anzulegen.
log4perl.category.Building = INFO, Screen log4perl.appender.Screen = Log::Dispatch::Screen log4perl.appender.Screen.layout = PatternLayout log4perl.appender.Screen.layout.ConversionPattern = %d [%c]: %m%n
info.conf bestimmt, dass die Logger in der Kategorie Building
und in allen ihrer Unterklassen
(also im Beispiel die in Building, Building::Residential und
Building::NuclearPowerPlant verwendeten Logger)
zu schreiben beginnen, und zwar nur
Nachrichten mit mindestens der Priorität INFO.
Der Appender Screen ist vom Typ Log::Dispatch::Screen und leitet
einfach alle durchgelassenen Nachrichten nach STDERR weiter.
Das PatternLayout legt mit
%d [%c]: %m%n
fest, dass jeder Nachricht (%m) zuerst das aktuelle Datum (%d) und die
Logger-Kategorie (%c) vorangeht, während stets ein Zeilenumbruch (%n) nachfolgt.
Hier ist die Ausgabe des Programms building.pl (nach STDERR) nachdem es mit dem
Parameter info.conf aufgerufen wurde:
2002/10/05 21:36:50 [Building.Residential]: TV is on
2002/10/05 21:36:50 [Building.NuclearPowerPlant]: I'm exploding!
Die DEBUG-Nachrichten werden, wie man sieht, unterdrückt.
Hiesse Zeile 1 in info.conf hingegen
1 log4perl.category.Building = DEBUG, Screen
kämen auch sie durch:
2002/10/06 15:11:13 [Building]: Create new Building::NuclearPowerPlant
2002/10/06 15:11:13 [Building]: Create new Building::Residential
2002/10/06 15:11:13 [Building.Residential]: Set tv to on
2002/10/06 15:11:13 [Building.Residential]: TV is on
2002/10/06 15:11:13 [Building.NuclearPowerPlant]: Set temperature to 200
2002/10/06 15:11:13 [Building.NuclearPowerPlant]: I'm exploding!
Wem diese Ausgabe zu geschwätzig ist und lieber nur Nachrichten
aus dem Atomkraftwerk empfangen möchte, fährt besser mit einer
Konfigurationsdatei wie in Listing nukeonly.conf gezeigt:
building.pl nukeonly.conf
zeigt Meldungen aller Prioritäten, aber nur beschränkt auf
die Kategorie Building.NuclearPowerPlant:
2002/10/05 21:36:51> Set temperature to 200
2002/10/05 21:36:51> I'm exploding!
1 log4perl.category.Building.NuclearPowerPlant = DEBUG, Screen
2 log4perl.appender.Screen = Log::Dispatch::Screen
3 log4perl.appender.Screen.stderr = 0
4 log4perl.appender.Screen.layout = PatternLayout
5 log4perl.appender.Screen.layout.ConversionPattern = %d> %m%n
Hier zeigt sich auch die Beschränkung des :easy-Ansatzes, der einfach
annimmt, dass die Kategorie des gerade verwendeten Loggers gleichzusetzen
wäre mit dem aktuellen Package -- was sich allerdings anhand der
ererbten new-Methode
in den Building::*-Subklassen als falsch herausstellt:
Statt eines Building-Loggers sollte der Konstruktor einen Logger der
Kategorie der gerade konstruierten Subklasse verwenden, was folgender
Konstruktor richtig tut:
sub new {
my($class) = @_;
my $logger = get_logger($class);
$logger->debug("Create new $class");
bless {}, $class;
}
Dann stimmt auch die Ausgabe im vererbten Konstruktor:
2002/10/06 15:14:14> Create new Building::NuclearPowerPlant
2002/10/06 15:14:14> Set temperature to 200
2002/10/06 15:14:14> I'm exploding!
Immer nur auf STDERR auszugeben, mag vielleicht für Kommandozeilenskripts noch angehen. Im Hintergrund laufende Dämonen sollten allerdings in eine Logdatei schreiben, in eine Datenbank loggen oder Emails aussenden. Dies alles und mehr unterstützt Log::Log4perl -- natürlich nur mit Konfigurationsparametern, der Code der Applikation bleibt weiterhin unangetastet.
1 log4perl.category = ERROR, File
2 log4perl.appender.File = Log::Dispatch::File
3 log4perl.appender.File.filename = test.log
4 log4perl.appender.File.layout = PatternLayout
5 log4perl.appender.File.layout.ConversionPattern = %d %F %L %p> %m%n
Nehmen wir an, die Applikation soll ab sofort ihre ERROR-Nachrichten aller
Kategorien in eine Logdatei test.log senden. Listing err2file.conf zeigt
die entsprechende Konfiguration. Einfach
building.pl err2file.conf
aufrufen und schon findet sich folgende Nachricht in test.log ein:
2002/10/08 22:29:30 Building.pm 42 ERROR> I'm exploding!
err2file.conf definiert mit
log4perl.category = ERROR, File
in der ersten Zeile einfach die Root-Kategorie, die Mutter aller anderen
Kategorien, von denen dann alle anderen automatisch erben.
Das Layout-Pattern %d %F %L %p> %m%n schreibt nach dem Datum den
Dateinamen des Perl-Moduls (%F), die Zeilennummer des Logging-Aufrufs (%L)
und die Priorität (%p) des Vorfalls.
Spielt nun Building::Residential verrückt und wir brauchen die
DEBUG-Meldungen daraus auf STDERR, ohne die Ausgabe der ERROR-Meldungen
nach test.log zu unterbrechen, erweitern wir die Konfigurationsdatei
einfach um vier Zeilen, wie in Listing err2file2.conf gezeigt.
01 log4perl.category.Building.Residential = DEBUG, Screen
02 log4perl.appender.Screen = Log::Dispatch::Screen
03 log4perl.appender.Screen.layout = PatternLayout
04 log4perl.appender.Screen.layout.ConversionPattern = %d [%c]: %m%n
05
06 log4perl.category = ERROR, File
07 log4perl.appender.File = Log::Dispatch::File
08 log4perl.appender.File.filename = test.log
09 log4perl.appender.File.layout = PatternLayout
10 log4perl.appender.File.layout.ConversionPattern = %d %F %L %p> %m%n
11 log4perl.appender.File.Threshold = ERROR
Der Aufruf
./building.pl err2file2.conf
schreibt
2002/10/05 21:36:38 [Building.Residential]: Set tv to on
2002/10/05 21:36:38 [Building.Residential]: TV is on
nach STDERR und weiterhin die oben gezeigte Ausgabe nach test.log.
Die letzte Zeile in err2file2.conf ist wichtig, denn Log::Log4perl
unterstützt, wie in der Dokumentation auf [3]
unter ``Beginner's Pitfalls'' illustriert,
Appendervererbung: Beschließt ein Logger in Building.Residential
einmal, seinen Appender feuern zu lassen, blubbert die Nachricht die
Appenderhierarchie hoch und wird bedingungslos von allen angeschlossenen
Appendern übernommen -- im vorliegenden Fall landeten die DEBUG-Nachrichten
aus Building::Residential allesamt im Root-Logger. Um dies zu verhindern
setzt die letzte Zeile in err2file2.conf den Appender-Threshold des
Logdatei-Appenders auf ERROR, damit die DEBUG-Nachrichten in letzter
Sekunde geblockt werden.
Wichtige Ereignisse sollte man nicht in einer Logdatei verstauben lassen,
sondern schnell an Interessierte weiterleiten. Explodiert das Atomkraftwerk,
soll die Applikation sofort eine Email mit einer Warnung schicken.
Auch dies geht natürlich, ohne in den Applikationscode einzugreifen,
Listing mailerrors.conf zeigt die Konfigurationsdatei. Der Aufruf
building.pl mailerrors.conf
schickt die in Abbildung 1 gezeigte Email and den entsetzten Adressaten.
1 log4perl.category.Building.NuclearPowerPlant = ERROR, Mailer
2 log4perl.appender.Mailer = Log::Dispatch::Email::MailSend
3 log4perl.appender.Mailer.to = l4ptest@perlmeister.com
4 log4perl.appender.Mailer.subject = Problem im Atomkraftwerk!
5 log4perl.appender.Mailer.layout = PatternLayout
6 log4perl.appender.Mailer.layout.ConversionPattern = %d %F %L> %m%n
| |
| Abbildung 1: You've got mail! |
Ich hoffe, diese kurze Wirbelwindtour durch Log::Log4perl hat euren Appetit angeregt, dieses neue Modul in euren Applikationen zu verwenden. Es gäbe noch viel zu erzählen -- wie man Datenbanken anspricht, wie man eigene Appender schreibt, und auch noch das ein oder andere Rezept für Log::Log4perl. Das Tutorial auf [2], die Manualseiten auf [3] und die log4j-Dokumentation auf [4] sollten euren größten Hunger stillen. Für mehr gibt's die Mailingliste auf [3], auf der sich euer Perl-Onkel gerne eurer Anfragen annimmt. Man sieht sich!
log4perl auf SourceForge:
http://log4perl.sourceforge.net
log4j auf der Apache-Jakarta-Seite:
http://jakarta.apache.org/log4j
 |
Michael Schilliarbeitet als Software-Engineer bei Yahoo! in Sunnyvale, Kalifornien. Er hat "Goto Perl 5" (deutsch) und "Perl Power" (englisch) für Addison-Wesley geschrieben und ist unter mschilli@perlmeister.com zu erreichen. Seine Homepage: http://perlmeister.com. |