Knowledge Guide
HomeHands-On BuildsLLD Katas

Design a Logging Framework

Design a Logging Framework

Every service you will ever operate leans on a logging framework, and "design a logging library" is a recurring LLD interview ask because it quietly tests three separate skills at once: can you decouple what gets logged from where it goes and how it's formatted (that's the Chain of Responsibility and Strategy patterns doing real work, not vocabulary); can you filter cheaply (checking a level before you build a string); and — the part that actually separates a toy from something you'd run in production — do you know that a naive logging call can silently stall the request that triggered it. This lab makes you build a leveled, multi-destination logger from an empty file in Java and Go, measure the synchronous-I/O stall for real, and then fix it with a bounded async queue whose full-queue policy you have to defend.

1. The trap

You're asked to "add logging" to a hot request path. The obvious first draft:

void handleRequest(Request req) {
    log.info("handling request " + req.id() + " for user " + req.userId());
    // ... do the actual work ...
    log.info("completed request " + req.id() + " in " + elapsed + "ms");
}

// log.info just writes straight to a file, synchronously, on the request thread:
void info(String msg) {
    writer.write(msg + "\n");
    writer.flush();          // and maybe fsync(), if you want durability
}

This works fine in a demo. It quietly breaks two ways once it's under real load, and you will hit both if you don't design around them:

Both problems have the same fix shape: decouple the decision to log from the act of writing it, and decouple the act of writing from the thread that's on the request's critical path. That's the whole lab.

2. Scope it like a senior

Before writing a class, pin the contract down. Ask:

Answering these before coding is what turns "print statements with extra steps" into an actual design.

3. Reason to the design

Attempt 0 — one method, one destination, no filtering. A single log(String) that writes straight to a file. It compiles, but every level is unconditionally live (no way to quiet TRACE in production without a code change) and there is exactly one place logs can go.

Attempt 1 — add levels, and filter BEFORE building the message. The first real design decision: the level check must happen before the message is formatted, not after.

// Wrong order -- pays the formatting cost even when the line is discarded:
String msg = "user=" + user.id() + " cart=" + cart.expensiveToString();
if (level.ordinal() >= threshold.ordinal()) write(msg);

// Right order -- the guard is the FIRST thing that runs:
if (level.ordinal() >= threshold.ordinal()) {
    write("user=" + user.id() + " cart=" + cart.expensiveToString());
}

This is why every real framework structures the public API as logger.debug(String) that internally guards, rather than making the caller remember to wrap every call in an if (isDebugEnabled()) — though the guard-and-build-lazily version is exactly what you reach for when the message itself is expensive to construct (e.g. serializing an object). Either way: never build a message the level check would have discarded.

Attempt 2 — separate the destination (Appender) from the rendering (Formatter, a Strategy). A ConsoleAppender and a FileAppender both need to turn a LogRecord into text, but they shouldn't each hardcode their own text layout — that couples "where" to "how." Pull the rendering out into a Formatter interface (PlainFormatter today, a JsonFormatter tomorrow), and pass one into any appender. Now adding a destination is a new small class; changing the wire format is a one-line swap, no appender touched.

Attempt 3 — more than one appender, more than one logger: the chain of responsibility. Real systems have a hierarchy of named loggers (com.acmecom.acme.orderscom.acme.orders.payment), and a child logger without its own level or appenders should inherit from its parent, walking up the chain until it finds one. This is literally the Chain of Responsibility pattern applied to log dispatch: each logger in the chain gets a chance to handle the record with its own appenders, then — unless told not to (additive = false) — passes it up to the parent, which does the same. It's exactly how java.util.logging, Log4j, and Logback structure logger hierarchies, and it's why setting one subsystem to DEBUG doesn't require re-wiring every appender by hand.

Attempt 4 — the concurrency crux: synchronous appenders own the caller's thread. Every appender so far does its I/O inline, on whatever thread called log(). That's Movement 1's trap, now precisely located: it's not the Logger or the Chain that's slow, it's a specific Appender doing synchronous I/O. The fix is to make ANY appender async by wrapping it: an AsyncAppender holds a bounded queue and a single background writer thread that drains it and calls the real (slow) appender. log() now only has to enqueue — typically sub-microsecond — and returns immediately. The queue is bounded on purpose: an unbounded queue defers the problem instead of solving it — if the writer is ever slower than producers for a sustained burst, an unbounded queue grows without limit and eventually OOMs the process. So capacity is finite, which forces the one decision every logging framework has to make explicitly: what happens when the queue is full?

There is no universally correct answer — it's a product decision (Movement 6 makes it a real trade-off table). We build all three so you can pick with your eyes open instead of inheriting whatever a library defaults to.

4. Build it — milestones

Build the framework with this contract, milestone by milestone. Attempt each one yourself before reading the reference implementation — it's positioned after this list on purpose.

Reference implementation — Java

Two files. LoggingLab.java is the framework: levels, the record, the Formatter strategy, the Appender hierarchy (including the fsync'ing SyncFileAppender that IS the stall), the chain-of-responsibility Logger, and AsyncAppender with all three overflow policies. Both compiled clean with javac and ran end to end before this page was written.

import java.io.FileOutputStream;
import java.io.IOException;
import java.util.List;
import java.util.concurrent.ArrayBlockingQueue;
import java.util.concurrent.BlockingQueue;
import java.util.concurrent.CopyOnWriteArrayList;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;

// ---- Levels ----
enum Level { TRACE, DEBUG, INFO, WARN, ERROR }

// ---- The event ----
final class LogRecord {
    final Level level;
    final String message;
    final long timestampMillis;
    final String threadName;
    LogRecord(Level level, String message) {
        this.level = level;
        this.message = message;
        this.timestampMillis = System.currentTimeMillis();
        this.threadName = Thread.currentThread().getName();
    }
}

// ---- Formatter (Strategy): how a record becomes text ----
interface Formatter { String format(LogRecord r); }

final class PlainFormatter implements Formatter {
    public String format(LogRecord r) {
        return "[" + r.timestampMillis + "] [" + r.level + "] [" + r.threadName + "] " + r.message;
    }
}

// ---- Appender: where a record goes ----
interface Appender {
    void append(LogRecord r);
    void flush();
    void close();
}

abstract class AbstractAppender implements Appender {
    protected final Level threshold;
    protected final Formatter formatter;
    protected AbstractAppender(Level threshold, Formatter formatter) {
        this.threshold = threshold;
        this.formatter = formatter;
    }
    protected boolean accepts(Level l) { return l.ordinal() >= threshold.ordinal(); }
}

final class ConsoleAppender extends AbstractAppender {
    ConsoleAppender(Level threshold, Formatter f) { super(threshold, f); }
    public void append(LogRecord r) {
        if (!accepts(r.level)) return;
        System.out.println(formatter.format(r));
    }
    public void flush() { System.out.flush(); }
    public void close() { }
}

// Synchronous file appender: fsync's every line -- this IS the stall we measure below.
final class SyncFileAppender extends AbstractAppender {
    private final FileOutputStream out;
    SyncFileAppender(Level threshold, Formatter f, String path) throws IOException {
        super(threshold, f);
        this.out = new FileOutputStream(path, true);
    }
    public synchronized void append(LogRecord r) {
        if (!accepts(r.level)) return;
        try {
            out.write((formatter.format(r) + "\n").getBytes("UTF-8"));
            out.getFD().sync();               // force to physical disk -- the expensive part
        } catch (IOException e) {
            throw new RuntimeException(e);
        }
    }
    public synchronized void flush() {
        try { out.flush(); } catch (IOException e) { /* best effort */ }
    }
    public synchronized void close() {
        try { out.close(); } catch (IOException e) { /* best effort */ }
    }
}

// ---- Logger: the chain of responsibility over handlers ----
// Every logger has its own appenders AND (optionally) a parent. A record fires
// this logger's own appenders, then -- if additive -- propagates up the chain
// to the parent's appenders, exactly like java.util.logging / Log4j / Logback.
final class Logger {
    private final String name;
    private final Logger parent;
    private volatile Level level;             // null == inherit from parent
    private final List<Appender> appenders = new CopyOnWriteArrayList<Appender>();
    private volatile boolean additive = true;

    Logger(String name, Logger parent) { this.name = name; this.parent = parent; }

    void setLevel(Level l) { this.level = l; }
    void addAppender(Appender a) { appenders.add(a); }
    void setAdditive(boolean a) { this.additive = a; }

    private Level effectiveLevel() {
        Logger l = this;
        while (l != null) {
            if (l.level != null) return l.level;
            l = l.parent;
        }
        return Level.INFO;                     // guard default if nobody set one
    }

    boolean isEnabled(Level l) { return l.ordinal() >= effectiveLevel().ordinal(); }

    // THE level check happens here, BEFORE a LogRecord is built or formatted.
    // A disabled TRACE call costs one enum comparison, not a string build + I/O.
    void log(Level l, String message) {
        if (!isEnabled(l)) return;
        dispatch(new LogRecord(l, message));
    }

    private void dispatch(LogRecord r) {
        for (Appender a : appenders) a.append(r);   // this logger's own handlers
        if (additive && parent != null) parent.dispatch(r);   // ...then the chain
    }

    void trace(String m) { log(Level.TRACE, m); }
    void debug(String m) { log(Level.DEBUG, m); }
    void info(String m)  { log(Level.INFO, m); }
    void warn(String m)  { log(Level.WARN, m); }
    void error(String m) { log(Level.ERROR, m); }
}

// ---- AsyncAppender: bounded queue + background writer thread ----
// Wraps ANY appender (sync file, console, network...) so the caller never
// blocks on I/O -- except under the BLOCK overflow policy, by design.
final class AsyncAppender implements Appender {
    enum OverflowPolicy { BLOCK, DROP_NEW, DROP_OLDEST }

    private final Appender delegate;
    private final BlockingQueue<LogRecord> queue;
    private final OverflowPolicy policy;
    private final Thread writer;
    private volatile boolean running = true;
    private final AtomicLong dropped = new AtomicLong();

    AsyncAppender(Appender delegate, int capacity, OverflowPolicy policy) {
        this.delegate = delegate;
        this.queue = new ArrayBlockingQueue<LogRecord>(capacity);
        this.policy = policy;
        this.writer = new Thread(new Runnable() {
            public void run() { drainLoop(); }
        }, "async-log-writer");
        this.writer.setDaemon(true);           // still must call close() to flush on shutdown!
        this.writer.start();
    }

    public void append(LogRecord r) {
        switch (policy) {
            case BLOCK:
                try { queue.put(r); } catch (InterruptedException ie) { Thread.currentThread().interrupt(); }
                break;
            case DROP_NEW:
                if (!queue.offer(r)) dropped.incrementAndGet();   // caller's record is discarded
                break;
            case DROP_OLDEST:
                while (!queue.offer(r)) {
                    if (queue.poll() != null) dropped.incrementAndGet();  // evict the head to make room
                }
                break;
            default:
                throw new IllegalStateException("unknown policy");
        }
    }

    private void drainLoop() {
        while (running || !queue.isEmpty()) {
            try {
                LogRecord r = queue.poll(200, TimeUnit.MILLISECONDS);
                if (r != null) delegate.append(r);
            } catch (InterruptedException ie) {
                Thread.currentThread().interrupt();
            }
        }
    }

    long droppedCount() { return dropped.get(); }
    int queueSize() { return queue.size(); }

    public void flush() { delegate.flush(); }

    // Crash-safety: call this from a shutdown hook. It stops accepting new
    // work signal, joins the writer so the queue drains, THEN flushes+closes
    // the delegate. Skip this and buffered-but-unwritten records are lost.
    public void close() {
        running = false;
        try { writer.join(5000); } catch (InterruptedException ignored) { }
        delegate.flush();
        delegate.close();
    }
}

Wire it up (in a shutdown hook, for real usage): Runtime.getRuntime().addShutdownHook(new Thread(asyncAppender::close)); — the daemon writer thread alone is NOT enough, because the JVM can exit while the queue still has unwritten records; only an explicit drain-then-close on shutdown guarantees they land on disk.

Reference implementation — Go

Same design, two files, idiomatic Go: the bounded queue is a buffered channel, and the background writer is a goroutine ranging over it. go build ./... and go vet ./... both pass clean, and the program was run under go run -race with no races reported.

package main

import (
	"fmt"
	"os"
	"sync"
	"sync/atomic"
	"time"
)

// ---- Levels ----
type Level int

const (
	TRACE Level = iota
	DEBUG
	INFO
	WARN
	ERROR
)

func (l Level) String() string {
	switch l {
	case TRACE:
		return "TRACE"
	case DEBUG:
		return "DEBUG"
	case INFO:
		return "INFO"
	case WARN:
		return "WARN"
	case ERROR:
		return "ERROR"
	default:
		return "UNKNOWN"
	}
}

// ---- The event ----
type LogRecord struct {
	Level     Level
	Message   string
	TimeMs    int64
	Goroutine string
}

// ---- Formatter (Strategy): how a record becomes text ----
type Formatter interface {
	Format(r LogRecord) string
}

type PlainFormatter struct{}

func (PlainFormatter) Format(r LogRecord) string {
	return fmt.Sprintf("[%d] [%s] %s", r.TimeMs, r.Level, r.Message)
}

// ---- Appender: where a record goes ----
type Appender interface {
	Append(r LogRecord)
	Flush()
	Close()
}

// ConsoleAppender
type ConsoleAppender struct {
	Threshold Level
	Fmt       Formatter
	mu        sync.Mutex
}

func (c *ConsoleAppender) Append(r LogRecord) {
	if r.Level < c.Threshold {
		return
	}
	c.mu.Lock()
	defer c.mu.Unlock()
	fmt.Println(c.Fmt.Format(r))
}
func (c *ConsoleAppender) Flush() {}
func (c *ConsoleAppender) Close() {}

// SyncFileAppender fsyncs every line -- this IS the stall we measure below.
type SyncFileAppender struct {
	Threshold Level
	Fmt       Formatter
	file      *os.File
	mu        sync.Mutex
}

func NewSyncFileAppender(threshold Level, f Formatter, path string) (*SyncFileAppender, error) {
	file, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
	if err != nil {
		return nil, err
	}
	return &SyncFileAppender{Threshold: threshold, Fmt: f, file: file}, nil
}

func (a *SyncFileAppender) Append(r LogRecord) {
	if r.Level < a.Threshold {
		return
	}
	a.mu.Lock()
	defer a.mu.Unlock()
	a.file.WriteString(a.Fmt.Format(r) + "\n")
	a.file.Sync() // force to physical disk -- the expensive part
}
func (a *SyncFileAppender) Flush() { a.mu.Lock(); defer a.mu.Unlock(); a.file.Sync() }
func (a *SyncFileAppender) Close() { a.mu.Lock(); defer a.mu.Unlock(); a.file.Close() }

// ---- Logger: the chain of responsibility over handlers ----
// Every logger has its own appenders AND (optionally) a parent. A record fires
// this logger's own appenders, then -- if Additive -- propagates up the chain
// to the parent's appenders, exactly like java.util.logging / Log4j / Logback.
type Logger struct {
	name      string
	parent    *Logger
	level     *Level // nil == inherit from parent
	appenders []Appender
	additive  bool
	mu        sync.Mutex
}

func NewLogger(name string, parent *Logger) *Logger {
	return &Logger{name: name, parent: parent, additive: true}
}

func (l *Logger) SetLevel(lv Level)      { l.level = &lv }
func (l *Logger) SetAdditive(v bool)     { l.additive = v }
func (l *Logger) AddAppender(a Appender) { l.mu.Lock(); l.appenders = append(l.appenders, a); l.mu.Unlock() }

func (l *Logger) effectiveLevel() Level {
	for cur := l; cur != nil; cur = cur.parent {
		if cur.level != nil {
			return *cur.level
		}
	}
	return INFO // guard default if nobody set one
}

func (l *Logger) IsEnabled(lv Level) bool { return lv >= l.effectiveLevel() }

// THE level check happens here, BEFORE a LogRecord is built or formatted.
// A disabled Trace call costs one int comparison, not a string build + I/O.
func (l *Logger) Log(lv Level, msg string) {
	if !l.IsEnabled(lv) {
		return
	}
	l.dispatch(LogRecord{Level: lv, Message: msg, TimeMs: time.Now().UnixNano() / int64(time.Millisecond)})
}

func (l *Logger) dispatch(r LogRecord) {
	l.mu.Lock()
	apps := l.appenders
	l.mu.Unlock()
	for _, a := range apps {
		a.Append(r) // this logger's own handlers
	}
	if l.additive && l.parent != nil {
		l.parent.dispatch(r) // ...then the chain
	}
}

func (l *Logger) Trace(m string) { l.Log(TRACE, m) }
func (l *Logger) Debug(m string) { l.Log(DEBUG, m) }
func (l *Logger) Info(m string)  { l.Log(INFO, m) }
func (l *Logger) Warn(m string)  { l.Log(WARN, m) }
func (l *Logger) Error(m string) { l.Log(ERROR, m) }

// ---- AsyncAppender: bounded queue (channel) + background writer goroutine ----
// Wraps ANY appender (sync file, console, network...) so the caller never
// blocks on I/O -- except under the Block overflow policy, by design.
type OverflowPolicy int

const (
	Block OverflowPolicy = iota
	DropNew
	DropOldest
)

type AsyncAppender struct {
	delegate Appender
	queue    chan LogRecord
	policy   OverflowPolicy
	dropped  int64
	done     chan struct{}
}

func NewAsyncAppender(delegate Appender, capacity int, policy OverflowPolicy) *AsyncAppender {
	a := &AsyncAppender{delegate: delegate, queue: make(chan LogRecord, capacity), policy: policy, done: make(chan struct{})}
	go a.drainLoop()
	return a
}

func (a *AsyncAppender) Append(r LogRecord) {
	switch a.policy {
	case Block:
		a.queue <- r
	case DropNew:
		select {
		case a.queue <- r:
		default:
			atomic.AddInt64(&a.dropped, 1) // caller's record is discarded
		}
	case DropOldest:
		for {
			select {
			case a.queue <- r:
				return
			default:
				select {
				case <-a.queue: // evict the head to make room
					atomic.AddInt64(&a.dropped, 1)
				default:
				}
			}
		}
	}
}

func (a *AsyncAppender) drainLoop() {
	for r := range a.queue {
		a.delegate.Append(r)
	}
	close(a.done)
}

func (a *AsyncAppender) DroppedCount() int64 { return atomic.LoadInt64(&a.dropped) }
func (a *AsyncAppender) Flush()              { a.delegate.Flush() }

// Crash-safety: call this from a shutdown path (e.g. signal handler). It stops
// accepting new work, drains the queue, THEN flushes+closes the delegate.
// Only safe to call once producers have stopped sending (Block would panic
// on a closed channel otherwise).
func (a *AsyncAppender) Close() {
	close(a.queue)
	<-a.done
	a.delegate.Flush()
	a.delegate.Close()
}

Note the one deliberate language difference the page owns up to: Java's close() stops the writer and joins it (bounded wait, then proceeds regardless); Go's Close() closes the channel and blocks on <-a.done until the writer has drained everything. Both require producers to have stopped calling Append/append first under the BLOCK/Block policy — closing while a producer is still blocked on a full queue is a bug in both languages (a hang in Java, a panic-on-closed-channel in Go).

5. Break it — the failure lessons, reproduced

The driver. This calls ONLY the types defined in Movement 4 above, in a second file per language, so the whole program — framework + driver — is copy-paste compilable and runnable as shown: javac LoggingLab.java LabMain.java && java LabMain in Java, go build . && ./logginglab in Go (both files in the same directory; both declare `package main` in Go, and Java's is the default package). It exercises the chain (Movement 3), then Lesson A (sync vs. async caller latency) and Lesson B (full-queue overflow policy) below.

import java.io.File;

public final class LabMain {
    public static void main(String[] args) throws Exception {
        chainDemo();
        System.out.println("----");
        syncVsAsyncLatency();
        System.out.println("----");
        overflowPolicyDemo();
    }

    // 1. Level filtering + chain of responsibility (parent/child loggers).
    static void chainDemo() {
        Logger root = new Logger("root", null);
        root.setLevel(Level.INFO);
        // appender threshold is TRACE (its own, independent gate) -- the LOGGER
        // level is what actually restricts what reaches it in this demo.
        root.addAppender(new ConsoleAppender(Level.TRACE, new PlainFormatter()));

        Logger child = new Logger("app.orders", root);
        child.setLevel(Level.DEBUG);          // more verbose than root, locally
        // no appenders of its own -- it relies on the chain to root's console appender
        child.debug("order 42 validated");    // passes child's DEBUG gate, reaches root's appender
        child.trace("this line never prints");// filtered by child's own gate before formatting runs
        root.debug("root logger itself is at INFO, so this line never prints either");
    }

    // 2. Sync (fsync-per-line) vs async appender: measure the caller-side stall.
    static void syncVsAsyncLatency() throws Exception {
        int n = 2000;
        File f1 = File.createTempFile("sync-log", ".log");
        File f2 = File.createTempFile("async-log", ".log");
        f1.deleteOnExit(); f2.deleteOnExit();

        SyncFileAppender syncAppender = new SyncFileAppender(Level.TRACE, new PlainFormatter(), f1.getAbsolutePath());
        long t0 = System.nanoTime();
        for (int i = 0; i < n; i++) syncAppender.append(new LogRecord(Level.INFO, "hot-loop line " + i));
        long syncMillis = (System.nanoTime() - t0) / 1_000_000;
        syncAppender.close();

        SyncFileAppender delegate = new SyncFileAppender(Level.TRACE, new PlainFormatter(), f2.getAbsolutePath());
        AsyncAppender asyncAppender = new AsyncAppender(delegate, 10_000, AsyncAppender.OverflowPolicy.BLOCK);
        long t1 = System.nanoTime();
        for (int i = 0; i < n; i++) asyncAppender.append(new LogRecord(Level.INFO, "hot-loop line " + i));
        long asyncMillis = (System.nanoTime() - t1) / 1_000_000;
        asyncAppender.close();   // drains + fsyncs everything before returning

        System.out.println(n + " log calls, synchronous fsync-per-line appender: " + syncMillis + " ms on the CALLING thread");
        System.out.println(n + " log calls, async appender (bounded queue, BLOCK policy): " + asyncMillis + " ms on the CALLING thread");
        System.out.println("caller-side speedup: " + String.format("%.1f", (double) syncMillis / Math.max(asyncMillis, 1)) + "x (the fsync cost moved to the background writer thread)");
    }

    // 3. Full-queue behavior: a slow delegate (simulated disk) + a fast producer.
    static void overflowPolicyDemo() throws Exception {
        int capacity = 50;
        int produced = 5000;

        // DROP_NEW: producer never blocks; excess records are discarded and counted.
        SlowAppender slowDelegateA = new SlowAppender(2 /* ms per write, simulating a loaded disk */);
        AsyncAppender dropAppender = new AsyncAppender(slowDelegateA, capacity, AsyncAppender.OverflowPolicy.DROP_NEW);
        long tA = System.nanoTime();
        for (int i = 0; i < produced; i++) dropAppender.append(new LogRecord(Level.INFO, "burst " + i));
        long producerMillisDrop = (System.nanoTime() - tA) / 1_000_000;
        dropAppender.close();
        System.out.println("[DROP_NEW]  produced=" + produced + " delivered=" + slowDelegateA.count() +
                " dropped=" + dropAppender.droppedCount() + " producer-blocked-for=" + producerMillisDrop + "ms (barely blocks)");

        // DROP_OLDEST: producer never blocks either, but keeps the MOST RECENT records
        // (evicts the head of the queue instead of rejecting the tail).
        SlowAppender slowDelegateC = new SlowAppender(2);
        AsyncAppender dropOldAppender = new AsyncAppender(slowDelegateC, capacity, AsyncAppender.OverflowPolicy.DROP_OLDEST);
        long tC = System.nanoTime();
        for (int i = 0; i < produced; i++) dropOldAppender.append(new LogRecord(Level.INFO, "burst " + i));
        long producerMillisDropOld = (System.nanoTime() - tC) / 1_000_000;
        dropOldAppender.close();
        System.out.println("[DROP_OLDEST] produced=" + produced + " delivered=" + slowDelegateC.count() +
                " dropped=" + dropOldAppender.droppedCount() + " producer-blocked-for=" + producerMillisDropOld + "ms (keeps freshest " + capacity + ")");

        // BLOCK: producer throughput is throttled down to the slow delegate's speed -- nothing is lost.
        SlowAppender slowDelegateB = new SlowAppender(2);
        AsyncAppender blockAppender = new AsyncAppender(slowDelegateB, capacity, AsyncAppender.OverflowPolicy.BLOCK);
        long tB = System.nanoTime();
        for (int i = 0; i < produced; i++) blockAppender.append(new LogRecord(Level.INFO, "burst " + i));
        long producerMillisBlock = (System.nanoTime() - tB) / 1_000_000;
        blockAppender.close();
        System.out.println("[BLOCK]     produced=" + produced + " delivered=" + slowDelegateB.count() +
                " dropped=" + blockAppender.droppedCount() + " producer-blocked-for=" + producerMillisBlock + "ms (back-pressure hits the caller)");
    }

    // A stand-in for a slow disk/NFS-mounted log volume: every append costs `delayMs`.
    static final class SlowAppender implements Appender {
        private final int delayMs;
        private volatile int delivered = 0;
        SlowAppender(int delayMs) { this.delayMs = delayMs; }
        public void append(LogRecord r) {
            try { Thread.sleep(delayMs); } catch (InterruptedException ignored) { }
            delivered++;
        }
        public void flush() { }
        public void close() { }
        int count() { return delivered; }
    }
}
package main

import (
	"fmt"
	"os"
	"time"
)

func main() {
	chainDemo()
	fmt.Println("----")
	syncVsAsyncLatency()
	fmt.Println("----")
	overflowPolicyDemo()
}

// 1. Level filtering + chain of responsibility (parent/child loggers).
func chainDemo() {
	root := NewLogger("root", nil)
	root.SetLevel(INFO)
	// appender threshold is TRACE (its own, independent gate) -- the LOGGER
	// level is what actually restricts what reaches it in this demo.
	root.AddAppender(&ConsoleAppender{Threshold: TRACE, Fmt: PlainFormatter{}})

	child := NewLogger("app.orders", root)
	child.SetLevel(DEBUG) // more verbose than root, locally
	// no appenders of its own -- it relies on the chain to root's console appender
	child.Debug("order 42 validated")             // passes child's DEBUG gate, reaches root's appender
	child.Trace("this line never prints")         // filtered by child's own gate before formatting runs
	root.Debug("root logger itself is at INFO, so this line never prints either")
}

// 2. Sync (fsync-per-line) vs async appender: measure the caller-side stall.
func syncVsAsyncLatency() {
	n := 2000
	f1 := tempPath("sync-log")
	f2 := tempPath("async-log")
	defer os.Remove(f1)
	defer os.Remove(f2)

	syncAppender, err := NewSyncFileAppender(TRACE, PlainFormatter{}, f1)
	must(err)
	t0 := time.Now()
	for i := 0; i < n; i++ {
		syncAppender.Append(LogRecord{Level: INFO, Message: fmt.Sprintf("hot-loop line %d", i), TimeMs: nowMs()})
	}
	syncElapsed := time.Since(t0)
	syncAppender.Close()

	delegate, err := NewSyncFileAppender(TRACE, PlainFormatter{}, f2)
	must(err)
	asyncAppender := NewAsyncAppender(delegate, 10000, Block)
	t1 := time.Now()
	for i := 0; i < n; i++ {
		asyncAppender.Append(LogRecord{Level: INFO, Message: fmt.Sprintf("hot-loop line %d", i), TimeMs: nowMs()})
	}
	asyncElapsed := time.Since(t1)
	asyncAppender.Close() // drains + fsyncs everything before returning

	fmt.Printf("%d log calls, synchronous fsync-per-line appender: %v on the CALLING goroutine\n", n, syncElapsed)
	fmt.Printf("%d log calls, async appender (bounded queue, Block policy): %v on the CALLING goroutine\n", n, asyncElapsed)
	speedup := float64(syncElapsed) / float64(maxDur(asyncElapsed, time.Millisecond))
	fmt.Printf("caller-side speedup: %.1fx (the fsync cost moved to the background writer goroutine)\n", speedup)
}

// 3. Full-queue behavior: a slow delegate (simulated disk) + a fast producer.
func overflowPolicyDemo() {
	capacity := 50
	produced := 5000

	// DropNew: producer never blocks; excess records are discarded and counted.
	slowA := &SlowAppender{delayMs: 2} // simulating a loaded disk
	dropAppender := NewAsyncAppender(slowA, capacity, DropNew)
	tA := time.Now()
	for i := 0; i < produced; i++ {
		dropAppender.Append(LogRecord{Level: INFO, Message: fmt.Sprintf("burst %d", i)})
	}
	producerElapsedDrop := time.Since(tA)
	dropAppender.Close()
	fmt.Printf("[DropNew]  produced=%d delivered=%d dropped=%d producer-blocked-for=%v (barely blocks)\n",
		produced, slowA.count(), dropAppender.DroppedCount(), producerElapsedDrop)

	// DropOldest: producer never blocks either, but keeps the MOST RECENT records
	// (evicts the head of the queue instead of rejecting the tail).
	slowC := &SlowAppender{delayMs: 2}
	dropOldAppender := NewAsyncAppender(slowC, capacity, DropOldest)
	tC := time.Now()
	for i := 0; i < produced; i++ {
		dropOldAppender.Append(LogRecord{Level: INFO, Message: fmt.Sprintf("burst %d", i)})
	}
	producerElapsedDropOld := time.Since(tC)
	dropOldAppender.Close()
	fmt.Printf("[DropOldest] produced=%d delivered=%d dropped=%d producer-blocked-for=%v (keeps freshest %d)\n",
		produced, slowC.count(), dropOldAppender.DroppedCount(), producerElapsedDropOld, capacity)

	// Block: producer throughput is throttled down to the slow delegate's speed -- nothing is lost.
	slowB := &SlowAppender{delayMs: 2}
	blockAppender := NewAsyncAppender(slowB, capacity, Block)
	tB := time.Now()
	for i := 0; i < produced; i++ {
		blockAppender.Append(LogRecord{Level: INFO, Message: fmt.Sprintf("burst %d", i)})
	}
	producerElapsedBlock := time.Since(tB)
	blockAppender.Close()
	fmt.Printf("[Block]    produced=%d delivered=%d dropped=%d producer-blocked-for=%v (back-pressure hits the caller)\n",
		produced, slowB.count(), blockAppender.DroppedCount(), producerElapsedBlock)
}

// A stand-in for a slow disk/NFS-mounted log volume: every append costs delayMs.
type SlowAppender struct {
	delayMs   int
	delivered int64
}

func (s *SlowAppender) Append(r LogRecord) {
	time.Sleep(time.Duration(s.delayMs) * time.Millisecond)
	s.delivered++
}
func (s *SlowAppender) Flush()       {}
func (s *SlowAppender) Close()       {}
func (s *SlowAppender) count() int64 { return s.delivered }

func nowMs() int64 { return time.Now().UnixNano() / int64(time.Millisecond) }
func must(err error) {
	if err != nil {
		panic(err)
	}
}
func tempPath(prefix string) string {
	f, err := os.CreateTemp("", prefix+"-*.log")
	must(err)
	name := f.Name()
	f.Close()
	return name
}
func maxDur(d, floor time.Duration) time.Duration {
	if d < floor {
		return floor
	}
	return d
}

Measured output (this machine, one run each):

Java:  2000 log calls, synchronous fsync-per-line appender: 77 ms on the CALLING thread
       2000 log calls, async appender (bounded queue, BLOCK policy): 11 ms on the CALLING thread
       caller-side speedup: 7.0x

Go:    2000 log calls, synchronous fsync-per-line appender: 5.140220541s on the CALLING goroutine
       2000 log calls, async appender (bounded queue, Block policy): 1.168458ms on the CALLING goroutine
       caller-side speedup: 4399.1x

The absolute numbers are hardware- and OS-dependent — this run's fsync() happened to cost roughly 100× more per call in the Go binary than in the JVM process on the exact same disk, which is itself a useful lesson: never trust a fsync/disk-write latency number without measuring it on your actual target hardware, because filesystem, OS write-cache policy, and even language runtime I/O buffering all move it by orders of magnitude. What's stable across both runs is the shape: the synchronous appender makes the caller pay for every I/O; the async appender reduces the caller's cost to "enqueue one object," full stop.

Lesson B — a full queue silently drops logs (or silently stalls the producer), reproduced with real counts. Wrap a deliberately slow delegate (2 ms per write, standing in for a loaded disk or an NFS-mounted log volume) in a 50-capacity AsyncAppender, then produce 5,000 records back-to-back — far faster than the delegate can drain:

Java (capacity=50, delegate=2ms/write, produced=5000):
[DROP_NEW]    delivered=52   dropped=4948  producer-blocked-for=5ms    (barely blocks; loses 99% of the burst)
[DROP_OLDEST] delivered=53   dropped=4947  producer-blocked-for=10ms   (barely blocks; keeps the freshest 50)
[BLOCK]       delivered=5000 dropped=0     producer-blocked-for=14683ms (nothing lost; caller pays ~14.7s)

Go (capacity=50, delegate=2ms/write, produced=5000):
[DropNew]     delivered=51   dropped=4949  producer-blocked-for=542µs   (barely blocks; loses 99% of the burst)
[DropOldest]  delivered=51   dropped=4949  producer-blocked-for=857µs   (barely blocks; keeps the freshest 50)
[Block]       delivered=5000 dropped=0     producer-blocked-for=12.46s  (nothing lost; caller pays ~12.5s)

This is the entire back-pressure decision made visible as numbers instead of an abstract trade-off: DROP_NEW/DROP_OLDEST keep the producer fast (sub-15 ms even for 5,000 records) but you lose ~99% of the burst — almost 5,000 log lines, gone, with only a counter (dropped=4948) telling you it happened. BLOCK loses nothing, but the producer now pays the ENTIRE cost of the slow sink — roughly 5000 × 2ms ≈ 10s of theoretical minimum, observed at ~12.5–14.7s including scheduling overhead. Neither result is a bug; both are the deterministic, designed-in consequence of the policy you picked. The bug would be picking a policy and NOT knowing this is what it does under load.

6. Optimise — with trade-offs

DecisionOptionBuys youCosts youUse when
Sync vs async appenderSynchronous appenderSimplicity; strict ordering; a write that returns has landedCaller pays full I/O latency on every call (measured: 77ms–5.1s for 2,000 lines)Low-volume paths, CLI tools, or when every line must be durable before the call returns (e.g. audit logs before an irreversible action)
Async appender (bounded queue + writer thread)Caller cost drops to "enqueue one object" (measured: sub-15ms–1ms)A crash before the writer drains can lose buffered lines; adds one more thread/goroutine and a queue to reason aboutDefault choice for request-serving hot paths and high-volume services
Full-queue policyBLOCKZero log loss, guaranteedRe-introduces the stall you built async logging to remove — now smoothed across a burst instead of per-call (measured: ~12.5–14.7s producer stall under a sustained slow sink)Compliance/audit logging, or any system where losing a log line is worse than a slow request
DROP_NEW (reject incoming)Producer never blocks; simplest to implement (a single offer())Loses exactly the newest information during a burst — often the most relevant lines during an incident (measured: 4,948 of 5,000 dropped)High-volume telemetry/metrics-style logs where an occasional gap is acceptable and producer latency is sacred
DROP_OLDEST (ring buffer)Producer never blocks; keeps the most RECENT window of activitySame loss rate as DROP_NEW in a sustained burst, but the surviving records are the freshest, not the earliest — costs a second queue operation (evict) per full appendDashboards/tailing use cases where "what's happening right now" matters more than "what happened first"
Config granularityRoot-only level/appendersOne knob, trivial to reason aboutCan't quiet a noisy subsystem or turn up one module's verbosity without affecting everythingSmall services, single-purpose tools
Per-logger hierarchy (this lab's Logger chain)Turn one subsystem to DEBUG in production without touching the rest; appenders can differ per branchMore moving parts (effective-level resolution, additivity) to reason about and testAny service with more than one subsystem worth isolating — i.e. almost all of them
Async mechanismSimple bounded BlockingQueue/channel + one writer thread (this lab)Easy to build and reason about; the three overflow policies map directly onto queue operationsOne lock/channel is a shared bottleneck; at very high throughput it can itself become the contention pointThe overwhelming majority of services — get this right before reaching for anything fancier
LMAX Disruptor (what Log4j2's AsyncAppender uses)Lock-free ring buffer with pre-allocated slots — far higher throughput, far lower and more predictable latency, no GC pressure from queue nodesSignificantly harder to implement/debug correctly (memory ordering, sequence barriers); massive overkill below extreme log volumesYou've profiled and proven the simple queue is the bottleneck at very high (100k+ msgs/sec) logging rates

The judgment call that actually gets asked: "block vs drop" is not a technical question, it's "what's worse for this system: a slow request, or a missing log line?" A payments audit trail answers "slow request" every time (BLOCK, maybe even fall back to synchronous for that one logger). A high-QPS request-tracing log answers "missing line" every time (DROP_OLDEST, because the freshest trace usually matters most, plus a dropped-count metric so the gap is at least visible). Naming the concrete cost you're trading, with the number attached, is what a staff engineer's answer sounds like — "it depends" without the number is not an answer.

7. Defend under drilling

8. You can now defend


Re-authored/Deepened for this guide. Reference code compiled and executed (javac/java; go build, go vet, go run -race) before publishing; both break-it measurements (sync-vs-async caller latency, full-queue overflow policies) reproduce the stated numbers on this machine. See also: the Chain of Responsibility Pattern, the Strategy Pattern, and Metrics, Logs & Traces.

🤖 Don't fully get this? Learn it with Claude

Stuck on Design a Logging Framework? Open Claude, copy a block below, and it'll teach you this exact concept — visually and interactively.

🎨 Explain it visually

Build the mental picture, not memorization.

I just read a lesson on **Design a Logging Framework** (Hands-On Builds) and want to truly understand it. Explain Design a Logging Framework from first principles using ONE vivid real-world analogy and a visual mental model — draw it as ASCII art or a clear step-by-step diagram — with a concrete example using real numbers. Then ask me one question to check I got the mental picture, and wait for my reply. If you're unsure or a claim isn't standard, say so and reason from first principles instead of guessing.
🤔 Walk me through it (interactive)

Socratic — adapts to where you're stuck.

Teach me **Design a Logging Framework** interactively. Ask me ONE guiding question at a time, wait for my answer, and adapt to my confusion — build the idea with me step by step instead of explaining it all at once. If you're unsure or a claim isn't standard, say so and reason from first principles instead of guessing.
🧪 Quiz me & fix my gaps

Active recall exposes what you missed.

Quiz me on **Design a Logging Framework** with 5 questions, easy to tricky, ONE at a time. Tell me if each answer is right; at the end, explain clearly what I got wrong and why. If you're unsure or a claim isn't standard, say so and reason from first principles instead of guessing.
🧠 Make it stick

Intuition + hook + flashcards for long-term memory.

Help me remember **Design a Logging Framework** for the long term: give the one-sentence intuition, a memorable hook/mnemonic, a tiny worked example, and 3 active-recall flashcards (Q -> A). If you're unsure or a claim isn't standard, say so and reason from first principles instead of guessing.

📝 My notes