Using Log Files to Debug an Application

At one time, there were no symbolic debuggers. You couldn't bring up the source code and step through one line at a time, printing out variable values as the program changed them. The only thing you could do was write out debugging statements to indicate what the program was doing.

Logging, or writing program state information during execution, is still one of the most common ways to debug a program. Debuggers, although very useful, often interfere with the debugging process in a number of ways. It is not uncommon for a program to run fine under a debugger and crash without the debugger.

Logging lets you display information at different points in the program without interfering too much with the overall running of the program. Obviously, if you spend too much time writing to log files, your program will slow down, but overall, logging is an excellent way to locate bugs.

Using System.out and System.err

In a stand-alone Java program, you frequently write debugging information to System.out and System.err. When you call the printStackTrace method in a Throwable, for example, the stack trace goes to System.err unless you specify otherwise.

Because servlets and JSPs run inside a servlet/JSP engine, messages you write to System.out and System.err don't necessarily appear on your screen. Exactly where the messages appear depends on the servlet/JSP engine. For Tomcat, writing to either results in messages in catalina.out in the logs/ subdirectory of Tomcat's home. Not all servlet and JSP engines support the use of System.out and System.err.

Using the Servlet-Logging API

Recognizing that not all servlet engines can support System.out and System.err for logging, Sun added a pair of standard log methods in the ServletContext object. Using these methods, you can write log messages to a log that your application server maintains. For Tomcat, it's also located in the logs/ subdirectory and is usually named localhost_log.date.txt where date identifies the date for the entries contained within the file.

The log methods in ServletContext are

public void log(String message)
public void log(String message, Throwable throwable)

The second variation of the log method lets you print the stack trace from an exception along with your message.

Using Log4J for Detailed Logging

For some time, Web developers using Tomcat have been using a capable logging package called Log4J. Log4J makes it possible to define logging categories, manage log destinations, and control the formatting of your messages. Log4J is available at http://jakarta.apache.org/log4j/docs/index.html.

Log4J defines these core components: Loggers, Appenders, and Layouts.

Loggers are responsible for outputting messages to destinations, or Appenders. When you create a Logger, you give it a name and a Level. Levels define the informational type of the messages and are organized hierarchically. The following are the predefined levels (in order):

• DEBUG— The most fine-grained informational level, used to provide detailed information used to debug applications

• INFO— Used to announce the progress of an application

• WARN— Indicates a potentially harmful situation

• ERROR— Designates a situation that is the result of an error that may allow the application to continue running

• FATAL— Indicates that the application has had a serious fault that will likely lead to its termination

Log4J also defines these levels:

• ALL— Show all informational messages

• OFF— Do not show any informational messages

Loggers use levels to decide whether to output messages. For example, if a logger is created with an assigned level of DEBUG, it will produce entries for every informational level. On the other hand, if a logger is assigned a level of ERROR, it will log only messages that are of type ERROR or FATAL. The Logger class has methods that correspond to each of the levels. Each of the methods has a signature that looks like this:

void debug(Object message)
void debug(Object message, Throwable t)

The methods take an object that is rendered into a string and an optional Throwable that can be used to provide additional diagnostic information. In addition to the debug, info, warn, error, and fatal methods, the Logger class also has a generic method, log, which can be used to create logs at various levels. The log method is intended for use by wrapper methods, but can be useful if you need to produce different types of logs in one place at run time.

Appenders represent the strategy for outputting log statements. For our purpose, an appender is responsible for deciding whether a message should be output based on its level and for managing the log destination. Log4J provides appenders for writing to the console, files, and databases. There are also appenders that e-mail events and write to remote log servers. Log4J can output to multiple appenders.

As you would expect, Layouts define the format of the log output. SimpleLayout provides a log level and message, HTMLLayout outputs events in an HTML table, and PatternLayout allows you to specify the format using a pattern.

You can define components or configure Log4J programmatically or through the use of a properties file. Listing 11.1 is an example of a simple log4j.properties file:

Listing 11.1 Source Code for log4j.properties

log4j.category.examples.logger=DEBUG, file

log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=<TOMCAT_HOME>/webapps/logs/log.txt

log4j.appender.file.layout=org.apache.log4j.SimpleLayout

On the first line, we've defined a logger whose name is examples.logger, which logs events of DEBUG level or greater and whose appender is named file. The second and third lines of the example define the appender to be a RollingFileAppender whose output is a file in the webapps/logs/ subdirectory of the Tomcat installation. Don't forget to replace <TOMCAT_HOME> with the actual name of the directory Tomcat is installed in. A RollingFileAppender will back up log files when they reach a predetermined size. The last line sets the format of the output to SimpleLayout.

To use Log4J with Tomcat, you need to copy log4j.jar to /common/lib/ in the Tomcat installation directory. Then, it's only a matter of including the functionality in your Web applications.

Listing 11.2 is an example of a servlet that uses Log4J to log an informational message.

Listing 11.2 Source Code for Log4JServlet

package examples;

import javax.servlet.*;
import javax.servlet.http.*;
import java.io.*;
import java.util.*;

import org.apache.log4j.*;

public class Log4JServlet extends HttpServlet {

   public void doGet(HttpServletRequest request, HttpServletResponse response)
        throws ServletException, IOException {

      Logger logger = Logger.getLogger("examples.logger");
      logger.info("In the doGet method of Log4JServlet!");

      PrintWriter out = response.getWriter();
      out.println("<html>");
      out.println("<head><title>A Servlet That uses Log4J</title></head>");
      out.println("<body>");
      out.println("<p>We've just logged an event!</p>");
      out.println("</body></html>");
   }
}

The log4j.properties for this Web application should be placed in the WEB-INF/classes subdirectory of the application. By doing this, you can configure each application independently of one another.

The resulting log file contains the event

INFO - In the doGet method of Log4JServlet!

By using scriptlets, you can add Log4J to your JSPs as well. Better yet, beginning in Hour 16, you'll learn enough about custom tags to be able to use the Log Tag Library in your JavaServer Pages. Visit http://jakarta.apache.org/taglibs/doc/log-doc/intro.html for additional information about the Log Tag Library.

Logging to a File

When all else fails, you can always open up a file and write log messages to it. If you close the file after writing, remember to make sure you open it again with the append option set to true. That is, make sure you don't overwrite the existing file; otherwise, you'll lose the previous log message every time you write a new one.

Using Exceptions to Trace Execution

Sometimes when you're debugging, you want to find out what routine called a particular method. You could throw an exception, but you don't want to stop executing the method; you just want to write a log message indicating who called the method. For instance, one class might be calling a method with bad values and you want to locate the offending class.

You can throw an exception and catch it immediately to get an instant snapshot of the current thread's call stack, like this:

try
{
    throw new Exception("dummy");
}
catch (Exception exc)
{
    System.out.println("This method was called from:");
    exc.printStackTrace(System.out);
}

This technique isn't the prettiest thing in the world, and it isn't very fast, but sometimes it's the only choice you have.