Kohei Nozaki's blog 

Entries tagged [logging]

java.util.logging: Programmatic configuration and logging with Java8 lambdas


Posted on Monday Mar 30, 2015 at 06:24PM in Technology


Configuration

We can put configurations in following places (ordered by priority):

  1. java.util.logging.config.class system property. specify FQCN of a class here

  2. java.util.logging.config.file system property. specify the path to a property file here

  3. $JAVA_HOME/lib/logging.properties file. put JRE-wide configuration here

Use of java.util.logging.config.class is most flexible. in that way we can simply put a config class under src/test/java for unit tests. we need to put configuration procedures in the default constructor. an implementation would be something like following:

package testutil;

import java.util.logging.*;

public class LoggingConfig {
    public LoggingConfig() {
        try {
            // Load a properties file from class path that way can't be achieved with java.util.logging.config.file
            /*
            final LogManager logManager = LogManager.getLogManager();
            try (final InputStream is = getClass().getResourceAsStream("/logging.properties")) {
                logManager.readConfiguration(is);
            }
            */

            // Programmatic configuration
            System.setProperty("java.util.logging.SimpleFormatter.format",
                    "%1$tY-%1$tm-%1$td %1$tH:%1$tM:%1$tS.%1$tL %4$-7s [%3$s] (%2$s) %5$s %6$s%n");

            final ConsoleHandler consoleHandler = new ConsoleHandler();
            consoleHandler.setLevel(Level.FINEST);
            consoleHandler.setFormatter(new SimpleFormatter());

            final Logger app = Logger.getLogger("app");
            app.setLevel(Level.FINEST);
            app.addHandler(consoleHandler);
        } catch (Exception e) {
            // The runtime won't show stack traces if the exception is thrown
            e.printStackTrace();
        }
    }
}

If you prefer configuration in a property file rather than a config class, following will work as the same to config class:

handlers=java.util.logging.ConsoleHandler
java.util.logging.ConsoleHandler.formatter=java.util.logging.SimpleFormatter
java.util.logging.SimpleFormatter.format=%1$tY-%1$tm-%1$td %1$tH:%1$tM:%1$tS.%1$tL %4$-7s [%3$s] (%2$s) %5$s %6$s%n

java.util.logging.ConsoleHandler.level=FINEST
app.level=FINEST

To set system property for every test execution, put following plugin definition to your pom.xml. note that IntelliJ IDEA respects this configuration in its test execution.

<plugin>
    <artifactId>maven-surefire-plugin</artifactId>
    <version>2.18.1</version>
    <configuration>
        <systemPropertyVariables>
            <java.util.logging.config.class>
                testutil.LoggingConfig
            </java.util.logging.config.class>

            <!-- If you prefer a file this will work too -->
            <!--<java.util.logging.config.file>-->
                <!--src/test/resources/logging.properties-->
            <!--</java.util.logging.config.file>-->
        </systemPropertyVariables>
    </configuration>
</plugin>

Logging examples

Application class:

public class MyClass {
    private static final Logger log = Logger.getLogger(MyClass.class.getName());
    public String hello(String greetings, String name) {
        // entering will be logged as FINER
        log.entering(MyClass.class.getName(), "hello", new Object[]{greetings, name});

        // lambdas
        log.finest(() -> "finest: " + LocalDateTime.now());
        log.finer(() -> "finer: " + LocalDateTime.now());
        log.fine(() -> "fine: " + LocalDateTime.now());
        log.info(() -> "info: " + LocalDateTime.now());
        log.warning(() -> "warning: " + LocalDateTime.now());
        log.severe(() -> "severe: " + LocalDateTime.now());

        // exception logging

        // throwing will be logged as FINER
        log.throwing(MyClass.class.getName(), "hello", new Exception("test"));

        // exception + message logging with lambda
        log.log(Level.FINEST, new Exception("test"), () -> String.format("arg=%s", name));

        // exception + parameter logging with LogRecord
        final LogRecord record = new LogRecord(Level.FINEST, "arg={0}");
        record.setThrown(new Exception("test"));
        record.setLoggerName(log.getName()); // logger name will be null unless this
        record.setParameters(new Object[]{name});
        log.log(record);

        final String rc = greetings + ", " + name;

        // exiting will be logged as FINER
        log.exiting(MyClass.class.getName(), "hello", rc);
        return rc;
    }
}

Test:

public class MyClassTest {
    @org.junit.Test
    public void testHello() throws Exception {
        MyClass sut = new MyClass();
        Assert.assertEquals("Hello, Kyle", sut.hello("Hello", "Kyle"));
    }
}

Output:

2015-03-30 18:01:19.362 FINER   [app.MyClass] (app.MyClass hello) ENTRY Hello Kyle
2015-03-30 18:01:19.425 FINEST  [app.MyClass] (app.MyClass hello) finest: 2015-03-30T18:01:19.425
2015-03-30 18:01:19.427 FINER   [app.MyClass] (app.MyClass hello) finer: 2015-03-30T18:01:19.427
2015-03-30 18:01:19.428 FINE    [app.MyClass] (app.MyClass hello) fine: 2015-03-30T18:01:19.428
2015-03-30 18:01:19.429 INFO    [app.MyClass] (app.MyClass hello) info: 2015-03-30T18:01:19.429
2015-03-30 18:01:19.431 WARNING [app.MyClass] (app.MyClass hello) warning: 2015-03-30T18:01:19.430
2015-03-30 18:01:19.433 SEVERE  [app.MyClass] (app.MyClass hello) severe: 2015-03-30T18:01:19.433
2015-03-30 18:01:19.434 FINER   [app.MyClass] (app.MyClass hello) THROW
java.lang.Exception: test
	at app.MyClass.hello(MyClass.java:27)
	at app.MyClassTest.testHello(MyClassTest.java:10)
...

2015-03-30 18:01:19.439 FINEST  [app.MyClass] (app.MyClass hello) arg=Kyle
java.lang.Exception: test
	at app.MyClass.hello(MyClass.java:30)
	at app.MyClassTest.testHello(MyClassTest.java:10)
...

2015-03-30 18:01:19.442 FINEST  [app.MyClass] (app.MyClass hello) arg=Kyle
java.lang.Exception: test
	at app.MyClass.hello(MyClass.java:34)
	at app.MyClassTest.testHello(MyClassTest.java:10)
...

2015-03-30 18:01:19.447 FINER   [app.MyClass] (app.MyClass hello) RETURN Hello, Kyle