Logging

Logging

During development we often add many print statements to check to see how the code is doing, what is happening, what intermediate results there are etc. When done with the development it would be nice to turn this additional code off, but have the ability to quickly turn it back on if we discover a problem. This is where logging comes into play. Logging allows us to use “rules” to say what information should be shown. For example when I am working on the code to create graphs, I do not have to see any debugging information about the SQL command being send, however trying to figure out what goes wrong during a SQL statement it would be nice to show the SQL statements without adding any additional code.

Logging Package

R does provide a basic logging capability using stop, warning and message. These allow to print message (and stop execution in case of stop). However there is not an easy method to redirect the logging information to a file, or turn the logging information on and off. This is where one of the following packages comes into play. The packages themselves are very similar since they try to emulate log4j.

Both of the following packages use a hierarchic loggers, meaning that if you change the level of displayed level of logging at one level all levels below it will update their logging.
h3. logging

The logging development is done at http://logging.r-forge.r-project.org/ and more information is located at http://cran.r-project.org/web/packages/logging/index.html . To install use the following command:

install.packages(“logging”, repos=“http://R-Forge.R-project.org”)

This has my preference pure based on documentation.

futile

The second logging package is http://cran.r-project.org/web/packages/futile.logger/ and is eerily similar to logging (as a matter of fact logging is based on futile).

Example Usage

To be able to use the loggers there needs to be some initialization done. Neither package allows to read it from a configuration file, so we might want to use the pecan.xml file to set it up. The setup will always be somewhat the same:

# load library
library(logging)
logReset()

# add handlers, responsible for actually printing/saving the messages
addHandler(writeToConsole)
addHandler(writeToFile, file="file.log")

# setup root logger with INFO
setLevel('INFO')

# make all of PEcAn print debug messages
setLevel('DEBUG', getLogger('PEcAn'))

# only print info and above for the SQL part of PEcAn
setLevel('INFO', getLogger('PEcAn.SQL'))

To now use logging in the code you can use the following code:

pl <- getLogger(‘PEcAn.MetaAnalysis.function1’)

pl$info(“This is an INFO message.”)

pl$debug(“The value for x=%d’, x)

pl$error(”Something bad happened and I am scared now.“)

or

loginfo(”This is an INFO message.“, logger=‘PEcAn.MetaAnalysis.function1’)

logdebug(”The value for x=%d’, x, logger=‘PEcAn.MetaAnalysis.function1’)

logerror(“Something bad happened and I am scared now.”, logger=‘PEcAn.MetaAnalysis.function1’)

Related Issues

• #1071 How to handle errors?
• #1222 Ignore warnings
  You can use logger.setLevel("ERROR") to only show error messages. All the code that does not use logger will not be filtered.