Application Logging: What, When, How

Logging is a fundamental part of applications. Every application has a varying flavor of logging mechanism. A very good designed logging system is a huge utility for system administrators and developers. Especially support team knows its value very well. Logs save many valuable hours of support team or developers. As users execute programs at the front, system invisibly builds a vault of event information (log entries) for system administrators and support team.

After stating its value, let’s try to figure out logging requirements for an application. Java has a standard logging API in its new versions (java.util.logging). Log4J is also a well-known library for logging. We implemented a transparent “Logging Service” in our application framework. You may prefer some kind of logging implementations but there are some other important questions you have to answer in your application design which are what to log, when to log, how much to log, how to control logging and how correlate it with your exception system.

What to Log

Some application exceptions should be logged:
Why not to log all exceptions? Some exceptions are managed exceptions which are thrown by application as a warning or as a validation error to the user. If all validation errors or application exceptions are included in logs, logs lose their usefulness since it would contain many entries hard to reach valuable entries. Here, we should discriminate exceptions if they should be logged. We used a Loggable mark interface to determine if it is included in logs. Another best practice is to have a single global exception handler. In this way, application developers don’t worry about logging of any exception they generate. A single exception handler means a single unified and neat exception logging.

Some application events should be logged:
For major components of application we may log lifecycle events like start, stop and restart. Some security-related events may be logged such as unauthorized URL access attempts, user logins etc. Some resource thresholds may be exceeded and should be logged.

Some application states should be logged:
In some codes, we should ask that “What could go wrong here in this code”. If this state occurs, we may throw an exception or log it (if we don’t want to interrupt current process) with some levels like Error, Warning or Information. For example if a connection is normally released while it is uncommitted, that info may be logged as uncommitted connection release that points some application code problems.

Application process steps may be logged:
For some multi-step processes, we may create process log files so that we can inspect process progress. It behaves like a smart progress indicator telling you what is happening in the current step. Process logs may include errors, warnings and information.

Some debug information may be logged:
In some applications, you may have some errors and can’t find why this is happening. You may add some debug logs into your code and redeploy it to diagnose the problem. Some chronic bugs deserve debug traces which can’t be detected in development environment.

Executed SQLs may be logged:
In some conditions, we may want to get the SQL statement executed by an application. We should easily switch logging on without start/stop of system. Let’s say user complain about wrong report result when executing a report. If we don’t have a clue about that we may log SQL and trace it.

User HTTP requests may be logged:
We may need what is coming from the user with full parameter details. To achieve this kind of logging we have to plug a log service in servlets and JSP pages.

Executing threads may be logged:
I mentioned a BlackBox implementation in our applications in one of my previous posts. You may log executing thread information to that black box to figure out what may go wrong in a system crash.

JavaScript errors may be logged:
This may be considered same with first item but its implementations totally differs. You need to have a global JavaScript exception handler. In the handler, you submit JavaScript error with AJAX to log on the server (assuming it is not an AJAX error).

Some Best Practices

As I said above, exception handling system is an important plug point for logging. In our all Servlets and JSPs, main code blocks have following structure to enable global exception handling. This standard eliminates the work of logging exceptions by developers (Transparent unified logging):

try{
}
catch(Exception e){
   GlobalHandler.handleException(e);
}

We name “Log Medium” to mean where to store log entries but in Java logging API it is called Handlers. For some type of logs, database logs are handy since you can run powerful SQL queries against log table which is merely possible in files.

To assign log messages to the appropriate log levels is also important. Otherwise some wrong alerts would mislead system administrators.

We used System.err stream for application-level logging which is same place with e.printStackTrace() which may be printed with our global handler log entry at the same time. We wouldn’t need all exception’s stack trace but some may be very useful to see where the root of the problem (i.e. StackOverflowException).

When logging exceptions we used following format. Some articles recommends that we’d better to include problem failover suggestion but I think this information should be given to the user not included in the logs. Logs are rarely read but exceptions are in front of users.

Log entry should answer following questions:
Who(UserName), When (Timestamp), Where(Context, ServletOrPage,Database), What (Command), Result (Exception)

[ErrorHandlerName] UserName: userabc DatabaseName: ABC Timestamp: 15.07.2009 13:02:08 Context:Servlet Page: /prod/sales/SalesOrders.jsp Window: windwName Command: saveSalesOrder Exception: ShortDescriptionOfException
ExceptionStackTraceHere

In a clustered environment, logging should be considered. We separated same type of log files with a cluster node name suffix to the file name. Otherwise, concurrent log writes may lead to some problems. system_node01.log system_node02.log

As a last item, logging may be a very interesting performance killer. If applications begin to log a lot, application performance may severely fall down. I have a real life story for that. Once we had forgotten to include an image file in deployment package. It was being used in every page. When we started system after installment, page response was so slow. Log files seem small enough that may not incur problem. After, opening and reading log files, we realized that log frequency (stating image is missing) was high and that was causing the problem. In conclusion, your log file size and log writing frequency should be small.