Thursday, July 1, 2010

Reconfiguring Log4j at runtime

At the start of my latest project I realized that I often take for granted the presence of log4j. For me it's just a given that it will be in my next app and that everyone already knows how to hack log4j for their own needs. Not so!

While including Log4j in your app and calling debug is usually a given I think I'm one of a hand full of people that have actually looked over the JavaDocs to discover what else lgo4j can do for me. Hey it's OK, we all have deadlines and reading logger JavaDocs isn't exactly on the critical path right?

If you haven't yet, I would encourage you to skim through the JavaDocs. For those who decline or are just too busy, I'd like to share a nice feature that will save you some serious time.

So, how would you like to control the log4j Loggers in your application deployed to production or anywhere off of you local environment?  More often then not you just don't get the option to leave debugging on in production since SysAdmins don't care much for verbose logging on their servers and rightly so since logs can grow rapidly if your a good user of debugging. What you really need is a logger admin page in your app where you can change the logging levels of configured loggers and add new, something like the following image.

(Note:Some package names were obscured to protect the innocent)

In the above image you see a logger manager screen where you can change the logging level as well as a text box where you could enter a new Logger such as com.mycorp.myapp.dao or the full path of a specific class.

So how's all this work? It pretty much comes down to Log4j Loggers and their Levels. First off is the Logger which in the case of Log4j can only be created by calling a static Factory method, Logger.getLogger(String name). If you have used Log4j before you are no doubt well acquainted with this method when your creating a logger for a specific Class. All instances of Logger are children of the RootLogger which always exists in log4j and can only be retrieved by calling Logger.getRootLogger(). This is how log4j can perform its logging at the class or package level and only print out messages at the root configured level such as ERROR which tends to be the default level.

Speaking of Levels, all loggers are configured to log at a  specific Level which is inherited from the parent logger such as the RootLogger or another logger in the family tree specified by package notation in the name. For example com.foo is a parent to com.foo.bar, If the root is configured at ERROR com.foo.bar would be at ERROR as well unless com, com.foo, or com.foo.bar have Loggers are configured at a different Level.
 Looking at the above screen shot you should be able recognize the Loggers and their assigned Levels.

Now let me explain that form displayed above. At the top of the form is the Logger Name text box which allows you to create a new Logger. Lets say you want to create a logger for com.foo.bar.model.dao.MyDAO; you simply type that or some part of that package into the text box, select a level like DEBUG and click OK. The form updates itself and the new logger is displayed on the form. Logging for that level will be activated and you'll be able to see whats going on!

After your done debugging whats wrong with MyDAO you might want to set its Logging Level back to ERROR, to do this simply change the Level in the drop-down and the form submits updating the Logger to its new Level. Easy real time management of Logger Levels!

So  enough theory and rambling, your here her for the code, I know you are! Let me walk you through the code now! Most of the example code is your general MVC stuff so I'll point out the overall structure and then point out the interesting parts in each class file.  I am currently working with JSF for my views so this example has JSF in the view but should translate to a jsp very simply if desired. 

LoggerManager which acts as the Controller of creating Loggers and LoggerAdmin a Form BackingBean which takes care of the view logic. In addition there are two supporting files, ComparableLogger and of course the html view.

The LoggerManager acts as our service/controller layer which contains 2 aptly named methods, getLoggers() and addLogger(). The getter provides a controlled manner for the front end to retrieve the current log4j Loggers as a list of ComparableLoggers which extend the log4j Logger class (keep reading for details on  ComparableLogger).


Enumeration<logger> loggers = LogManager.getCurrentLoggers();
while (loggers.hasMoreElements())
{
    Logger lgr = loggers.nextElement();
    if(lgr != null &amp;&amp; filterUnconfigured)
    {
        if(lgr.getLevel() != null)
            list.add(new ComparableLogger(lgr));
        }
        else
        {
            list.add(new ComparableLogger(lgr));
        }
    }
Collections.sort(list);


The code here is requesting the list of Loggers by making a call to the static LogManager.getCurrentLoggers(). This returns an Enumeration which includes items that have no Log level there by taking the default. Those set to default can be ignored, so we loop through the returned Loggers building a List of Loggers with a logging level and in the process converting them to ComparableLoggers for later sorting.

Wow that you know how to get the active Loggers, you'll want to be able to add new ones! You have most likely done this before, simply pass the new Name of the logger, something like "com.foo.dao" and also include a logging Level in the form of an int constant defined in the Level class. Then create a new logger as you normally would.


...
Logger newLog = Logger.getLogger(newLoggerName);
Level newLevel = Level.toLevel(newLogLevel);
newLog.setLevel(newLevel);
...



Well that is the meat of the code right there, pretty simple really! The rest of the code is, as I mentioned, display oriented code. I'll run though the other classes and their purpose real quick to help you with the full picture.  The next class, LoggerAdmin, is referred to as a a Backing bean because it is a jova object representation of the view. Its responsibilities include containing data and managing view logic. You'll notice that it does some translating to provide logger levels for the UI as well as passing long the UI requests to the Service layer.

The next object is ComparableLogger and as mentioned before it exists to provide a sortable wrapper for a Logger object. Finally there is the manageLogger.xhtml file used by the Faces framework to generate the view. Faces is far outside the scope of this posting but looking it over should give you a general idea of what your view ought to be doing.

I have included all of the code below:

LoggerManager.java
package org.lee.twobytes.managelogger;

import java.util.ArrayList;
import java.util.Collections;
import java.util.Enumeration;
import java.util.List;

import org.apache.log4j.Level;
import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;

/**
 * Provides access helpers for retrieving Logger information about the running
 * application.
 *
 * @author lclarke
 */
public class LoggerManager
{
    /**
     * Lists only configured loggers in Log4j also sorts the results by name.
     *
     * @return
     */
    public List getActiveLoggers()
    {
        return getLoggers(true);
    }

    /**
     * Lists ALL active loggers in Log4j also sorts the results.
     *
     * @return
     */
    public List getAllActiveLoggers()
    {
        return getLoggers(false);
    }

    protected List<comparablelogger> getLoggers(boolean filterUnconfigured)
    {
        // Logger rootLogger = Logger.getRootLogger();
        ArrayList list = new ArrayList();

        Enumeration loggers = LogManager.getCurrentLoggers();
        while (loggers.hasMoreElements())
        {
            Logger lgr = loggers.nextElement();
            if (lgr != null && filterUnconfigured)
            {
                if (lgr.getLevel() != null)

                    list.add(new ComparableLogger(lgr));
            }
            else
            {
                list.add(new ComparableLogger(lgr));
            }
        }
        Collections.sort(list);
        return list;
    }

    /**
     * Creates the new Logger
     *
     * @param newLoggerName
     * @param newLogLevel
     * @throws TINException
     */
    public void addLogger(String newLoggerName, Integer newLogLevel)

             throws Exception
    {
        if (newLoggerName != null && newLogLevel != null)
        {
            Logger newLog = Logger.getLogger(newLoggerName);
            Level newLevel = Level.toLevel(newLogLevel);
            newLog.setLevel(newLevel);
        }
        else
        {
            throw new Exception("Logger information was invalid or null.");
        }
    }
}



LoggerAdmin.java

package org.lee.twobytes.backingbeans.admin;

import java.util.ArrayList;
import java.util.Collections;
import java.util.List;

import org.apache.log4j.Level;
import org.apache.log4j.Logger;

import org.lee.twobytes.model.NameValuePair;
import org.lee.twobytes.model.ComparableLogger;
import org.lee.twobytes.model.LoggerManager;
import org.lee.twobytes.model.exceptions.TBException;

/**
 * Provides access to Logger manager for the display and configuration of log4j
 * loggers.
 *
 * @author lclarke
 */
public class LoggerAdmin extends AdminBaseBean
{

    private static final Logger logger = Logger.getLogger(LoggerAdmin.class);

    private static List<NameValuePair<String, Integer>> LogLevels2;
    static
    {
        LogLevels2 = new ArrayList<NameValuePair<String, Integer>>();
        LogLevels2.add(new NameValuePair<String, Integer>
            (Level.WARN.toString(), Level.WARN.toInt()));
        LogLevels2.add(new NameValuePair<String, Integer>
            (Level.TRACE.toString(), Level.TRACE.toInt()));
        LogLevels2.add(new NameValuePair<String, Integer>
            (Level.DEBUG.toString(), Level.DEBUG.toInt()));
        LogLevels2.add(new NameValuePair<String, Integer>
            (Level.ERROR.toString(), Level.ERROR.toInt()));
        LogLevels2.add(new NameValuePair<String, Integer>
            (Level.FATAL.toString(), Level.FATAL.toInt()));
        LogLevels2.add(new NameValuePair<String, Integer>
            (Level.INFO.toString(), Level.INFO.toInt()));
        LogLevels2.add(new NameValuePair<String, Integer>
            (Level.OFF.toString(), Level.OFF.toInt()));
      
        Collections.sort(LogLevels2);
    }

    private LoggerManager loggerManager;
    private String currentLoggerName = null;
    private String newLoggerName = null;
    private Integer newLogLevel = Level.DEBUG.toInt();
  
    public String getCurrentLoggerName()
    {
        return currentLoggerName;
    }

    public void setCurrentLoggerName(String currentLoggerName)
    {
        this.currentLoggerName = currentLoggerName;
    }

    public List<ComparableLogger> getActiveLoggers()
    {
        return loggerManager.getActiveLoggers();
    }

    /**
     * Adds a new logger to the app for the specified classpath
     */
    public String processAdd()
    {
        logger.debug("ADD LOGGER: name:" + this.newLoggerName + " Level:" + this.newLogLevel);
        try
        {
            loggerManager.addLogger(this.newLoggerName,  this.newLogLevel);
            this.setInfoMessageByKey("label.settingsSaveSuccess", null);
            this.newLogLevel = Level.DEBUG.toInt();
            this.newLoggerName = null;
        }
        catch (TBException e)
        {
            this.setInfoMessageByKey("label.erroraddinglogger", null);
        }
      
        // this.notesHandler.notifyReload();
        // } catch (TBException e) {
        // this.handleSystemError("error updating config items", e);
        // }  
        return null;
    }

    /**
     * Updates the logger that changed levels.
     * @return
     */
    public String processUpdate()
    {
        if (this.currentLoggerName != null)
        {
            logger.debug("Updating logger: "+this.currentLoggerName);
        }
        return null;
    }

    /**
     * Drives display values for the dropdown
     *
     * @return
     */
    public List<NameValuePair<String, Integer>> getLogLevels()
    {
        return LogLevels2;
    }

    public LoggerManager getLoggerManager()
    {
        return loggerManager;
    }

    public void setLoggerManager(LoggerManager loggerManager)
    {
        this.loggerManager = loggerManager;
    }

    public String getNewLoggerName()
    {
        return newLoggerName;
    }

    public void setNewLoggerName(String newLoggerName)
    {
        this.newLoggerName = newLoggerName;
    }

    public Integer getNewLogLevel()
    {
        return newLogLevel;
    }

    public void setNewLogLevel(Integer newLogLevel)
    {
        this.newLogLevel = newLogLevel;
    }
}



ComparableLogger.java
package org.lee.twobytes.managelogger.model.ComparableLogger;

import org.apache.log4j.*;

/**
 * I wanted to sort Loggers but, they aren't comparable... this takes care of
 * that. IT sorts on the Logger name by default.
 *
 */
public class ComparableLogger implements Comparable
{
    private Logger logger = null;

    /**
     * Indicates that loggers should be sorted by Name only,
     *  if set to false
     * then sort is done by Level then name.
     */
    public static boolean orderByNameOnly = true;

    public ComparableLogger()
    {

    }

    public ComparableLogger(Logger logger)
    {
        this.logger = logger;
    }

    public Logger getLogger()
    {
        return logger;
    }

    public void setLogger(Logger logger)
    {
        this.logger = logger;
    }

    @Override
    public int compareTo(ComparableLogger lgrIn)
    {
        if (!orderByNameOnly &&
            logger.getEffectiveLevel().toInt() !=
                lgrIn.getLogger().getEffectiveLevel().toInt())
        {
            return (logger.getEffectiveLevel().toInt() <
                lgrIn.getLogger().getEffectiveLevel().toInt()) ? -1 : 1;
        }
        else return logger.getName().compareTo(lgrIn.getLogger().getName());
    }

    /**
     * Exposes the Loggers EffectiveLevel value to the front end for use in
     * form.
     *
     * @return
     */
    public int getLevelInt()
    {
        return this.logger.getEffectiveLevel().toInt();
    }

    /**
     * Sets the loggers actual Level to provided value if it changed.
     *
     * @param newVal
     */
    public void setLevelInt(int newVal)
    {
        if (logger.getEffectiveLevel().toInt() != newVal)
           this.logger.setLevel(Level.toLevel(newVal));
    }

    public String getLoggerName()
    {
        return this.logger.getName();
    }
}



manageLogger.xhtml



<?xml version='1.0' encoding='UTF-8' ?>
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN"
                      "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
<html xmlns="http://www.w3.org/1999/xhtml"
      xmlns:ui="http://java.sun.com/jsf/facelets"
      xmlns:f="http://java.sun.com/jsf/core"
      xmlns:h="http://java.sun.com/jsf/html"
      xmlns:a4j="http://richfaces.org/a4j"
      xmlns:rich="http://richfaces.org/rich"
      xmlns:t="http://myfaces.apache.org/tomahawk"
      xmlns:c="http://java.sun.com/jstl/core">

<ui:composition template="../templates/template.xhtml">
<ui:define name="pageTitle"><h:outputText value="#{msg['manageLogger.page.title']}"/></ui:define>
<ui:define name="pageSubTitle"><h:outputText value="#{msg['manageLogger.page.subtitle']}"/></ui:define>
<ui:define name="content">
<h:form id="form">


<rich:messages id="pageMessages" globalOnly="true" infoClass="rich-messages-info" errorClass="rich-messages-error"/>

<a4j:outputPanel id="loggerPanel">
<table id="loggerTable" border="0" cellspacing="0" cellpadding="3">  
<tr>
    <td colspan ="2">
    <table>
        <tr><td colspan="3"><b><h:outputLabel value="#{msg['label.newlogger']}" title="#{msg['label.newlogger']}" style="padding-top:6px;height:20px;"/></b></td></tr>
        <tr><td colspan="3"><h:outputLabel value="#{msg['label.loggername']}:" title="#{msg['label.loggername']}" style="padding-top:6px;height:20px;"/></td>
            <td><h:inputText id="newLoggerName" value="#{loggerAdmin.newLoggerName}" style="width:200px;"/></td>
            <td>
                <h:selectOneMenu id="newLogLevel" value="#{loggerAdmin.newLogLevel}" >
                        <t:selectItems value="#{loggerAdmin.logLevels}" var="lvl" itemLabel="#{lvl.name}" itemValue="#{lvl.value}" />
                </h:selectOneMenu>
            </td></tr>
        <tr><td colspan="3"><a4j:commandButton id="add" action="#{loggerAdmin.processAdd}" style="width:75px; margin-right:6px;" value="#{msg['label.ok']}" reRender="loggerPanel"/></td></tr>
    </table>
    </td>
</tr>
<ui:repeat var="logger" value="#{loggerAdmin.activeLoggers}">
<tr>  
    <td align="right" valign="top"><h:outputLabel value="#{logger.logger.name}:" title="#{logger.logger.name}" style="font-size:150%;padding-top:6px;height:20px;"/></td>
    <td align="left">
        <h:selectOneMenu id="level" value="#{logger.levelInt}" >
            <t:selectItems value="#{loggerAdmin.logLevels}" var="lvl" itemLabel="#{lvl.name}" itemValue="#{lvl.value}" />
            <a4j:support event="onchange" action="#{loggerAdmin.processUpdate}">
              
            </a4j:support>
        </h:selectOneMenu> <rich:message for="level"/>
    </td>
</tr>
</ui:repeat>

</table>
</a4j:outputPanel>
<br/>

</h:form>

</ui:define>
</ui:composition>
</html>