Java Util Logging Behaviour in Tomcat

Logging is the interface between developers and system admin. Developers need to know how their logging code behave in a server envrionment. Admins need to know how to configure and turn on/off logging. This series inspects how two most common logging methods, Java Util Logging and Log4j, behave in Tomcat and WebSphere.


Java Util Logging is part of the JDK starting with version 6, which means that a web application can use it without including any additional jars in WEB-INF/lib. However, also because it is part of the JDK, Tomcat server itself uses the library for internal logging. How to make sure different web applications and the Tomcat server itself use Java Util Logging without interfering with each other? Tomcat has put in extra mechanism upon the Java Util Logging framework. This article inspects how Java Util Logging behaves in Tomcat.

1. Default Behaviour with Basic Logging Code

  • Basic Java Util Logging Code


In the following java util logging sample code, two loggers are created: the mainLogger com.appinf and a perfSubLogger com.appinf.perf.  This is to help us understand how java util logging organizes loggers in a tree structure. No additional calls are made to customize these loggers
public class JavaUtilLoggingTestServlet extends HttpServlet {
    
    static Logger mainLogger = null;
    static Logger perfSubLogger = null;
    static {
        mainLogger = Logger.getLogger("com.appinf");
        perfSubLogger = Logger.getLogger("com.appinf.perf");
    }
    
    protected void process(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {
        final long startTime = System.currentTimeMillis();
        perfSubLogger.logp(Level.INFO, "JavaUtilLoggingSETest", "main", "Enter");
        
        mainLogger.logp(Level.INFO, "JavaUtilLoggingSETest", "main", "Processing ... ");

        final long endTime = System.currentTimeMillis();
        perfSubLogger.logp(Level.INFO, "JavaUtilLoggingSETest", "main", "Exit Total time : " + (endTime - startTime) + " ms.");

        String destination = "/test.jsp";
        getServletContext().getRequestDispatcher(destination).forward(request, response);
    }}
  • How Does Basic Logging Code Behave in Tomcat

1. Tomcat Log Manager : ClassLoaderLogManager

In Java SE, Logger.getLogger invokes java.util.logging.LogManager, which creates all loggers within the JVM based on a .properties file. In Tomcat, in order to better manage web-application level logging configurations, a new LogManger is created. Notice that the following system property is added to the command line by the tomcat startup script. (catalina.bat or catalina.sh)

-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager 

If ${catalina.base}/conf/logging.properties exists, the startup script also adds the following command line parameter. 

-Djava.util.logging.config.file=/software/Tomcat/apache-tomcat-7.0.25/conf/logging.properties

ClassLoaderLogManager reads the file if specified, otherwise it will use ${java.home}/lib/logging.properties. You can refer to Tomcat Documentation or source code. If your Tomcat environment defined customized catalina.base to support multiple instances, make sure ${catalina.base}/conf/logging.properties exists. 


2. Default Config File : ${catalina.base}/conf/logging.properties

The logging.properties file shipped with Tomcat contains the following entries.
  • .handlers = 1catalina.org.apache.juli.FileHandler, java.util.logging.ConsoleHandlerhandlers
-- by default, everything logs to console and a file
  • 1catalina.org.apache.juli.FileHandler.level = FINE
    1catalina.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
    1catalina.org.apache.juli.FileHandler.prefix = catalina.
-- that file is configured as above.
  • org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager].level = INFO
    org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/manager].handlers = 3manager.org.apache.juli.FileHandler
    3manager.org.apache.juli.FileHandler.level = FINE
    3manager.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
    3manager.org.apache.juli.FileHandler.prefix = manager
-- Other name loggers are configured, but they don't affect our code.

3. Because of 1 and 2, under default setting, the logging statements in the sample code will write to both the console and catalina.out.

  • Catlina.out
  • Console


2. Customize : Log to application specific log file

If the default behaviour is not what you want, and if you want applications to write to their own logs, there are three ways you can do it in Tomcat.

 

Method 1 : Modify ${catalina.base}/conf/logging.properties

Add the following entries to ${catalina.base}/conf/logging.properties .

handlers = 1catalina.org.apache.juli.FileHandler, 2localhost.org.apache.juli.FileHandler, 3manager.org.apache.juli.FileHandler, 4host-manager.org.apache.juli.FileHandler, java.util.logging.ConsoleHandler,5appinf.org.apache.juli.FileHandler

5appinf.org.apache.juli.FileHandler.level = FINE
5appinf.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
5appinf.org.apache.juli.FileHandler.prefix = app-inf.


com.appinf.handlers = 5appinf.org.apache.juli.FileHandler
com.appinf.level = INFO

 

Method 2 : Add logging.properties file to a web app under WEB-INF\classes

handlers = org.apache.juli.FileHandler
org.apache.juli.FileHandler.level = FINE
org.apache.juli.FileHandler.directory = ${catalina.base}/logs
org.apache.juli.FileHandler.prefix = app-inf.


com.appinf.level = INFO
com.appinf.perf.level = SEVERE
 
The above lines define the web-app level root logger to log only to app-inf.*.log, and not the console, or catalinat.out

 

Method 3 : Same as Java SE, add a FileHandler in Java Code.   

mainLogger.setUseParentHandlers(false);
if ( mainLogger.getHandlers().length == 0){
    FileHandler fh = new FileHandler("logs" 
        + File.separator + "com.appinf.log", 1024 * 5000, 10, true);
    fh.setFormatter(new SimpleFormatter());        
    mainLogger.addHandler(fh);}
There are several things to note here.
  • If you are not using absolute path, it will use the directory where you start tomcat.
  • Subdirectories have to exist beforehand.
  • Even though you specified a file handler, logs are still written to the parent logger. To disable it, you have to setUseParentHandlers to false.
  • You can still use Method 2. A web-app level root logger will be configured. If setUseParentHandlers to false, handlers defined in WEB-INF\classes\logging.properties will be ignored,  unless you directly associate the handler with the mainLogger.
    • com.appinf.handlers = org.apache.juli.FileHandler

Comparision of Method 1, 2 and 3

 For Developers :
  • In Method 2 and 3 described above, app team controls the configuration of the app's logging, whether it is by java code or WEB-INF\classes\logging.properties
  • WEB-INF\classes\logging.properties is Tomcat specific, enabled by Tomcat's ClassLoaderLogManager.
  • Java code is probably more universal if you may need to migrate from Tomcat to WebSphere, or vice versa.
For System admin :
  • In all three Methods described above, you have ways to redirect where application logs or change logging levels. This may become handy in trouble-shooting.
  • You may not want to take up the task of configuring logging for each web-app, however, you canmonitor catalina.out to mandate apps follow your logging policy.

4 comments:

  1. This comment has been removed by the author.

    ReplyDelete
  2. This post is very helpful to understanding the infrastructure of Java Util Behavior. Being a Creative web app developer, I really need to understand these behaviors.

    ReplyDelete
  3. I am unable to read articles online very ften, but I’m glad I did today. This is very well written and your points are well-expressed. Please, don’t ever stop writing.
    The Web Handlers

    ReplyDelete
  4. this blog for developers only but its really informative and contentfulandroid app development company

    ReplyDelete