Application logging

METAMOD logs events that happen in the system. The logging of these events can be used for IT operations and for simplifying development.

To provide scalable and standardised logging, METAMOD uses the Log::Log4perl framework in Perl code and the log4php framework in PHP code. Both of these frameworks are ports of the log4j logging framework for Java.

It is important to understand how the log4p* frameworks work before you start using them. In particular it is important to understand how categories, levels and appenders work. This article gives a good introduction to the central concepts of the frameworks: http://www.perl.com/pub/a/2002/09/11/log4perl.html

Perl:

#There are three possbilities for initialising the logger
 
# 1. Initialise it at compile time like this. This method assumes the use of the default master_config.txt file
use Metamod::Config qw(:init_logger);
 
# 2. Use the Metamod::Config object
use Metamod::Config;
my $config = Metamod::Config->new();
$config->initLogger(); 
 
# 3. Use the static class function
use Metamod::Config;
Metamod::Config::staticInitLogger($path_to_master_config); # or Metamod::Config::staticInitLogger();
 
#after initialisation
use Log::Log4perl qw(get_logger); #this line can be before init as well
 
my $logger = get_logger($category);
$logger->error("something wrong just happend\n"); # remember \n

PHP:

<?php
  # There are three possible ways to initialise the logger

  # 1. Initialise the default config
  require_once("../funcs/mmConfig.inc");
 
  $mmConfig->initLogger(); # $mmConfig is created when mmConfig.inc is parsed
 
  # 2. Initialise using a different config
  require_once("../funcs/mmConfig.inc"); 
  $otherConfig = new MMConfig($path_to_other_config);
  $otherConfig->initLogger();
 
  # 3. Initialise using a static function that is basically option 2. reduced to one statement
  require_once("../funcs/mmConfig.inc"); 
  $otherConfig = MMConfig::getInstanceWithLogger();
 
  # after the logger is initialised you can do this
  # Note that you don't need to include the log4php library as that has already been done 
  $logger = Logger::getLogger( $category );
  $logger->info( 'Loggmelding' );    
 
?>

Log::Log4perl and log4php is configured using configuration files. The configuration files used to by the two frameworks are similar to each other, but not identical. For this reason METAMOD uses one or more “meta” configuration files that contains the configuration for both frameworks. The meta configuration is parsed by the script update_logger_config.pl that will create log4php_config.ini and log4perl_config.ini.

The meta configuration contains lines that start with either log4all, log4php or log4perl. All lines starting with log4all will inserted in the configuration for both PHP and Perl. The log4php and log4perl lines will only be inserted into the configuration file for the respective framework.

To make logging setup simple, METAMOD contains a default logging configuration that will be read by update_logger_config.pl. This will configure the root logger in the system. In addition you can specify additional configuration files to update_logger_config.pl that will also end up in the generated configuration files. A typical use of these additional configuration files is to add debug output in some part of the application.

See the documentation of update_logger_config.pl for exact usage of the script.

The following will log debug messages for the metamod.search logger for Perl. Note that we take to care to not send the debug message to the root logger.

log4perl.logger.metamod.search=DEBUG, SEARCH_LOGGER
# prevent garbage from reaching the root logger
log4perl.additivity.metamod.search=0
log4perl.appender.SEARCH_LOGGER=Log::Log4perl::Appender::File
log4perl.appender.SEARCH_LOGGER.filename = /some/file
log4perl.appender.SEARCH_LOGGER.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.SEARCH_LOGGER.layout.ConversionPattern=%F on line: %L msg: %m%n

The following configuration will send all log messages to the screen.

log4perl.rootLogger=DEBUG, SCREEN
log4perl.appender.SCREEN=Log::Log4perl::Appender::Screen
log4perl.appender.SCREEN.stderr = 1
log4perl.appender.SCREEN.layout=Log::Log4perl::Layout::PatternLayout
log4perl.appender.SCREEN.layout.ConversionPattern=[%p] %c %m in %F at line %L%n

METAMOD uses the following log levels with the following definition.

• FATAL: requires instant human assistance (IT operations). For instance full disks, lack of connection to database servers, file servers or LDAP.
• ERROR: serious error, but isolated to current task/request. Does not affect entire METAMOD instance. IT operations should be notified.
  • Exceptions, even if caught later
• WARNING: Might be an error, but not necessarily. Should be looked at to see if it is an actual problem.
  • milder Exceptions, usually caught
• INFO: Used to track main application use in production:
  • tracking user
    • log in
    • log out
    • generate/update directories
  • tracking of data:
    • uploads (ftp/http (which user?))
    • moving
    • deletion
  • tracking of metadata
    • source (ncdigest, harvest), ownertag
    • installing/changing xml-files
    • changes of xmd-metadata (which user?)
    • uploading to search-database(s)
  • other statistics?
• DEBUG: Free to be used by the developers as they see fit during development. DEBUG logging should rarely be used in production.

METAMOD uses the following categories for log messages. The categories correspond with the main parts of the application.

• metamod
  • search
  • harvest
  • oai-pmh
  • upload
  • base
  • adm
  • common

In log4php each level in the logger hierarchy is separated using dots. Example: metamod.search.

In Log::Log4perl each level in the hierarchy is separeted using double colons. Example: metamod::search.

By default METAMOD uses two appenders. One for logging just FATAL and ERROR messages and one for logging all messages in the same file.

The following configuration variables in the METAMOD configuration file is used to configure the logging.

• LOG4PERL_CONFIG: The configuration file used to configure Log::Log4perl
• LOG4PERL_WATCH_TIME: The number of seconds between each time Log::Log4perl should check for changes to the log configuration.
• LOG4PHP_CONFIG: The configuration file used to configure log4php.
• LOG4ALL_SYSTEM_LOG: The file that the root logger will log to.

The configuration files will be watched for changes so it is possible to change the logging configuration at runtime without restarting the application. This is for instance useful for turning on debugging in a production system.

The monitoring of logs is the responsibility of IT operations and is not implemented by METAMOD it self.