BrewlearnLogging in Java
SLF4J facade, log levels, parameterized messages vs string concatenation.
Facade and backend
SLF4J is a logging facade: an API your code calls. A backend such as Logback or Log4j 2 decides where and how messages are written. SLF4J itself writes nothing; swap the backend without touching your code.
Levels
Levels go TRACE < DEBUG < INFO < WARN < ERROR, and configuration decides which are shown. DEBUG: developer detail (*cache miss for user:42*). INFO: the normal story (*server started on 8080*). WARN: odd but handled (*retrying, attempt 2/3*). ERROR: an operation failed (*payment failed*).
Built for nothing
The JDK's java.util.logging disables FINE by default, just like a disabled DEBUG. What does this print?
import java.util.logging.Logger;
int built = 0;
String msg(String s) { built++; return s; }
void main() {
var log = Logger.getLogger("demo");
log.fine("A " + msg("x"));
log.fine(() -> "B " + msg("y"));
System.out.println(built);
}012
Show the answer
The first call builds "A " + msg("x") before fine() even runs, so msg executes although nothing is logged. The lambda version is only called if FINE is enabled. Result: 1.
A debug line in a hot loop
log.debug("Loaded " + items.size()
+ " items for " + user);Builds the string every time, even with DEBUG off.
log.debug("Loaded {} items for {}",
items.size(), user);SLF4J formats only if DEBUG is enabled.
Losing the stack trace
Concatenating e logs only its toString(): no stack trace, so nobody can see where the error came from. Pass the exception as the last argument instead: log.error("Charge failed for {}", order.id(), e);
} catch (PaymentException e) {
log.error("Charge failed: " + e); // bad
throw new CheckoutException(order.id(), e);
}What never goes in a log
Logs get shipped, indexed and kept for months, often readable by many people. Never log passwords, tokens, API keys or personal data. Log IDs instead of whole objects, and mask anything sensitive before it reaches a logger.
Key takeaways
- Facade (SLF4J) vs backend (Logback, Log4j 2)
- Placeholders {} avoid building disabled messages
- Pass the exception last to keep the stack trace
- Never log passwords, tokens or personal data
Log4Shell lived in a logging library: logging a user-controlled string like ${jndi:ldap://...} could make vulnerable Log4j 2 versions fetch and run remote code.
Practice questions
The JDK's built-in java.util.logging behaves like SLF4J here: FINE is disabled by default. What does this print to standard output?
import java.util.logging.Logger;
String expensive() {
System.out.println("computed");
return "big report";
}
void main() {
var log = Logger.getLogger("app");
log.fine("Report: " + expensive());
log.fine(() -> "Report: " + expensive());
}- computed
- Report: big report
- Nothing is printed
- computed computed
Check your answer
computed. The first call builds its message string before fine() even runs, so expensive() executes although nothing is logged. The lambda version is only called when FINE is enabled.
This line runs millions of times with DEBUG turned off. Best fix?
log.debug("Loaded " + items.size()
+ " items for " + user);- log.debug(String.format("Loaded %d items for %s", items.size(), user));
- System.out.println("Loaded " + items.size() + " items");
- log.error("Loaded " + items.size() + " items for " + user);
- log.debug("Loaded {} items for {}", items.size(), user);
Check your answer
log.debug("Loaded {} items for {}", items.size(), user);. With placeholders, SLF4J formats the message only if DEBUG is enabled, so a disabled statement costs almost nothing.