javascriptjavaphprubydotnet

Where are Java errors logged?

Logging errors is an essential component in any application as it allows developers to track the root cause of errors and fix them easily. By default, Java log messages are stored only on the console, but they can be transferred to a longer term location as well. These messages let you see what’s happening in your application and troubleshoot problems.

Console logs

At the most basic level, Java errors are logged on the console. Developers typically call System.out.println() to print log messages on the console. Whenever the console is closed, these messages are lost as they cannot be stored in any permanent location. To overcome this problem, developers use logging frameworks which are responsible for storing data to any other location such as a file or a database.

Logging frameworks

There are several common frameworks for logging in Java and they let you customize where your logs are sent. Logback and Log4j are two popular frameworks that are simple to use. Logback was built as a replacement for its predecessor, Log4j. Logback offers a faster implementation than Log4j, provides more options for configuration, and gives more flexibility in archiving old log files. The newest is log4j 2 but it's still catching up in adoption.

Let's focus on Logback since it offers many improvements and is very common. The Logback architecture consists of three main classes: logger, appender, and layout. The appender determines where the logs are sent.

A logger is a class that applications interact with to create log messages. Layouts prepare messages for outputting. Logback supports the creation of custom classes for formatting messages, as well as robust configuration options for the existing ones. Appenders transfer log messages to their final destinations. A logger can have more than one appender such as ConsoleAppender, FileAppender, RollingFileAppender, etc. We generally think of appenders as being attached to text files, but Logback also offers network outputs like syslog.

A logging framework like Logback is declared as a dependency. When using Maven, it'll be added in the pom.xml file.

<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
  <version>1.2.3</version>
</dependency>

The configuration file is where the layouts and appenders are declared. Look for a text file named logback.xml. It should be located somewhere in the project classpath. In this example, you can see it's set to log to standard output on the console:

<configuration>
  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>
  <root level="debug">
    <appender-ref ref="STDOUT" />
  </root>
</configuration>

Log files

With Logback, log files can be created by adding a file appender in the configuration file.

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
  <file>tests.log</file>
  <append>true</append>
  <encoder>
    <pattern>%-4relative [%thread] %-5level %logger{35} - %msg%n</pattern>
  </encoder>
</appender>

In the example below, we’ve created a log file named test.log that generates an example message stored in the test.log file.

public class Example {
  private static final Logger logger = LoggerFactory.getLogger(Example.class);

  public static void main(String[] args) {
    logger.info("Example log from {}", Example.class.getSimpleName());
  }
}

Here is the log message of test.log file which contains the date and time of the message and a description of the generated message:

20:34:22.136 [main] INFO Example - Example log from Example

Log levels

There are five different levels in the logger class. Each level has a different priority; from lowest to highest they are debug, info, warn, error, and fatal. This is useful to tune what level of detail you wish to view or record in the logs, and can be helpful to filter on the highest impact problems. If you are debugging a problem you’ll want debug logs, but production applications may run more efficiently if you record only info and above.

Fatal: This is the highest priority log message, a severe issue that causes premature termination. These issues are expected to be immediately visible on the console. logger.fatal("Fatal Message") method is used to display this type of message.

Error: These are runtime issues or unexpected conditions that need to be caught or the application will exit. They often indicate bugs or failures in dependent systems. We can display the error messages using the logger.error("Error Message") method.

Warning: This type of log is at a level lower than the error level. It often arises due to the use of deprecated APIs and other runtime situations that are undesirable but the program is able to continue processing. The logger.warn("Warning Message") method displays this type of message.

Info: This displays the informational messages to indicate the progress of an application using the logger.info("Information Message") method. It shows the runtime events such as startup or shutdown. Informational events often give clues to the cause of following errors.

Debug: logger.debug("Debug Message") shows the most verbose information, which is useful to debug the application. Leaving this level on all the time can produce a lot of noisy data.

Log formats

The major problem with log files is that by default, they are typically unstructured text data. This makes it hard to query them for any sort of useful information. As a developer, it would be nice to be able to filter all logs by the application name or the severity of the event. The goal of log formats is to solve these sorts of problems and allow additional analytics.

The format of Java logs is determined by the logging framework you use. Let’s look at the format of log4j logs. A simple example will help make it clear what log formatting really is. Generally you write to a log file as shown below:

public class TestClass {
  private static final Logger logger = LoggerFactory.getLogger(TestClass.class);
  public static void main(String[] args) {
    logger.debug("This is debug");
  }
}

This example would simply produce a message in your logs, which isn’t very useful for troubleshooting or analysis.

This is debug

You can format the logs using the log4j pattern layout to add helpful metadata. To do this you need to add a ConversionPattern in the log4j.properties file.

log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d %p %t %c %m

In the example above, the ConversionPattern contains a combination of conversion characters: %d denotes date and time, %p is for log level, %t is used to print the name of the thread, %c is used to output the name of class, and %m is used to print the application-supplied message associated with the logging event.

2018-12-15 01:35:32,279 DEBUG main com.example.demo.TestClass This is debug

The log starts with the date and time of log. This is followed by the log level, whether it is INFO, ERROR, WARNING, FATAL, or DEBUG. It contains the method name and source class. It also contains the log message giving a brief description about the log. This additional information tells us when and where the message was generated.

To make log files machine readable and to add more advanced functionalities, we recommend using a structured format that can be easily parsed. This could be XML, JSON, or other formats. JSON is the most popular, so you are most likely to see JSON for structured logging. Most log management solutions like Loggly and Splunk can ingest and index each of the fields for fast searching.

With logback, you can specify a JSON layout along with the required logging fields. It will produce a JSON log as shown below:

{ "time": "2018-12-04 21:42:20", "level": "DEBUG ", "message": "This is debug" }

Logging in Spring

Spring provides central control for logging. In fact, logging is the only mandatory external dependency. It integrates with lots of other tools so you have plenty of choices. By default, Spring (spring-core) uses JCL (commons-logging) for logging. JCL has a runtime discovery algorithm to find out for other logging frameworks in well known places on the project classpath.

Using Log4j

One popular choice is to use the Log4j logging framework. Spring provides some utilities for configuring and initializing Log4j, so it has an optional compile time dependency on Log4j in some modules.

To integrate Log4j you need to put Log4j on the classpath and provide it with a configuration file (log4j.properties or log4j.xml in the root of the classpath). Here is the dependency declaration for Maven users:

<dependencies>
  <dependency>
    <groupId>log4j</groupId>
    <artifactId>log4j</artifactId>
    <version>${log4j.version}</version>
  </dependency>
</dependencies>

Next, you need to create a log4j.properties file and add to the resource folder in {project-directory}/src/resource. Here’s a sample log4j.properties file for logging to the console:

log4j.rootCategory=INFO, stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{ABSOLUTE} %5p %t %c{2}:%L - %m%n
log4j.category.org.springframework.beans.factory=DEBUG

A simple controller will return a welcome page. Furthermore, it shows you how to use log4j by creating and using the Logger object.

import org.apache.log4j.Logger;
import org.springframework.stereotype.Controller;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestMethod;
import org.springframework.web.servlet.ModelAndView;

@Controller
public class WelcomeController {

  private static final Logger logger = Logger.getLogger(WelcomeController.class);

  @RequestMapping(value = "/", method = RequestMethod.GET)
  public ModelAndView getWelcome() {

    // logs debug message
    if (logger.isDebugEnabled()) {
      logger.debug("getWelcome is executed!");
    }

    // logs exception
    logger.error("This is Error message", new Exception("Testing"));

    ModelAndView model = new ModelAndView("welcome");
    model.addObject("msg", "Hello Spring MVC + Log4j");
  return model;
  }
}

The generated log output of above controller looks like this:

2018-10-23 14:10:35 DEBUG WelcomeController:19 - getWelcome is executed!
2018-10-23 14:10:35 ERROR WelcomeController:23 - This is Error message
java.lang.Exception: Testing
        at com.mkyong.common.controller.WelcomeController.getWelcome(WelcomeController.java:23)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)

Using Logback

Logback is intended as a successor to the log4j project. There are several reasons Logback is a better choice for a logging framework than Log4j, including that it is faster, it has native support for slf4j, and it has automatic reloading of configuration files. Check out the Logback installation guide to learn how to include Logback in your Spring app.