Java logging fun facts

I finally bit the bullet. I pulled out all the nice System.out.println() calls from my slideshow app and set up proper Java logging. I didn’t expect it to be easy – in all the hours I’ve spent debugging Java frameworks, the hardest thing is always trying to work out how to get things to actually appear in logs – and, sure enough, I accumulated a little list of things that were non-obvious. I’ve used slf4j as the logging façade, and java.util.logging (aka JDK 1.4 logging) as the implementation.

Handler levels vs logger levels

If you have:

.level = SEVERE
au.id.lagod.slideshow.level              = FINE
java.util.logging.FileHandler.level = INFO

what’s the actual log level? The first line gives the default log level. For packages in au.id.lagod.slideshow, this is overridden by the second line. The third line then gives the finest level that will be logged by the file handler. So in this case, the log file will actually only contain messages of level INFO and coarser. Another handler might accept the FINE messages that will be emitted by my app.

Logger specifications don’t need wildcards

Line 2 in the above snippet sets the log level for all classes in package au.id.lagod.slideshow and all it’s subpackages. So, if I want to get FINE logging in au.id.lagod.slideshow.*:

# THIS IS CORRECT:)
au.id.lagod.slideshow.level = FINE

# OR EVEN THIS
au.id.lagod.level = FINE

# OR THIS (if I don't mind being that inclusive)
au.id.level = FINE

# WRONG!!
au.id.lagod.slideshow.*.level = FINE

logging.properties does NOT use slf4j level names

If you use SLF4J, you use calls like logger.debug(), logger.info(), etc., to send strings to the logger. If you use java.util.logging (JDK 1.4 logging) as the logging provider, you configure the logger using a logging.properties file.

These guys do NOT use the same log level names. Doing a bunch of logger.debug() calls? In the logging.properties file:

# This shows logger.debug() messages
.level = FINE

# This is an error
.level = DEBUG

See here for the full translation between slf4j and j.u.l. log levels.

Specifying logging.properties in Eclipse

When launching from the command line, I specify the properties file in the first command line parameter, like this:

java -Djava.util.logging.config.file=./logging.properties -cp .:./*:lib/* au.id.lagod.slideshow.Runner

When launching in Eclipse, -Djava.util.logging.config.file goes into the VM arguments box of the Run configuration, NOT the application arguments box.

Where on earth is the log file?

OK, this is in the documentation, but I can tell you that if you google “java logging log file location” it will be many, many pages before you find an answer you can use. Before you get there, you’ll have to wade through gems of the documentation writer’s art such as:

java.util.logging.FileHandler.pattern: The log file name pattern.

So here’s a hot tip: java.util.logging.FileHandler.pattern actually is the log file name. It’s not a pattern, at least not in the regex sense. There are some handy placeholders for variables that can be interpolated into it, but you don’t have to use any of them. Just type the path you want. If you want to know about the placeholders, have a look at the Javadoc for FileHandler.