Java Application Logging
Best Practices
1.
Introduction
The pretty basic need to diagnose any Java application is to have
debug information available in console or log files. Everybody who starts java starts with
System.out.println() for printing message in java console.
But, this is not at all powerful as compared to advanced java logging
and in any java server application without java logs you won't be able to figure out what went wrong. That’s why logging in java is most important while writing server applications. Logging in Java is not by choice and it is must to understand.
But, this is not at all powerful as compared to advanced java logging
and in any java server application without java logs you won't be able to figure out what went wrong. That’s why logging in java is most important while writing server applications. Logging in Java is not by choice and it is must to understand.
This document gives basic overview of Java logging and the
guidelines to be followed while logging application errors, debug information.
The intended audience of this document includes developers, code reviewers and
architects. Well-structured log information will help developers to identify
and resolve defects quickly.
2.
Objective
of Logging
Logging is an efficient way of monitoring application execution.
When used right this can provide information of what is happening during runtime.
You can log errors and actions applications encounter, which is pretty critical
to analyze bugs and runtime behavior. Logging other things can be very
informative e.g. the start and end of a batch process, the changes made by
administrators, amount of processed files and duration within a certain method
call and so on.
Logging is kind of a double-edged sword. You want the right
kind of information available to you, but don’t want to store tons of logs that
don’t mean anything to you later. You want to write concise informative
messages that are self-explanatory and able to be dumped soon after, as needed.
Following are few uses of logging
·
Audit trail & application status
·
Automatic monitoring of errors and warnings
·
Track down configuration problems
·
Track down bugs
3.
Logging
Frameworks
Log4j, SLF4J and Logback are widely used logging frameworks by
java developers.
Log4j : Log4j is
the largely used and well established framework. It is simple to use and log
information is printed as String. For example, following is a debug log using
log4j.
log.debug("Found " + records + "
records matching filter: '" + filter + "'");
SLF4J : SLF4J is
just a façade implementation. Its advantage is the pattern substitution
support:
log.debug("Found {} records matching filter:
'{}'", records, filter);
|
SLF4J adds a nice {} substitution feature. Also, because
string concatenation is avoided and toString() is not called if the logging
statement is filtered, there is no need for isDebugEnabled() anymore.
Logback : Logback has many
interesting features like Conditional
processing of configuration files, filters etc., and is actively
developed.
Choose a log framework that will best suit your application.
In this document, we will use log4j for examples and illustrations.
4.
Configuration
and Setup
In this section we will see how to configure log4j. It is
important to understand the log levels before creating the configuration file.
4.1 Log levels
There are five log levels supported by the log4j framework.
Using the correct log level based on the severity will prevent surplus logging
in production environment.
ERROR – Something terribly wrong had happened, that
must be investigated immediately. No system can tolerate items logged on this
level. Example: NPE, database unavailable, mission critical use case cannot be
continued.
WARN – The process might be continued, but take extra caution.
Example: “Application running in development mode”, “Unable to connect to
primary Database and using Secondary” etc. The application can tolerate warning
messages, but they should always be justified and examined.
INFO – Important business the application has finished.
In ideal world, administrator or advanced user should be able to understand
INFO messages and quickly find out what the application is doing. For example
if an application is all about booking airplane tickets, there should be only one
INFO statement per each ticket saying “[Who] booked ticket from [Where] to
[Where]“. Other definition of INFO message: each action that changes the state
of the application significantly (database update, external system request).
DEBUG – Developers stuff. Error messages and Exceptions
that will help the developers to quickly identify bugs and application failures.
TRACE – Very detailed information, intended only for
development. You might keep trace messages for a short period of time after
deployment on production environment, but treat these log statements as temporary,
which should or might be turned-off eventually. The distinction between DEBUG
and TRACE is the most difficult, but if you put logging statement and remove it
after the feature has been developed and tested, it should probably be on TRACE
level.
Its quite common sense that more you log, more you perform
file IO that slows down your application. That's why choosing correct java
logging level for every single message is quite important. Since having no java
logging is not a choice you have to have logging in java application,
what you can control is log level and log messages on that level.
4.2 Configuration
file
Logging frameworks will read the configuration from a property
or xml file. Here we will see how to
configure log4j using property file.
log4j.properties
#
Root logger option
log4j.rootLogger=INFO,
file
#
Direct log messages to a log file
log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=C:\logging.log
log4j.appender.file.MaxFileSize=1MB
log4j.appender.file.MaxBackupIndex=2
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d{yyyy-MM-dd
HH:mm:ss} %-5p %c{1}:%L - %m%n
In the above example, we set the log level to INFO, the log
file name is C:\logging.log and it will be rolled over upon reaching the size
1MB. Choosing a correct pattern is important since it will help to identify the
date, time and level during log analysis.
The log4j.properties should be passed to JVM using the argument as shown
below.
java –Dlog4j.configuration=C:\log4j.properties
5.
Best
Practices
5.1 Format of log
statements
If the log information contains the file name, function etc.,
it will help to locate the problematic code quickly.
Ø
Always create the logger for each file using the
file name as shown below. Logger log = Logger.getInstane(“FileName”);
Ø
Use of function name while logging will help
identification process. For example,
log.info(“getEmailRecords() : Returning “ + count + “ Records); conveys
that the function getEmailRecords() returns
number of records to the caller.
Ø
Tune your pattern: Logging pattern is a
wonderful tool that transparently adds a meaningful context to every logging
statement you make. But, you must consider very carefully which information to
include in your pattern. For example, logging date when your logs roll every
hour is pointless as the date is already included in the log file name. On the
contrary, without logging the thread name you would be unable to track any
process using logs when two threads work concurrently – the logs will overlap.
This might be fine in single-threaded applications – that are almost dead
nowadays. From my experience, the ideal logging pattern should include (of course
except the logged message itself): current time (without date, milliseconds
precision), logging level, name of the thread, simple logger name (not fully
qualified) and the message.
5.2 Dos and Don’ts
Ø
Be concise and
descriptive. Each logging statement should contain both data and
description. Consider the following examples:
log.debug("Message
with id + message.getJMSMessageID() + “ processed");
Ø
Log all Exceptions
without fail. If an Exception occurs, log the detailed information
before returning to caller. For example,
try {
Connection
dbConnection = ConnectionManager.openConnection(username, password);
…
} catch (Exception ex) {
log.error(“getDbConnection()
: Error opening data base connection “ + ex.getMessage());
log.error(“getDbConnection()
: Host = … Port = … Username = … “);
}
…
getDBConnection() method logs the error message during
exception. openConnection() also would have logged error. This will help to
trace the root cause quickly.
Ø
Log all validation
errors. It is important to log
the error message when validation of user input/number/array index etc. fails.
try {
int
xValue = Integer.parseInt(usernput);
} catch (NumberFormatException
ex) {
log.error(“validateInput()
: Invalid Number “ + ex.getMessage());
}
Ø
Log all connection
problems/interface errors. If there is any problem while opening
database, socket, http, web service connection etc., log the error along with
debug information like host name, port number, URL, protocol.
Ø
Log null values when
appropriate. If execution of a method cannot continue due to null
values, log it.
if(null
== dbConnection) {
log.info(“getEmailRecords() : DB
connection null, returning null”);
return null;
}
Ø
Log outgoing result.
If a method return returns result in from of array, collections, log the count/size
etc. This will be useful for reconciliation with caller log.
public ArrayList<Object> getEmailRecords() {
…
…
log.info(“getEmailRecords() : Returning Email Records. Count = “ + result.size());
return result;
}
Ø
Log incoming data from
external components. This is the special case of the previous tip: if
you communicate with an external system, consider logging every piece of data
that comes out from your application and gets in. Period. Integration is a
tough job and diagnosing problems between two applications (think two different
vendors, environments, technology stacks and teams) is particularly hard.
Ø
Log intermediate result.
While fetching data from database, web service, socket etc., log the
details before processing.
try {
ResultSet result
= conn.executeQuery(…);
if(null !=
result) {
log.info(“getEmailRecords() : Fetched “ + result.size() + “ records from DB”);
}
}
Ø
Do not log confidential
information. Care should be taken not to log confidential information
like Password, SSN, Credit Card Number, PIN, CVV etc., in log files. If logged during testing, remove them before
deploying in production.
Ø
Do not log large data.
Do not log large objects like file contents, XML data, HTML pages etc. If you
log too much, logging has a performance side effect.
6.
Conclusion
This document contains basic guidelines to diagnose defect
resolution through improved logging. However these are not the complete and
best guidelines. Continue to learn from your experience also and improve the
logging of applications.
7.
References
Comments
Post a Comment