03
Thu, Oct
2 New Articles

Java Journal: Log4j

Java
Typography
  • Smaller Small Medium Big Bigger
  • Default Helvetica Segoe Georgia Times

Logging is generally one of those real-world complexities that isn't taught in school. Instead, it's learned as a best practice that's passed down from a coding guru to future coding gurus. Most applications of significant size, whether they are written in Java or not, tend to evolve logging frameworks. I say "evolve" because, unfortunately, it has been my experience that logging is usually put into a system long after the initial development. In fact, in many cases, it is usually developed in response to some heinous system problem that can't be tracked down through traditional techniques, such as walking the code with a debugger.

Typically, there are three cases when using a debugger is ineffective. The first case is when you are dealing with threading issues. Threading issues are often difficult to debug because of what is referred to as the Heisenberg Uncertainty Principle (HUP), which simply states that some phenomenon cannot be observed directly because the physical act of observation may interfere with the results. In the case of threading issues, which are often the result of race conditions, the act of attaching a debugger almost always skews the results. The second case where debugging is ineffective is on distributed systems. Although it is now easier than ever to attach and debug into a server, things can get dicey when you have multiple distributed servers. Also, as with threading problems, you may run into the HUP. In fact, you can almost think of distributed systems as being a generalization of the threading problem, where each server is analogous to a thread. The third--and often overlooked--difficult situation to debug occurs when you have the "random" bug. We have all run into these little beasts before. This type of bug is difficult to reproduce or seems to happen only when all the planets are in a certain alignment. Walking code in search of a bug like this can be extremely time-consuming and often yields nothing but frustration.

What are the Criteria for a Good Logging Framework?

So we know that we need logging frameworks, but what criteria do we have for them? Like all frameworks, logging frameworks need to be reliable, fast, flexible, and easy to use. Let's explore each of these attributes in detail.

Reliable

First and foremost, any kind of logging system must be reliable. Here is a counter-example. One of the first projects that I worked on right out of school (during the ancient days of two-tiered client/server architecture) had a requirement for all "serious" errors to be logged. Not knowing how valuable logging could be to development, the task was one of the final pieces of the system to be worked on. Since the term "serious" was never well-defined in the specification, the programmer implementing the logger decided to log everything from invalid user input to disk write failures. The logs were all being appended to a single file on the server, which of course led to an enormous amount of contention between transactions for the services of that file. In a last ditch effort to alleviate the situation, it was decided that all the errors should instead be logged to a relational database. The problem was that the first time the logging database was bounced, two separate errors about the database being unavailable were recorded. Each "serious" error in turn spun up two "serious" errors each and so on and so on in geometric progression until a second or two later when everything came to a grinding halt. Did I mention this was all during a customer acceptance test? Anyway, lesson learned: Logging frameworks must be extremely reliable and must not lead to recursive logging.

Fast

Although we may want to put a logging framework into a client-side application, speed is probably not going to be much of an issue. However logging on a server, especially if it is going to be extensive, needs to be fast. According to Apache, it has been their experience that approximately 4% of a typical code base is logging.

Flexible

Logging frameworks should be flexible in both where and what they log. For example, you should be able to log a single entry to multiple locations. Since you have to be careful about recursive logging, sending log entries to multiple monitored locations is a good protection against a failure scenario in which the resource being logged to is down. In addition, what is being logged should be configurable. Generally, there are times when you want more or less detail in your logs or you want information on all failures or just catastrophic ones. The more flexibility you have in this area, the easier it is going to be to track down the information you want.

Easy to Use

I don't care how good your logging framework is, it needs to be easy to use and easy to understand. If it's too complicated or difficult, developers are going to revert to using System.out.println(). So either they are going to clutter up system out with a bunch of garbage that can't be turned off or they are going to put in and remove each println() by hand when they need it. I know most people are really against it, but sometimes I do wish Java had a preprocessor like C/C++.

Log4j

So once again it's the open-source gurus at Apache Jakarta Project to the rescue. Let's see how their Log4j logger framework stacks up against our criteria.

Our first attribute is reliability, and in Apache's own words, "log4j is not reliable. It is a best-effort and fail-stop logging system." Although this statement implies that Log4j fails our criteria, it really doesn't. What they mean is that it can't be guaranteed to log every error. However, they have gone to extraordinary lengths to make sure that it will not throw any uncaught exceptions that would crash the application it is being run in.

Our next criteria is that it's fast, and yes, it is very fast. Although it does require a minimal amount of processing for provisioning each call and determining if a particular logging level has been enabled or not, the impact on your system will be negligible. They even have a few tricks you can use for those of you with servers in which every cycle counts, but like most optimizations, I don't recommend using these unless you absolutely have to.

Flexibility is where Log4j really shines. You can log to multiple locations in multiple formats as well as set different levels of logging and change them on the fly.

As for ease of use, that is up to you to decide after looking at the following examples. For these examples, you will need the binary distribution of Log4j from the Apache Jakarta Project Log4j Project. As of the writing of this article, the current version is 1.2.8. Download the package and add the src directory to your classpath.

Example 1: Basic Logging

For our first example, we will start with the following class:

// Log4jTest.java
import org.apache.log4j.Logger;
import org.apache.log4j.BasicConfigurator;

public class Log4jTest
{
  static Logger logger = Logger.getLogger(Log4jTest.class);

  public static void main(String[] args)
  {
    BasicConfigurator.configure();
    logger.debug("Begin Application");

    // Put application here

    logger.debug("End Application"); 
  }
}

In our example above, we are using two classes from the Log4j API: Logger and BasicConfigurator. Logger is the central class to the API; everything within the API exists as support for either using or configuring a Logger. Our second class is BasicConfigurator, which we will normally want to replace at some point down the road, but for now, it sets up a lot of defaults for us. Note that almost everything done with the Log4J API uses static classes and methods. This is done so that we don't have to continually pass around references to our Logger(s).

After the import statements and the declaration of the class, we create a static reference to a logger class using the static method Logger.getLogger(Log4jTest.class). Loggers are all named by the string passed in to the getLogger() method. So in this case, we have created a Logger called Log4jTest. Since only one logger with a given name can exist at a time, if one with this exact name had already existed, instead of creating a new Logger, we would have been given a reference to the existing one. Note the similarities between this and the singleton design pattern.

Next, we declare main() followed by a static call to BasicConfigurator.configure(). This method, as the name implies, will set up a number of basic configurations for us automatically. Most notably, it sets up the Logger to send its output to the console. It will set a standard format for the logging as well as a standard logging level. We will go into more details on each of these configurations later.

Now, we make two calls to logger.debug(), each of which will be logged to the console, based on the configuration provided by BasicConfigurator. The resulting output looks like this:

0 [main] DEBUG Log4jTest  - Begin Application0 [main] DEBUG Log4jTest  - End Application

Example 2: Sharing a Logger

For our next example, we will show how two classes can share a logger. First, we will modify our example above to create a new instance of a class called SampleApplication. The modified source code looks like this:

// Log4jTest.java
import org.apache.log4j.Logger;
import org.apache.log4j.BasicConfigurator;

public class Log4jTest
{
  static Logger logger = Logger.getLogger(Log4jTest.class);

  public static void main(String[] args)
  {
    BasicConfigurator.configure();
    logger.debug("Begin Application");

    new SampleApplication();

    logger.debug("End Application");
  }
}

Our new SampleApplication class looks like this:

// SampleApplication.java
import org.apache.log4j.Logger;

public class SampleApplication
{
  static Logger logger = Logger.getLogger(Log4jTest.class);

  SampleApplication()
  {
    logger.debug("Application Constructor");
  }
}

In our new SampleApplication class, we also request a static reference to the Log4jTest logger, and since one already exists, we will just give a reference to it. It has already been configured, so we don't need to include BasicConfigurator. Note in our source the addition of a call to logger.debug() in SampleApplication's constructor. The console output for our application is now as follows:

0 [main] DEBUG Log4jTest  - Begin Application

10 [main] DEBUG Log4jTest  - Application Constructor

10 [main] DEBUG Log4jTest  - End Application

Loggers, Appenders, and Layouts

Log4j has three basic concepts: loggers, appenders and layouts. As we have seen in our above two examples, loggers are the sources of information. When we get to a particular situation that we think is noteworthy, we call a method on the logger. Appenders are the natural reciprocal of loggers: They are the destinations for what is to be logged, and one of the key features of Log4j is that we can have multiple appenders for a single logger. Our final concept is that of a layout, which is simply a template for "pretty printing" of your appender. Another nice feature is that each appender can have its own layout.

Example 3: Multiple Appenders

For our next example, we will modify our previous example to have an additional appender that sends its results to a file. Changes only need to be made to Log4jTest.java:

// Log4jTest.java
import org.apache.log4j.Logger;
import org.apache.log4j.BasicConfigurator;
import org.apache.log4j.FileAppender;
import org.apache.log4j.PatternLayout;

public class Log4jTest
{
  static Logger logger = Logger.getLogger(Log4jTest.class);

  public static void main(String[] args)
  {
    PatternLayout patternLayout = new PatternLayout();
    patternLayout.setConversionPattern("%d %r [%t] %-5p %c - %m%n");

    try
    {
      FileAppender fileAppender = 
        new FileAppender(patternLayout,"Log4jTest.log");
      BasicConfigurator.configure(fileAppender);
    }
    catch (java.io.IOException e){}

    BasicConfigurator.configure();
    logger.debug("Begin Application");

    new SampleApplication();

    logger.debug("End Application");
  }
}

In this example, we have added two new classes: PatternLayout and FileAppender. We simply instantiate a new PatternLayout and then provision it with a pattern. Each of the characters preceded by a percentage mark (%) will be replaced with a certain value. (For a table of all possible values, see the Log4j documentation, as the list is rather extensive.)
For our example, we have preserved the default pattern used in our previous example with the exception of prepending it with a date/time stamp represented by the "%d". Next, we create a FileAppender and provision it with our new pattern layout and a file name. Our last change is to then add this FileAppender to our basic configuration. Now, if we run the application again, we will see that the console output is identical to that of Example 2:

0 [main] DEBUG Log4jTest  - Begin Application

10 [main] DEBUG Log4jTest  - Application Constructor

10 [main] DEBUG Log4jTest  - End Application

These are the contents of our newly created Log4jTest.log file:

2003-11-09 19:06:37,136 0 [main] DEBUG Log4jTest - Begin Application
2003-11-09 19:06:37,146 10 [main] DEBUG Log4jTest - Application Constructor
2003-11-09 19:06:37,146 10 [main] DEBUG Log4jTest - End Application

Remember that your log files are appenders and that the application will keep adding entries to the end of the file each time you run it. This is one of the reasons I always add the date/time stamps to the front of each entry.

Example 4: Levels of Logging

Log4j in its standard configuration provides five levels of logging, each considered to be successively more important: debug, info, warn, error, and fatal. You can adjust your logger to any of the five levels, and it will log messages from that level or that of any higher level. In other words, if we set the logging level to warn, we would get messages for warn, error, and fatal but not for debug or info. You set a log messages level by calling the method corresponding to the name of the level.

// SampleApplication.java
import org.apache.log4j.Logger;

public class SampleApplication
{
  static Logger logger = Logger.getLogger(Log4jTest.class);

  SampleApplication()
  {
    logger.debug("Debug Message");
    logger.info("Info Message");
    logger.error("Error Message");
    logger.warn("Warn Message");
    logger.fatal("Fatal Message");
  }
}

Here, we have added a logging level for each message. The corresponding output looks like this:

0 [main] DEBUG Log4jTest  - Begin Application

10 [main] DEBUG Log4jTest  - Debug Message

10 [main] INFO Log4jTest  - Info Message

10 [main] ERROR Log4jTest  - Error Message

10 [main] WARN Log4jTest  - Warn Message

10 [main] FATAL Log4jTest  - Fatal Message

10 [main] DEBUG Log4jTest  - End Application

To set the level of logging you desire, just call the setLevel method on your logger. The call would look like this to change the level to debug:

logger.setLevel((Level) Level.DEBUG);

Note that it is also possible to create your own developer-assigned logging levels, but it is not encouraged by the authors of Log4j.

Best Practices

Configure your loggers at application initialization and use configuration files. Log4j has direct support for property files and XML files. In fact, you can even set up listeners so that if you swap out the configuration files, your application will pick up the changes at runtime. Also, don't forget about our debugger nemesis--the Heisenberg Uncertainty Principle, which can come into play when changing logging levels. Although not as intrusive as a debugger, loggers have been known to cause anomalies. And be careful what you log. Most applications have data that they need to keep secret, so be cautious when handling sensitive data such as passwords, encryption keys, social security numbers, or credit card numbers. There's no point in keeping your database secure if you log out all the data that goes into it. And finally, don't forget that Log4j is open-source, so if you want to integrate it into your platform or tool, feel free to do so. Just remember to submit changes back to the community.

Other Related Tools

Chainsaw--This is a great graphical tool for viewing and filtering logs and is now included in the standard Log4j distribution.

log4Unit--Log4j and junit are being used in conjunction with one another to not only prove that a test passes but to record what happened behind the scenes to make the test pass.

log4j400--This includes MessageQueues and DataQueues appenders for your iSeries.

Log4j has also been ported to just about every major computer language. You can get a current list of supported languages from the Apache Jakarta Project.

Conclusion

Use a logging framework from the beginning of a project. You are going to wind up adding one at some point anyway, so put it in when it can help speed up your development by assisting you in finding errors. In addition, a logging framework that is part of your overall configuration from the start is far more likely to fit in with your overall application architecture. Log4j meets all four of our criteria for a good logging framework. It is reliable, fast, and flexible and, after analyzing the examples above, I'm sure you will agree that it is easy to use. The best feature of Log4j is its flexibility--from formatting your results the way you want them to setting up multiple redundant logging targets, it can all be done with Log4j. Still not enough to entice you? In addition to what I have shown here, you can set up a named hierarchy of Loggers or experiment with contexts that give you detailed information about the state of the system at the time you call a log entry. And if you still crave more, try out Chainsaw, log4Unit, log4j400, or any of the other dozen or so Java Log4j extensions.

Michael J. Floyd is an extreme programmer and the Software Engineering Manager for DivXNetworks. He is also a consultant for San Diego State University and can be reached at This email address is being protected from spambots. You need JavaScript enabled to view it..

Michael Floyd

Michael J. Floyd is the Vice President of Engineering for DivX, Inc.

BLOG COMMENTS POWERED BY DISQUS

LATEST COMMENTS

Support MC Press Online

$

Book Reviews

Resource Center

  • SB Profound WC 5536 Have you been wondering about Node.js? Our free Node.js Webinar Series takes you from total beginner to creating a fully-functional IBM i Node.js business application. You can find Part 1 here. In Part 2 of our free Node.js Webinar Series, Brian May teaches you the different tooling options available for writing code, debugging, and using Git for version control. Brian will briefly discuss the different tools available, and demonstrate his preferred setup for Node development on IBM i or any platform. Attend this webinar to learn:

  • SB Profound WP 5539More than ever, there is a demand for IT to deliver innovation. Your IBM i has been an essential part of your business operations for years. However, your organization may struggle to maintain the current system and implement new projects. The thousands of customers we've worked with and surveyed state that expectations regarding the digital footprint and vision of the company are not aligned with the current IT environment.

  • SB HelpSystems ROBOT Generic IBM announced the E1080 servers using the latest Power10 processor in September 2021. The most powerful processor from IBM to date, Power10 is designed to handle the demands of doing business in today’s high-tech atmosphere, including running cloud applications, supporting big data, and managing AI workloads. But what does Power10 mean for your data center? In this recorded webinar, IBMers Dan Sundt and Dylan Boday join IBM Power Champion Tom Huntington for a discussion on why Power10 technology is the right strategic investment if you run IBM i, AIX, or Linux. In this action-packed hour, Tom will share trends from the IBM i and AIX user communities while Dan and Dylan dive into the tech specs for key hardware, including:

  • Magic MarkTRY the one package that solves all your document design and printing challenges on all your platforms. Produce bar code labels, electronic forms, ad hoc reports, and RFID tags – without programming! MarkMagic is the only document design and print solution that combines report writing, WYSIWYG label and forms design, and conditional printing in one integrated product. Make sure your data survives when catastrophe hits. Request your trial now!  Request Now.

  • SB HelpSystems ROBOT GenericForms of ransomware has been around for over 30 years, and with more and more organizations suffering attacks each year, it continues to endure. What has made ransomware such a durable threat and what is the best way to combat it? In order to prevent ransomware, organizations must first understand how it works.

  • SB HelpSystems ROBOT GenericIT security is a top priority for businesses around the world, but most IBM i pros don’t know where to begin—and most cybersecurity experts don’t know IBM i. In this session, Robin Tatam explores the business impact of lax IBM i security, the top vulnerabilities putting IBM i at risk, and the steps you can take to protect your organization. If you’re looking to avoid unexpected downtime or corrupted data, you don’t want to miss this session.

  • SB HelpSystems ROBOT GenericCan you trust all of your users all of the time? A typical end user receives 16 malicious emails each month, but only 17 percent of these phishing campaigns are reported to IT. Once an attack is underway, most organizations won’t discover the breach until six months later. A staggering amount of damage can occur in that time. Despite these risks, 93 percent of organizations are leaving their IBM i systems vulnerable to cybercrime. In this on-demand webinar, IBM i security experts Robin Tatam and Sandi Moore will reveal:

  • FORTRA Disaster protection is vital to every business. Yet, it often consists of patched together procedures that are prone to error. From automatic backups to data encryption to media management, Robot automates the routine (yet often complex) tasks of iSeries backup and recovery, saving you time and money and making the process safer and more reliable. Automate your backups with the Robot Backup and Recovery Solution. Key features include:

  • FORTRAManaging messages on your IBM i can be more than a full-time job if you have to do it manually. Messages need a response and resources must be monitored—often over multiple systems and across platforms. How can you be sure you won’t miss important system events? Automate your message center with the Robot Message Management Solution. Key features include:

  • FORTRAThe thought of printing, distributing, and storing iSeries reports manually may reduce you to tears. Paper and labor costs associated with report generation can spiral out of control. Mountains of paper threaten to swamp your files. Robot automates report bursting, distribution, bundling, and archiving, and offers secure, selective online report viewing. Manage your reports with the Robot Report Management Solution. Key features include:

  • FORTRAFor over 30 years, Robot has been a leader in systems management for IBM i. With batch job creation and scheduling at its core, the Robot Job Scheduling Solution reduces the opportunity for human error and helps you maintain service levels, automating even the biggest, most complex runbooks. Manage your job schedule with the Robot Job Scheduling Solution. Key features include:

  • LANSA Business users want new applications now. Market and regulatory pressures require faster application updates and delivery into production. Your IBM i developers may be approaching retirement, and you see no sure way to fill their positions with experienced developers. In addition, you may be caught between maintaining your existing applications and the uncertainty of moving to something new.

  • LANSAWhen it comes to creating your business applications, there are hundreds of coding platforms and programming languages to choose from. These options range from very complex traditional programming languages to Low-Code platforms where sometimes no traditional coding experience is needed. Download our whitepaper, The Power of Writing Code in a Low-Code Solution, and:

  • LANSASupply Chain is becoming increasingly complex and unpredictable. From raw materials for manufacturing to food supply chains, the journey from source to production to delivery to consumers is marred with inefficiencies, manual processes, shortages, recalls, counterfeits, and scandals. In this webinar, we discuss how:

  • The MC Resource Centers bring you the widest selection of white papers, trial software, and on-demand webcasts for you to choose from. >> Review the list of White Papers, Trial Software or On-Demand Webcast at the MC Press Resource Center. >> Add the items to yru Cart and complet he checkout process and submit

  • Profound Logic Have you been wondering about Node.js? Our free Node.js Webinar Series takes you from total beginner to creating a fully-functional IBM i Node.js business application.

  • SB Profound WC 5536Join us for this hour-long webcast that will explore:

  • Fortra IT managers hoping to find new IBM i talent are discovering that the pool of experienced RPG programmers and operators or administrators with intimate knowledge of the operating system and the applications that run on it is small. This begs the question: How will you manage the platform that supports such a big part of your business? This guide offers strategies and software suggestions to help you plan IT staffing and resources and smooth the transition after your AS/400 talent retires. Read on to learn: