Expresso Logging

One of the main advantages of linux and other multi user systems is the logging ability. Expresso integrates with Logging standards to create logs, thereby documenting and storing certain system or user activity. This document seeks to describe the logging mechanism used within Expresso. It will cover basic requirements, rationale behind various decisions and a detailed walkthrough of the various logging categories and the purpose of each category.

Expresso Components Listing

Introduction

One of the main advantages of linux and other multi user systems is the logging ability. What is logging exactly? It is merely a process of creating logs, documenting and storing certain system or user activity for various reasons. Entire process and idea of logging probably came from programming, where it was useful to record events, such as program behaviour for further development, and to collect such information for future diagnostic and improvement. Same is with logging on the system level. It is, to say the least, useful to log all activities and events that took place on your system for future analysis. From a security point of view, logging serves as a proof of malicious activity or as an indicator of a potential one.

• Such a logging facility will need to be able to log to multiple targets such as a database, file, socket, etc.
  
• The facility needs to be able to log different types of unforeseen messages.
  
• Various types of logging messages should be able to be turned off and on without having to modify the original source code.

Apache Log4j Integration

Expresso is integrated with the Apache Log4j API. Log4j is an open source project based on the work of many authors. It allows the developer to control which log statements are output with arbitrary granularity. It is fully configurable at runtime using external configuration files. Best of all, log4j has a gentle learning curve.

To achieve these requirements. We have selected the logging system log4j for the following reasons:

• Good hierarchy of categories allows for extremely flexible logging options.
  
• Highly tested and recommended from a wide variety of sources.
  
• Configurable with a single file.
  
• Fast.
  
• Allows for multiple targets for logging.
  
• Large amount of industry support.

The LogManager class is Expresso's interface to the Apache Log4j framework, and is used to set up logging for all applications in a particular environment. When ConfigManager first calls LogManager during system startup, all files with names of the form "*Logging.xml" in the configuration directory are read, and logging channels are then available for each of the channels defined in these files. This allows each application to have it's own seperate logging configuration file, e.g. expressoLogging.xml for Expresso's own internal classes, eForumLogging.xml for eForum, and so forth.

The primary means for monitoring the intranet system is via a log.  All activities run and monitored by Expresso are logged into an HTML server log, accessible via any web browser. This allows the server to be monitored remotely as required, for completely remote system administration and operation. Most tasks are triggered by the application framework, and it writes status notifications, warnings and error messages to the log. Multiple logs can be set up for separate facilities, or one master log can be used for centralized collection of log data. For more information please refer to the Log4j project and the Log4j manual.

Expresso Extensions

To have Log4J fit into Expresso with the best capabilities, there will have to be some additions made other than simply using the straight logging code:

• Categories: Expresso will come predefined with a set of categories that will be useful to both the framework developer, and the framework user. They will include categories such as SQL tracing, ServletRequest Logging, Security Logging, etc. The categories will be detailed later on in this document.
  
• Appenders: Expresso currently does the bulk of its event logging to a database table. As such, a DBAppender needs to be created..
  
• static final traceDebug: A global static final integer will be used to filter out all debug messages. This way, with a single line of source code modified, all debug statements will be optimized out of the source code providing for faster, smaller source code.

Package Organization

All logging operations will be encapsulated within the com.jcorporate.expresso.core.logging package. It needs to be located there instead of within the services subtree because the logging code will be integrated throughout the entire framework and will not be easily separated out. Package organization will be:

• com.jcorporate.expresso.core.logging will contain the global debug switch file, the logging configuration properties file, the static initializer for the logging system, and any othe miscellaneous files that would not fit any of the other subpackages.
  
  
• com.jcorporate.expresso.core.logging.appenders will initially contain the DBAppender as well as any other appenders that may be added at a later time. Examples include an HtmlCommentAppender to dump logs into the servlet output stream, and JMSAppender to dump log activity into a Java Message Queue.

Configuration Mechanism

Log4j supports both properties files and XML configuration files. Due to the potentially complex configuration options of the categories, it is recommended that an XML configuration file be used.

The second configuration mechanism will be the class com.jcorporate.expresso.core.logging.debugLogging which will contain the public static final boolean member variable "debug" Which will be used to turn on/off any references to debug logging. The ExpressoLog class will also contain the factory method to initialize logging throughout the framework at startup time.

Finally, the expresso config file will need to point to a directory where events will be logged to.

Appender Types

DBAppender - This class will provide the functionality to log system events to the database table syslog. It will take care of the appropriate color coding necessary, and will seek to provide the same functionality that currently exists in Expresso Logging.

HTMLCommentAppender - This class will allow for embedding log statements as comments within an html page returned by a servlet. This will assist in rapid debugging and is easily turned off for a secure production envrionment.

SessionAppender - This appender will store the log information into the session. The servlets can have a javascript window open up which calls a servlet that will dump the session log into a web page.

JMSAppender - Expresso J2EE Only This will give the ability of logging to be dumped to a Message Queue Server. This gives the framework secure remote monitoring ability as the JMS messages will be distributed over SSL instead of in the clear. It is recommended that this appender be donated to the log4j initiative to provide better debugging / iterations as time goes on, and this appender is listed in the "TODO" list for upcoming features of log4j anyway.

Available Appenders

This section details the appenders that have been set up in the default configuraiton file. If you wish to change how a category is logged, please check here for names of the default appenders.

Categories

This section is by far the most detailed portion of this document. Categories set up in a tree-like fashion. The overall goal is to provide good grouping by functionality as well as class hierarchy. For each category listed, there will be the following information provided:

Note, the chosen appenders and priorities are only defaults. They may be changed at any time by the configuration file.

• Designation: The distinguished name of the category.
  
• Parent: The distinguished name of the parent category. Within the configuration file, the parent is implied if everything up to the last period equals another category.
  
• Description: The basic description of what this category will cover
  
• Default Appender(s): A list of which appender(s) will be used to log a particular category.
  
• Priority: The default priority level in which this category will trigger a log event Possilble priorities are:
  Error, Warn, Info, Debug

Editorial note for furture revision :TODO: categorize the following logging mechanisms: Startup Logging, Other System Events. Specify the format specifiers for each category.

How to use Expresso Logging

The full log4j documentation may be found here. At first, the number of possibilities for log4j may seem bewildering. However, to use it within your own work with Expresso is quite simple. Here's an example code snippit within your class:

What this code does:

• LogManager.instantiate() - You call this before ever attempting to get a Category instance. The log manager handles loading the logging XML configuration files. If the system is already initialized, the function will return without doing aynthing. You usually set up the Category variable to be a private static attribute that only gets initialized when the object instantiates.
• Category.getInstance() - This function loads the actual "logging category" that you wish to use. What the categories do will depend on the hierarchy set up. You may browse through the WEB-INF/config/expressoLogging.xml file in the config directory to choose which category you wish to use. If a category doesn't exist, then you can create a category that will inherit all the attributes of the parent category by simply adding to the parent category name: Example - Category.getInstance("expresso.ext.controller.download") will create a category that will have "expresso.ext.controller" as a parent and will do everything that expresso.ext.controller will do configuration-wise.
• log.error()/log.warn()/log.info()/log.debug() - These are the gut logging functions. The string they are supposed to log may or may not appear depending on how the logging configuration file is set up. In this case, if expresso.ext.controller's priority is set to error only, then only log.error() messages will actually produce any output. If its priority is set to "debug", then all messages will appear.
• log.isDebugEnabled() - Log4J was designed for performace. As such, the first thing it does is determine if a category should log a particular message, and if it doesn't, returns as quickly as possible. However, there are things that it may have no control over performance-wise. For example, the statement:
  log.debug("This" + " Is " + " A " + " Test " + " Message.");
  
  Would generate 5 string buffer appends() before ever finding out whether the framework was using debug logging. So to speed performance, always wrap your debug messages in isDebugEnabled() blocks.  

How to Add logging to your own Expresso-based application

You can easily add logging to your own application. To do this, you:

• Design your category hierarchy - You'll want to think about how to create your category hierarchies. In Expresso, for example, we have a split hierarchy for each major branch: ext, core, and services. You should look at the eforumLogging.xml, and ePollLogging.xml to get an idea of how you can set up your own hierarchies.
  
• Design your appender hierarchy - Each category can be set up to be dumped to different locations. You should consider what should go wear. Explore the available log4j appenders including our own supplied DBAppender to decide where you want things to go. Again, we encourage you to check out the logging configuraiton files to get an idea of how to set this up.
  
• Create your own logging xml file - After the design decisions are made, you'll want to create your own logging xml file and put it in your configuration directory. Expresso's LogManager will automatically load all xml files in the configuration directory and merge the categories into the existing expressoLogging.xml category tree. Please note: Do not define your own <root> node - Expresso already defines its own root node, and your own root will conflict with the rest of the system.
  
• Add logging code as detailed above - After your own logging.xml file is created, you can then add logging code to your own application.

We recommend that you study the Log4J manual included with the expresso distribution for a full feeling of the power of this logging framework. You can find it here. 

Production Capable High Speed Logging

Logging can be a serious performance drain if it is set up incorrectly - so it is important to have logging configured for your production environment for performance.

Chief Points:

Appenders:

1. Remove all debug-information generation.
   But using a ConversionPattern as shown below :

   <param name="ConversionPattern" value="%d %-5p [%t] - %m\n"/>

   We remove all debug information from the logging event. For example, stack traces will not be shown, nor will calling file location be displayed. This greatly improves the efficiency of the logging event.
   

2. Move logging to files, syslog or NT Event Log:
   

   Database logging can be expensive on the target database. It is better to log to a file at a specified location rather than to a database server. Since dbLog is the only appender using the database. Change that value and all categories using that appender will now log to a file instead of the database.

   <appender name="dbLog" class="org.apache.log4j.RollingFileAppender">
    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="[%t] - %m"/>
     </layout>
</appender>

Note also that this example uses the RollingFileAppender - This allows the log to get rolled over whenever it reaches 10 Mb in size. Perfect for a long term production environment. Other options to investigate are: SyslogAppender, DailyRollingFileAppender, and NTEventLogAppender. Check the log4j javadocs for more information on these classes.

Categories:

Move category priorities to warn or error only.

By setting the categories to log log.error() and maybe log.warn() you effectively eliminate all the overhead of logging various categories unless something serious happens. Here's an example:

 <category name="expresso.core" additivity="false">
   <priority value="error"/>
   <appender-ref ref="expressoLog"/>
 </category>

This sets all expresso.core and subcategories to only log on Errors. Note that any hierachies that have additivity="false" must also be set because their parent categories have no effect on them.

Conclusion

For technical information about how to use logging, please refer to the:

• Expresso Developers Guide (EDG)
• Javadocs
• Log4J Documentation