ALM Logging Recommendations

Recommendations for effective logging configuration for use with the ALM exploratory code

Logging for development and testing

In development and (non-performance) testing the most important consideration is getting maximally useful logging information.

This recipe collects system-wide warnings and major happenings to a rolling portal.log ; additionally collects trace-level logging from the layout portions of the codebase to its own layout log and highlights ALM errors in yet another log.

For clarity, the log4j.xml configuration language is used here rather than the less expressive .properties logging configuration format.

In its own file named log4j.xml:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

  <!--
   | This portal.log appender will create a rolling portal.log with at most 10 log file
   | instances of at most 3 MB each for a disk usage profile of 30 megabytes.
   +-->
  <appender name="PORTAL_LOG" class="org.apache.log4j.RollingFileAppender">
    <!-- Most deployments will want to change this to point explicitly at Tomcat/logs/portal.log -->    
    <param name="File"
      value="portal.log" />
    <param name="Encoding"
      value="UTF-8" />
    <param name="MaxFileSize"
       value="3000KB"/>
    <param name="MaxBackupIndex"
      value="10"/>
    
    <layout class="org.apache.log4j.PatternLayout">
      <!-- This pattern includes the relatively-expensive-to-compute location information
        and so is very informative in development and testing but is not appropriate for production use. -->
      <param name="ConversionPattern"
        value="%5p [%t] %c{2}.[%x] (%F:%L) %d{MMM/dd HH:mm:ss} - %m%n" />
    </layout>
  </appender>

  <!--
   | This alm.log appender will create a rolling alm.log with at most 10 log file
   | instances of at most 3 MB each for a disk usage profile of 30 megabytes.
   +-->
  <appender name="ALM_LOG" class="org.apache.log4j.RollingFileAppender">
    <!-- Most deployments will want to change this to point explicitly at Tomcat/logs/alm.log -->    
    <param name="File"
      value="alm.log" />
    <param name="Encoding"
      value="UTF-8" />
    <param name="MaxFileSize"
       value="3000KB"/>
    <param name="MaxBackupIndex"
      value="10"/>
    
    <layout class="org.apache.log4j.PatternLayout">
      <!-- This pattern includes the relatively-expensive-to-compute location information
        and so is very informative in development and testing but is not appropriate for production use. -->
      <param name="ConversionPattern"
        value="%5p [%t] %c{2}.[%x] (%F:%L) %d{MMM/dd HH:mm:ss} - %m%n" />
    </layout>
  </appender>

  <!--
   | This alm_error.log appender will create a non-rolling alm.log
   | which truncates itself on every portal start, capturing ERROR level information from ALM.
   | This prevents the actual error information from being lost on log roll, while preventing this file
   | from growing without bound on sequential portal runs.
   | (The technique of per-portal-launch scoped log files is often useful in development.  Having made a change
   | and restarted, the log file truncates and begins capturing information anew, with it very clear that the
   | log is associated with the current run and not some past run.)
   +-->
  <appender name="ALM_ERROR_LOG" class="org.apache.log4j.FileAppender">
    <param name="Threshold" 
      value="ERROR" />
    <!-- Most deployments will want to change this to point explicitly at Tomcat/logs/alm_error.log -->    
    <param name="File"
      value="alm_error.log" />
    <param name="Encoding"
      value="UTF-8" />
    <!-- This setting causes the file to truncate on Tomcat container restart 
      i.e. "Don't append to the file - truncate it." -->
    <param name="Append"
       value="false"/>
    
    <layout class="org.apache.log4j.PatternLayout">
      <!-- This pattern includes the relatively-expensive-to-compute location information
        and so is very informative in development and testing but is not appropriate for production use. -->
      <param name="ConversionPattern"
        value="%5p [%t] %c{2}.[%x] (%F:%L) %d{MMM/dd HH:mm:ss} - %m%n" />
    </layout>
  </appender>

  <!--
    | This logger declaration is here as a defense against unwanted noise from whirlycott in the
    | case where the root log level is set to a more verbose level than WARN,
    | as it is here in this suggested configuration.
    +-->
  <logger name="com.whirlycott.cache">
    <level value="WARN"/>
    <!-- no appender-ref element is here declared because appenders are cumulative
      logging by this logger will append using the appender of the root logger.
    -->
  </logger>
  
  <logger name="org.jasig.portal.layout">
    <level value="TRACE"/>
    <appender-ref ref="ALM_LOG"/>
    <appender-ref ref="ALM_ERROR_LOG"/>
  </logger>

  <root>
    <level value="INFO"/>      
    <appender-ref ref="PORTAL_LOG" />
  </root>



</log4j:configuration>

Suggested production configuration

In its own file named log4j.xml:

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">

  <!--
   | This portal.log appender will create a rolling portal.log with at most 10 log file
   | instances of at most 3 MB each for a disk usage profile of 30 megabytes.
   +-->
  <appender name="PORTAL_LOG" class="org.apache.log4j.RollingFileAppender">
    <!-- Most deployments will want to change this to point explicitly at Tomcat/logs/portal.log -->    
    <param name="File"
      value="portal.log" />
    <param name="Encoding"
      value="UTF-8" />
    <param name="MaxFileSize"
       value="3000KB"/>
    <param name="MaxBackupIndex"
      value="10"/>

    <layout class="org.apache.log4j.PatternLayout">
      <!-- This pattern does not include relatively-expensive-to-compute
           location information. -->
      <param name="ConversionPattern"
        value="%5p [%t] %c{2}.[%x] %d{MMM/dd HH:mm:ss} - %m%n" />
    </layout>
  </appender>

  <!--
   | This alm.log appender will create a rolling alm.log with at most 10 log file
   | instances of at most 3 MB each for a disk usage profile of 30 megabytes.
   +-->
  <appender name="ALM_LOG" class="org.apache.log4j.RollingFileAppender">
    <!-- Most deployments will want to change this to point explicitly at Tomcat/logs/alm.log -->    
    <param name="File"
      value="alm.log" />
    <param name="Encoding"
      value="UTF-8" />
    <param name="MaxFileSize"
       value="3000KB"/>
    <param name="MaxBackupIndex"
      value="10"/>

    <layout class="org.apache.log4j.PatternLayout">
      <!-- This pattern does not include relatively-expensive-to-compute
           location information. -->
      <param name="ConversionPattern"
        value="%5p [%t] %c{2}.[%x] %d{MMM/dd HH:mm:ss} - %m%n" />
    </layout>
  </appender>

  <!--
   | This alm_error.log appender will create a non-rolling alm.log
   | which truncates itself on every portal start, capturing ERROR level information from ALM.
   | This prevents the actual error information from being lost on log roll, while preventing this file
   | from growing without bound on sequential portal runs.
   | (The technique of per-portal-launch scoped log files is often useful in development.  Having made a change
   | and restarted, the log file truncates and begins capturing information anew, with it very clear that the
   | log is associated with the current run and not some past run.)
   |
   | In the case where the portal fails because of ALM problems, this log file should be moved to another location
   | for analysis before the portal is started, so that the truncation does not zap it.
   +-->
  <appender name="ALM_ERROR_LOG" class="org.apache.log4j.FileAppender">
    <param name="Threshold" 
      value="ERROR" />
    <!-- Most deployments will want to change this to point explicitly at Tomcat/logs/alm_error.log -->    
    <param name="File"
      value="alm_error.log" />
    <param name="Encoding"
      value="UTF-8" />
    <!-- This setting causes the file to truncate on Tomcat container restart 
      i.e. "Don't append to the file - truncate it." -->
    <param name="Append"
       value="false"/>

<layout class="org.apache.log4j.PatternLayout">
      <!-- This pattern includes the relatively-expensive-to-compute location information.
       This is appropriate here even for production use because this pattern will only be reached
       when an error has been detected in ALM.  In this narrow circumstance better information about the error
       is more important than efficiency of logging. -->
      <param name="ConversionPattern"
        value="%5p [%t] %c{2}.[%x] (%F:%L) %d{MMM/dd HH:mm:ss} - %m%n" />
    </layout>
  </appender>





    <!--
     | This logger declaration is here as a defense against unwanted noise from whirlycott in the
     | case where the root log level is set to a more verbose level than WARN.
     | In the suggested configuration here, the root log level is WARN, so the whirlycott log level
     | already inherits WARN, and so this configuration block has no effect (harmless).
     +-->
    <logger name="com.whirlycott.cache">
      <level value="WARN"/>
      <!-- no appender-ref element is here declared because appenders are cumulative
           logging by this logger will append using the appender of the root logger.
      -->
    </logger>

    <logger name="org.jasig.portal.layout">
      <level value="INFO"/>
      <appender-ref ref="ALM_LOG"/>
      <appender-ref ref="ALM_ERROR_LOG"/>
    </logger>

  <root>
    <level value="WARN"/>      
    <appender-ref ref="PORTAL_LOG" />
  </root>

</log4j:configuration>

Installing these configuration files

Getting the uPortal build to install the log4j.xml configuration from {uPortal_project_root}/properties/log4j.xml to its necessary install location, {tomcat}/webapps/uPortal/WEB-INF/classes/log4j.xml, requires a modification to build.xml:

Before:

  	<!-- Copy the Logger.properties file to the well-known location
  	log4j expects.-->
  	<copy file="properties/Logger.properties" tofile="${build.home}/WEB-INF/classes/log4j.properties"/>

After:

  	<!-- Copy the log4j.xml file to the well-known location
  	log4j expects.-->
  	<copy file="properties/log4j.xml" tofile="${build.home}/WEB-INF/classes/log4j.xml"/>