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,@ISA,@EXPORT,@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