Skip to main content

    Lesson 41 • Advanced

    Logging in Java

    When your app breaks at 2 AM, your logs are the only witness. By the end of this lesson you'll write structured, level-filtered logs with SLF4J — and know exactly what to record and what to never let near a log file.

    What You'll Learn in This Lesson

    • Why logging beats System.out.println in real apps
    • The five log levels (TRACE → ERROR) and when to use each
    • The SLF4J facade vs Logback / Log4j2 implementations
    • Parameterized logging with {} placeholders
    • Configuring Logback and tagging requests with MDC
    • What you must never log — secrets and PII

    Before You Start

    You'll get the most from this if you know Exception Handling (you'll log exceptions here) and Maven & Gradle (SLF4J and Logback are added as dependencies). A little Multithreading helps when we reach MDC.

    A Real-World Analogy

    💡 Analogy: Think of a plane's flight recorder (the "black box"). It quietly notes what happened, at what level of importance, with a timestamp — so that after something goes wrong, investigators can replay events and find the cause.

    System.out.println() is like shouting in the cockpit — gone the moment it's heard, with no timestamp, no severity, and no way to dial the noise up or down. A logging framework is the black box: every entry has a level (how important), a timestamp, and a source, and you can record more detail in development and less in production — without touching your code.

    1️⃣ Log Levels — The Volume Knob

    Every log message has a level that says how important it is. You set a threshold, and anything below it is silently dropped. In production you typically run at INFO, so the chatty TRACE and DEBUG lines cost you nothing. When you need to investigate, you lower the threshold to DEBUG — often for just one package — and the detail reappears, no redeploy required.

    LevelWhen to UseIn Production?
    TRACELoop iterations, method entry/exit — extreme detailOff
    DEBUGVariable values, algorithm steps (for developers)Off
    INFOApp started, user logged in, order placedOn ✅ (default)
    WARNRetry, deprecated API, slow query — unexpected but OKOn ✅
    ERRORUnhandled exception, failed payment — a human must lookOn ✅ + alerts

    The JDK's built-in java.util.logging uses slightly different names (FINEST/FINE ≈ TRACE/DEBUG, INFO, WARNING ≈ WARN, SEVERE ≈ ERROR), but the idea is identical. The worked example below uses it because it ships with the JDK and runs with zero dependencies.

    Worked Example — log levels (java.util.logging)
    import java.util.logging.Logger;
    import java.util.logging.Level;
    
    public class Main {
        // One logger per class, named after the class. Make it static final.
        private static final Logger log = Logger.getLogger("UserService");
    
        public static void main(String[] args) {
            // In production you run at INFO: anything below INFO is dropped.
            log.setLevel(Level.INFO);
    
            // Cheapest, noisiest messages. FINE here ~ DEBUG/TRACE elsewhere.
            log.fine("Entering findUser()");          // dropped (below INFO)
            log.fine("SQL: SELECT * FROM users");      // dropped (below INFO)
    
            // Normal, expected business events. Kept in production.
            log.info("User logged in: id=42");         // shown
    
            // Something looks off but the app keeps going.
            log.warning("Rate limit near: 950/1000");  // shown
    
            // A real failure a human must look at.
            log.severe("Payment failed for ORD-123");  // shown
        }
    }
    Output
    INFO: User logged in: id=42
    WARNING: Rate limit near: 950/1000
    SEVERE: Payment failed for ORD-123
    This uses java.util.logging, built into the JDK, so it runs with no extra dependencies. Each real line is prefixed with a timestamp and class that vary per run; the output shows the message part. Run it on onecompiler.com/java or a local JDK.

    2️⃣ SLF4J — The Facade Everyone Codes Against

    In real projects you don't call java.util.logging directly. You code against SLF4J (Simple Logging Facade for Java) — an API, a set of method names like log.info(...) that does no logging on its own. Behind it sits an implementation (also called a binding) that does the real work: Logback or Log4j2.

    Your code → SLF4J API (what you write against, always the same)

    SLF4J API → Logback or Log4j2 (the engine you pick at build time)

    Swap the engine by changing one dependency — your code never changes.

    Why a facade? Because libraries you depend on may use different logging engines. SLF4J lets the whole application — your code and its libraries — funnel through one engine you choose. Add it with two dependencies: slf4j-api (the facade) and a binding such as logback-classic (the engine). Get the logger once per class:

    private static final Logger log =
        LoggerFactory.getLogger(OrderService.class);

    3️⃣ Parameterized Logging — Use {}, Not "+"

    SLF4J messages use placeholders: a literal {} in the message that gets filled by the matching argument. log.info("user {}", id) prints user 42. Placeholders are filled left-to-right, so log.info("{} ordered {} items", name, count) works too.

    This isn't just tidier than string concatenation — it's faster. With "user " + id the full string is built every time, even when the line is below the threshold and immediately thrown away. With {}, SLF4J checks the level first and only assembles the message if it will actually be written.

    ❌ Concatenation (wasteful)

    log.debug("user " + id +
        " cart=" + cart);
    // string built even when
    // DEBUG is OFF

    ✅ Placeholders (cheap)

    log.debug("user {} cart={}",
        id, cart);
    // nothing built unless
    // DEBUG is ON
    Worked Example — SLF4J + parameterized logging
    import org.slf4j.Logger;
    import org.slf4j.LoggerFactory;
    
    public class OrderService {
        // SLF4J names the logger from the class — no hand-typed strings.
        private static final Logger log = LoggerFactory.getLogger(OrderService.class);
    
        public void placeOrder(String orderId, int items) {
            // Parameterized logging: {} is a placeholder filled by the next argument.
            // The string is only built if this level is actually enabled — so it is cheap.
            log.debug("Validating order {} with {} items", orderId, items);
            log.info("Order {} placed ({} items)", orderId, items);
    
            if (items > 100) {
                log.warn("Large order {}: {} items", orderId, items);
            }
    
            try {
                charge(orderId);
            } catch (Exception e) {
                // Pass the exception LAST, with NO {} for it — SLF4J prints the stack trace.
                log.error("Charge failed for order {}", orderId, e);
            }
        }
    
        private void charge(String orderId) { /* talk to payment provider */ }
    }
    Output
    # With Logback at INFO level, for placeOrder("ORD-9", 3):
    14:02:11.310 INFO  OrderService - Order ORD-9 placed (3 items)
    # (the debug line is dropped at INFO; warn/error appear only when triggered)
    SLF4J is a facade, so this needs slf4j-api plus a binding such as logback-classic on the classpath (add them via Maven or Gradle). It's a service method, not a standalone main, so use it inside a real project. The output shows one line at INFO level; the exact timestamp/format comes from your Logback pattern.

    🎯 Your Turn #1 — Pick the Right Level

    Three events, three different levels. Fill in info, warn, or error so each message lands at the right severity. The expected output is in the comments.

    Try it — choose info / warn / error
    import org.slf4j.Logger;
    import org.slf4j.LoggerFactory;
    
    public class Main {
        private static final Logger log = LoggerFactory.getLogger(Main.class);
    
        public static void main(String[] args) {
            // 🎯 YOUR TURN — fill in the blanks marked with ___
    
            int userId = 42;
    
            // 1) A routine, expected event — "user logged in". Use the production level.
            log.___("User logged in: id={}", userId);   // 👉 the everyday "it happened" level
    
            // 2) Something suspicious but not fatal — a slow database query.
            log.___("Slow query: 1200ms");               // 👉 the "heads up" level
    
            // 3) A real failure a human must fix — the database is unreachable.
            log.___("Database unreachable");             // 👉 the most severe level
    
            // ✅ Expected output (at INFO level):
            // INFO  Main - User logged in: id=42
            // WARN  Main - Slow query: 1200ms
            // ERROR Main - Database unreachable
        }
    }
    Fill in the blanks, then run it in a project with SLF4J + Logback. Check your output against the ✅ Expected output comment.

    🎯 Your Turn #2 — Convert to Placeholders

    Replace the + concatenation with {} placeholders. One message needs a single placeholder; the other needs two, filled left-to-right.

    Try it — parameterized messages
    import org.slf4j.Logger;
    import org.slf4j.LoggerFactory;
    
    public class Main {
        private static final Logger log = LoggerFactory.getLogger(Main.class);
    
        public static void main(String[] args) {
            // 🎯 YOUR TURN — fill in the blanks marked with ___
            // Rewrite these using PLACEHOLDERS instead of "+" concatenation.
    
            String user = "alice";
            int orders = 3;
    
            // 1) One placeholder. Replace the + concatenation with a {} placeholder.
            // BAD:  log.info("Welcome " + user);
            log.info("Welcome ___", user);               // 👉 put a {} where the name goes
    
            // 2) Two placeholders, filled left-to-right by the two arguments.
            log.info("User ___ has ___ orders", user, orders);  // 👉 two {} placeholders
    
            // ✅ Expected output (at INFO level):
            // INFO  Main - Welcome alice
            // INFO  Main - User alice has 3 orders
        }
    }
    Swap concatenation for {} placeholders, then run it and compare with the ✅ Expected output comment.

    4️⃣ Configuration — logback.xml

    You configure Logback in XML, not Java, in a file at src/main/resources/logback.xml. Three pieces matter: an appender (where logs go — console, file, etc.), a pattern (the layout of each line), and the levels (the root threshold plus per-package overrides). A rolling file appender starts a fresh file by size and date so a log can never fill the disk.

    In the pattern below, %d is the timestamp, %-5level the padded level, %logger the class, %msg%n your message and a newline. The %X{requestId} token pulls a value out of MDC — which the next section explains.

    logback.xml — rotation & pattern
    <configuration>
      <!-- Rolls the log over by size AND date, keeps 30 days, caps total at 3GB. -->
      <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>logs/app.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
          <fileNamePattern>logs/app.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
          <maxFileSize>100MB</maxFileSize>
          <maxHistory>30</maxHistory>
          <totalSizeCap>3GB</totalSizeCap>
        </rollingPolicy>
        <encoder>
          <!-- %X{requestId} pulls the value MDC.put("requestId", ...) stored. -->
          <pattern>%d %-5level [%X{requestId}] %logger - %msg%n</pattern>
        </encoder>
      </appender>
    
      <!-- Your own code logs at DEBUG; everything else stays at INFO. -->
      <logger name="com.myapp" level="DEBUG"/>
      <root level="INFO">
        <appender-ref ref="FILE"/>
      </root>
    </configuration>
    This is a Logback configuration file (XML), not Java. Place it at src/main/resources/logback.xml in a project that depends on Logback; the rolling policy rotates files by size and date and caps total disk usage at 3GB.

    5️⃣ MDC — Tracing One Request Through the Noise

    MDC (Mapped Diagnostic Context) is a small key/value map attached to the current thread. You stamp it once at the start of a request, reference the keys in your pattern, and every log line from that request — across every class it touches — carries the same tag.

    Analogy: MDC is a name badge every log line from a request automatically wears.

    MDC.put("requestId", id) — pin the badge on (start of request)

    %X{requestId} — show the badge in each log line (in the pattern)

    MDC.clear() — take the badge off in a finally block

    When 1,000 requests run at once, MDC lets you filter a million interleaved lines down to the single requestId you're chasing. That's the difference between minutes and hours of debugging.

    🎯 Mini-Challenge — Tag Every Line with a Request Id

    Time to put MDC to work with the support faded — only a comment outline is given. Stamp a requestId, log two messages, and clean up in a finally block so the id can't leak. The expected output is in the comments.

    Challenge — request tracing with MDC
    import org.slf4j.Logger;
    import org.slf4j.LoggerFactory;
    import org.slf4j.MDC;
    
    public class Main {
        private static final Logger log = LoggerFactory.getLogger(Main.class);
    
        // 🎯 MINI-CHALLENGE: tag every log line with a request id
        // 1. MDC.put("requestId", "req-7")  before doing the work
        // 2. log.info("Loading cart")  and  log.info("Checkout done")
        // 3. In a finally block, MDC.clear()  so the id never leaks to the next request
        //
        // With pattern  %-5level [%X{requestId}] %logger - %msg%n  you should see:
        // ✅ Expected output:
        // INFO  [req-7] Main - Loading cart
        // INFO  [req-7] Main - Checkout done
    
        public static void main(String[] args) {
            // your code here
        }
    }
    Write it from the outline, then run it with a Logback pattern that includes %X{requestId}. Match your output to the ✅ Expected output comment.

    Common Errors

    • String concatenation instead of placeholders: log.debug("user " + id) builds the string even when DEBUG is off. Use log.debug("user {}", id) so it's only built when the level is enabled.
    • Logging secrets or PII: log.info("login {}/{}", user, password) leaks a password into every log file and aggregator. Never log passwords, tokens, full card numbers, or personal data — log an id instead.
    • Wrong level: logging an expected event at ERROR (log.error("user logged in")) trains people to ignore real alerts; logging a real failure at DEBUG hides it in production. Match the level to the severity.
    • System.out.println in production: it has no level, no timestamp, no source, can't be filtered or searched, and can't be turned off. Use a logger — log.info(...) — everywhere.
    • Swallowing exceptions: catch (Exception e) {} makes failures invisible. Log it: log.error("op failed for {}", id, e) (exception last, no {} for it).

    Pro Tips

    • 💡 Lombok's @Slf4j: annotate a class and Lombok generates the private static final Logger log field for you — no boilerplate.
    • 💡 Structured JSON logging: output logs as JSON so Elasticsearch, CloudWatch, or Datadog can parse and search every field, not just match raw text.
    • 💡 Guard expensive arguments: if building an argument is costly, wrap it: if (log.isDebugEnabled()) log.debug("dump {}", expensive()).
    • 💡 Log rotation always on: cap file size and history in logback.xml so logs can never fill the disk and crash the app.

    📋 Quick Reference — Log Levels

    LevelSLF4J callUse forProd
    TRACElog.trace(...)Loop/iteration-level detailOff
    DEBUGlog.debug(...)Variable values, dev detailOff
    INFOlog.info(...)Normal business eventsOn ✅
    WARNlog.warn(...)Unexpected but recoverableOn ✅
    ERRORlog.error(...)Failures a human must fixOn ✅

    Frequently Asked Questions

    What is the difference between SLF4J, Logback, and Log4j2?

    SLF4J is a facade — an API you write your code against (log.info(...)). It does no logging itself. Logback and Log4j2 are implementations (also called bindings) that do the real work: formatting, filtering, and writing to files. You code against SLF4J, then pick one implementation on the classpath. Swapping Logback for Log4j2 needs zero code changes because both sit behind the same SLF4J calls. Logback is the natural default (same author as SLF4J); Log4j2 is favoured for very high-throughput async logging.

    Why use log.info("user {}", id) instead of log.info("user " + id)?

    Two reasons. Performance: with concatenation the string "user 42" is always built, even when DEBUG is turned off and the line is thrown away — wasted CPU and garbage. With placeholders, SLF4J first checks whether the level is enabled and only assembles the message if it is. Safety: the {} form keeps your message template constant, which tools can group and search on, and it avoids accidental NullPointerExceptions from calling methods inside the concatenation.

    Which log level should I use?

    TRACE: extremely fine detail like loop iterations (rarely on, even in dev). DEBUG: variable values and algorithm steps for developers. INFO: normal, expected business events — app started, user logged in, order placed; this is the production default. WARN: something unexpected but recoverable — a retry, a deprecated call, a slow query. ERROR: a real failure a human must look at — an unhandled exception or a failed payment. Rule of thumb: if it should page someone, it is ERROR; if it is just useful narration, it is INFO or below.

    How do I log an exception properly?

    Pass the exception (a Throwable) as the LAST argument with NO placeholder for it: log.error("Charge failed for {}", orderId, e). SLF4J detects the trailing Throwable and prints the full stack trace after your message. Do NOT do log.error(e.getMessage()) — that loses the stack trace and the cause, which is usually the most useful part. Never catch an exception and log nothing; a silent catch block makes failures invisible.

    What should I never put in a log?

    Secrets and sensitive data: passwords, API keys, access tokens, full credit-card numbers, and personally identifiable information (PII) such as full names tied to health or financial data. Logs are copied to files, shipped to log aggregators, and read by many people, so anything you log can leak. Log an identifier instead of the secret — a user id rather than an email, the last 4 digits rather than the full card. Many teams run automated scanners that fail the build if a secret pattern appears in a log statement.

    What is MDC and why does it matter?

    MDC (Mapped Diagnostic Context) is a thread-local map of key/value pairs that gets stamped onto every log line automatically. You call MDC.put("requestId", id) once at the start of handling a request, reference it in your pattern with %X{requestId}, and every log line from that request — across many classes — carries the id. That lets you filter a million interleaved log lines down to the single request you are debugging. Always MDC.clear() in a finally block, because threads are reused and a leftover value would mislabel the next request.

    🎉 Lesson Complete!

    You can now log like a professional: pick the right level, code against the SLF4J facade with Logback underneath, use {} placeholders instead of concatenation, configure rotation in logback.xml, trace requests with MDC, and keep secrets out of your logs.

    Next up: Secure Coding — preventing common vulnerabilities in Java applications.

    Sign up for free to track which lessons you've completed and get learning reminders.

    Previous

    Cookie & Privacy Settings

    We use cookies to improve your experience, analyze traffic, and show personalized ads. You can manage your preferences below.

    By clicking "Accept All", you consent to our use of cookies for analytics and personalized advertising. You can customize your preferences or reject non-essential cookies.

    Privacy PolicyTerms of Service