Logging in Java

A school bus driver keeps a logbook: departure time, stops, fuel filled, anything unusual. On a normal day nobody reads it. But when a parent asks why the bus was late last Thursday, the logbook answers in seconds. Logging is the logbook of a program. System.out.println is fine while you learn, but real applications run on servers where nobody watches the console, so they write structured messages, with a time, a level and a source, to files and log systems. In this lesson, you will learn log levels, use the JDK's built-in java.util.logging and System.Logger, and see how most teams log with SLF4J and Logback.

What Is Logging?

Logging in Java is the practice of recording messages about a program's activity through a logging framework that is used to decide, without changing code, which messages are kept, how they look and where they go. Each message has a level, a logger name (usually the class), a time and optionally an exception.

Log Levels

Every framework has a ladder of levels. A logger set to one level shows that level and everything more severe.

The Built-In java.util.logging

The JDK includes a logging framework in java.util.logging, so it needs no extra libraries. By default it prints INFO and above to the error stream with a two-line format. Let's see an example that configures it to print one clean line per message to standard output.

import java.util.logging.Formatter;
import java.util.logging.Handler;
import java.util.logging.Level;
import java.util.logging.LogRecord;
import java.util.logging.Logger;
import java.util.logging.StreamHandler;
 
public class FeeLog {
    private static final Logger LOG = Logger.getLogger("school.fees");
 
    static int totalFee(String student, int base, int lateDays) {
        LOG.fine(() -> "calculating fee for " + student);    // lazy message
        if (lateDays > 0) {
            LOG.log(Level.INFO, "{0} paid {1} days late",
                    new Object[] {student, lateDays});
        }
        if (lateDays > 30) {
            LOG.warning("very late payment: " + student);
        }
        return base + lateDays * 500;
    }
 
    public static void main(String[] args) {
        Logger root = Logger.getLogger("");
        for (Handler h : root.getHandlers()) root.removeHandler(h);
        Handler out = new StreamHandler(System.out, new Formatter() {
            @Override
            public String format(LogRecord r) {
                String line = String.format("%-7s %s - %s%n", r.getLevel(),
                        r.getLoggerName(), formatMessage(r));
                return r.getThrown() == null ? line
                        : line + "        caused by " + r.getThrown() + "\n";
            }
        });
        out.setLevel(Level.ALL);
        root.addHandler(out);
 
        totalFee("Navika", 15000, 0);
        totalFee("Srihitha", 15000, 3);
        totalFee("Advitha", 14000, 45);
 
        LOG.setLevel(Level.FINE);                    // turn on debug detail
        totalFee("Navika", 15000, 0);
 
        try {
            Integer.parseInt("15,000");
        } catch (NumberFormatException e) {
            LOG.log(Level.SEVERE, "bad fee value", e);
        }
        out.flush();
    }
}

INFO    school.fees - Srihitha paid 3 days late
INFO    school.fees - Advitha paid 45 days late
WARNING school.fees - very late payment: Advitha
FINE    school.fees - calculating fee for Navika
SEVERE  school.fees - bad fee value
        caused by java.lang.NumberFormatException: For input string: "15,000"

Explanation:

1. Logger.getLogger("school.fees") gets a named logger. Names form a hierarchy with dots, so settings for school also apply to school.fees.
2. The first call logs nothing: the FINE message is below the default INFO level, and the payment isn't late.
3. {0} and {1} are placeholders filled from the array, so no string is built unless the message is actually logged.
4. LOG.fine(() -> ...) takes a lambda. The message is built only if FINE is enabled, which it is after setLevel(Level.FINE).
5. LOG.log(Level.SEVERE, "...", e) attaches the exception, so the formatter can print its cause. Always pass the exception object, not just its message.

System.Logger

Since Java 9, System.Logger is a small logging API in java.lang that libraries can use without choosing a framework. By default it sends messages to java.util.logging; if an application installs a different backend, the same calls go there instead.

import java.util.logging.Logger;
import java.util.logging.SimpleFormatter;
 
public class ReportLog {
    public static void main(String[] args) {
        System.setProperty("java.util.logging.SimpleFormatter.format",
                "%4$s %3$s - %5$s%n");
        Logger root = Logger.getLogger("");
        root.getHandlers()[0].setFormatter(new SimpleFormatter());
 
        System.Logger log = System.getLogger("school.report");
        log.log(System.Logger.Level.INFO, "report ready for {0} students", 3);
        log.log(System.Logger.Level.DEBUG, "not shown at the default level");
        System.out.println("done");
    }
}

done

Explanation: System.getLogger returns a logger backed here by JUL. The INFO message goes to JUL's console handler on the error stream (so it doesn't appear in the checked output above, only done does), formatted by the pattern set in the property; the DEBUG message is below the default level and is dropped.

SLF4J and Logback

Most Java applications and libraries log through SLF4J (Simple Logging Facade for Java): an API only, with a backend plugged in underneath. Logback is the most common backend (it is Spring Boot's default); Log4j 2 and JUL are alternatives.

With the org.slf4j:slf4j-api and ch.qos.logback:logback-classic libraries on the class path (added through Maven or Gradle), code looks like this:

package school.fees;
 
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
 
public class FeeService {
    private static final Logger log = LoggerFactory.getLogger(FeeService.class);
 
    int totalFee(String student, int base, int lateDays) {
        log.debug("Calculating fee for {}", student);
        if (lateDays > 30) {
            log.warn("{} paid {} days late", student, lateDays);
        }
        return base + lateDays * 500;
    }
 
    void importFees(String file) {
        try {
            Integer.parseInt("15,000");   // pretend we read this from file
        } catch (Exception e) {
            log.error("Could not import {}", file, e);   // exception last
        }
    }
 
    public static void main(String[] args) {
        FeeService service = new FeeService();
        service.totalFee("Navika", 15000, 0);
        service.totalFee("Advitha", 14000, 45);
        service.importFees("fees.csv");
    }
}

And Logback is configured with a logback.xml file in src/main/resources:

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

Running it with SLF4J 2.0.20 and Logback 1.6.6 on the class path prints:

09:44:23.760 [main] DEBUG s.fees.FeeService - Calculating fee for Navika
09:44:23.761 [main] DEBUG s.fees.FeeService - Calculating fee for Advitha
09:44:23.761 [main] WARN  s.fees.FeeService - Advitha paid 45 days late
09:44:23.761 [main] ERROR s.fees.FeeService - Could not import fees.csv
java.lang.NumberFormatException: For input string: "15,000"
    at java.base/java.lang.NumberFormatException.forInputString(NumberFormatException.java:67)
    at java.base/java.lang.Integer.parseInt(Integer.java:565)
    at java.base/java.lang.Integer.parseInt(Integer.java:662)
    at school.fees.FeeService.importFees(FeeService.java:19)
    at school.fees.FeeService.main(FeeService.java:29)

Explanation:

1. LoggerFactory.getLogger(FeeService.class) names the logger after the class, the usual convention.
2. {} placeholders are filled only if the level is enabled, so log.debug(...) costs almost nothing in production.
3. Passing the exception as the last argument after the placeholders makes SLF4J print its full stack trace.
4. The pattern adds time, thread, level and logger name to every line. %logger{20} shortens the logger name to about 20 characters, which is why school.fees.FeeService appears as s.fees.FeeService.
5. The root level is INFO, but <logger name="school.fees" level="DEBUG"/> turns on debug messages for that one package, so both DEBUG lines appear.

In Practice

Common Mistakes

Logging the exception message only. log.error(e.getMessage()) loses the stack trace. Pass e itself.

Two backends on the class path. SLF4J warns about multiple bindings and picks one. Keep exactly one backend.

Expensive work in log arguments. log.debug("Report: {}", buildHugeReport()) still calls the method. Wrap it in if (log.isDebugEnabled()), or use a lazy supplier.

Using System.out in server code. It can't be filtered, rotated or searched like real logs.

Practice

1. Easy: In FeeLog.java, change the level of school.fees to WARNING instead of FINE, and predict which lines are printed.
2. Harder: Write a logging.properties file that sends INFO and above to a file named fees.log with a FileHandler, and run FeeLog with -Djava.util.logging.config.file=logging.properties after removing the handler setup from main.

Key Takeaways