[Koha-devel] [RFC] Using Log4perl to extend and improve logging and debugging
Andrew Moore
andrew.moore at liblime.com
Fri Aug 29 23:34:06 CEST 2008
NOTE: This is an RFC patch. I don't expect it to be directly applied
to your system, and please don't apply it to the main Koha repository!
Here is an example of how we can use Log4perl to extend (and hopefully
improve) our current logging methods. I'm hopeful that this does a
few things for us:
* This will help us separate our application errors from apache
errors by letting us easily redirect our errors to other files.
* This will help us debug things by letting us increase the level of
warnings from some parts of the application while ignoring other
parts. Since you can configure it to handle messages from different parts
of your application differently, you can inspect only certain parts
more closely. For instance, if you would like to log more
information about all opac seraches in order to let you investigate
that more closely, you can edit the configuration file to write all
of those types of messages to a different file.
* This will let us separate out debugging types of messages from error
messages. I would like for Koha to tell me of rather important
errors that should be investigated differently from how it tells me
of debugging messages. You can configure really bad ones to go to
email to your support team, and the rather mundane to be written to
a file.
* and maybe more!
I've included a few examples in this patch. One is in C4::Members
where I instantiate a Log4perl object and use it to record some
information when a function is called. The object knows that it's in
the C4::Members "category", so you can handle that information
differently in the log4perl configuration file if you like.
Another is a use from one of the opac scripts, opac-search.pl. It
shows how you might log search queries to a separate place.
Since we have a lot of calls to 'warn' scattered about our code, I
incuded a __WARN__ handler in C4::Debug that catches all calls to warn
and runs them through log4perl. Ideally, this is not necessary, but
it's a way for us to transition to using log4perl from the state we're
in now.
Finally, I've included an example configuration file that shows how
you might separate out messages from different parts of your
application into different places. You can also send these messages
through email, syslog, or other files.
I'm interested in discussion about whether extending the way we do
logging is necessary yet, and if so if this seems like a good
direction. I know that this can be improved and doesn't solve all of
our problems, so please let me know how you might improve this
approach, or of another one you would prefer.
---
C4/Debug.pm | 49 +++++++++++++++++++++++++++++++++++++++++++++----
C4/Members.pm | 13 +++++++++++++
log4perl.conf | 38 ++++++++++++++++++++++++++++++++++++++
opac/opac-search.pl | 5 +++++
4 files changed, 101 insertions(+), 4 deletions(-)
create mode 100644 log4perl.conf
diff --git a/C4/Debug.pm b/C4/Debug.pm
index 357764a..f54df40 100644
--- a/C4/Debug.pm
+++ b/C4/Debug.pm
@@ -21,6 +21,7 @@ use strict;
use warnings;
use Exporter;
+use Log::Log4perl qw(:easy);
# use CGI;
use vars qw($VERSION @ISA @EXPORT $debug $cgi_debug);
@@ -34,6 +35,22 @@ BEGIN {
# %EXPORT_TAGS = ( all=>[qw($debug $cgi_debug)], );
}
+=head2 BEGIN block for log4perl
+
+Log4perl is initialzed in a BEGIN block to make sure it's available
+for other BEGIN blocks.
+
+Perhaps it's not necessary to have this in a BEGIN block in the final
+code.
+
+The config file is hardcoded right now. That's not necessary.
+
+=cut
+
+BEGIN {
+ Log::Log4perl->init( '/home/acm/koha/dev/log4perl.conf' );
+}
+
BEGIN {
# this stuff needs a begin block too, since dependencies might alter their compilations
# for example, adding DataDumper
@@ -65,10 +82,34 @@ BEGIN {
}
}
-# sub import {
-# print STDERR __PACKAGE__ . " (Debug) import @_\n";
-# C4::Debug->export_to_level(1, @_);
-# }
+=head2 __WARN__ handler
+
+this overrides calls to C<warn> so that they don't get written to
+STDOUT, but instead get run through Log4perl
+
+=cut
+
+$SIG{__WARN__} = sub {
+ local $Log::Log4perl::caller_depth = $Log::Log4perl::caller_depth + 1;
+ my $logger = logger();
+ $logger->warn( @_ );
+};
+
+=head2 logger
+
+this function returns a logging object. It's not strictly necessary
+since you can call many of the Log4perl methods as class methods just
+fine. But, it shows one example of how we can set the logger category
+to make the messages wind be treated differently based on whether they
+are in the opac or staff interface.
+
+=cut
+
+sub logger {
+ my $class = shift;
+ my $log_category = shift || 'opac';
+ my $logger = Log::Log4perl->get_logger($log_category);
+}
1;
__END__
diff --git a/C4/Members.pm b/C4/Members.pm
index 7df9424..fde3001 100644
--- a/C4/Members.pm
+++ b/C4/Members.pm
@@ -31,6 +31,12 @@ use C4::Biblio;
our ($VERSION, at ISA, at EXPORT, at EXPORT_OK,$debug);
+# initialize a log4perl object to be used throughout this module. We
+# give it a category of C4::Members. This lets us call methods on it
+# with the logging separated out into different places from the rest
+# of the application, if we want.
+our $logger = Log::Log4perl->get_logger( __PACKAGE__ );
+
BEGIN {
$VERSION = 3.02;
$debug = $ENV{DEBUG} || 0;
@@ -2060,6 +2066,13 @@ sub DebarMember {
return unless defined $borrowernumber;
return unless $borrowernumber =~ /^\d+$/;
+ # Here's an example of using the logger object. You can call
+ # 'debug' 'info', 'warn', 'error', or 'fatal' on it to send
+ # messages with different levels of priority. They may get treated
+ # differently (or ignored entirely) depending on your
+ # configuration.
+ $logger->info( "debarring borrower $borrowernumber" );
+
return ModMember( borrowernumber => $borrowernumber,
debarred => 1 );
diff --git a/log4perl.conf b/log4perl.conf
new file mode 100644
index 0000000..de90960
--- /dev/null
+++ b/log4perl.conf
@@ -0,0 +1,38 @@
+# Where do we write the log files?
+# Eventually, this will use a __VARIABLE__ so that the installer writes the right value in at install time.
+log_file_root = /home/acm/koha/run/var/log
+
+# by default all log information can go to a default file, but only at ERROR level (or more severe)
+log4perl.logger = ERROR, FileAppenderDefault
+
+log4perl.appender.FileAppenderDefault = Log::Log4perl::Appender::File
+log4perl.appender.FileAppenderDefault.filename = ${log_file_root}/koha.log
+log4perl.appender.FileAppenderDefault.layout = Log::Log4perl::Layout::SimpleLayout
+
+# opac activity can be directed to a separate file
+log4perl.logger.opac = WARN, FileAppenderOpac
+
+log4perl.appender.FileAppenderOpac = Log::Log4perl::Appender::File
+log4perl.appender.FileAppenderOpac.filename = ${log_file_root}/koha-opac.log
+log4perl.appender.FileAppenderOpac.layout = Log::Log4perl::Layout::SimpleLayout
+
+# staff interface activity
+log4perl.logger.staff = WARN, FileAppenderStaff
+
+log4perl.appender.FileAppenderStaff = Log::Log4perl::Appender::File
+log4perl.appender.FileAppenderStaff.filename = ${log_file_root}/koha-staff.log
+log4perl.appender.FileAppenderStaff.layout = Log::Log4perl::Layout::SimpleLayout
+
+# cronjobs and other activity may be directed to another file or handler
+log4perl.logger.cron = WARN, FileAppenderCron
+
+log4perl.appender.FileAppenderCron = Log::Log4perl::Appender::File
+log4perl.appender.FileAppenderCron.filename = ${log_file_root}/koha-cron.log
+log4perl.appender.FileAppenderCron.layout = Log::Log4perl::Layout::SimpleLayout
+
+# In order to facilitate debugging OPAC search, perhaps we want log them at DEBUG level to the same OPAC file.
+log4perl.logger.opac.search = DEBUG, FileAppenderOpac
+
+# Or, maybe right now we don't want to log any search strings because they're annoying while we're researching something else.
+# log4perl.logger.opac.search = OFF, FileAppenderOpac
+
diff --git a/opac/opac-search.pl b/opac/opac-search.pl
index 5f50861..2aa0be8 100755
--- a/opac/opac-search.pl
+++ b/opac/opac-search.pl
@@ -45,6 +45,11 @@ elsif ($build_grouped_results) {
}
elsif ((@params>=1) || ($cgi->param("q")) || ($cgi->param('multibranchlimit')) || ($cgi->param('limit-yr')) ) {
$template_name = 'opac-results.tmpl';
+
+ # In this example, we're trying to log each search query. Since I want to be
+ # able to separate them apart from other logging, let's give them a different log
+ # category. And, it's pretty verbose, so let's send them at the "debug" level.
+ C4::Debug->logger('opac.search')->debug( 'searched for: ' . $cgi->param('q') );
}
else {
$template_name = 'opac-advsearch.tmpl';
--
1.5.6
More information about the Koha-devel
mailing list