DEV Community: Mukul S

The Hidden Cost of a Log Line : Sync/Async Flush and everything in Between

Mukul S — Wed, 29 Jul 2026 06:37:15 +0000

log.info("user logged in") looks free. It isn't. Behind that one line is a chain of decisions — buffer or not, flush or not, block or drop, same thread or another — and each one trades latency, throughput, and durability against the others. This post walks the whole chain, from the method call down to the bytes hitting the disk platter.

If you've ever wondered why your p99 latency has a mysterious spike, why logs vanish after a crash, or what "async logging" actually buys you, this is for you.

First, the map: facade vs. implementation

Java logging is a two-layer cake, and mixing up the layers is the #1 source of confusion.
The facade is the API your code calls. The implementation is what actually writes the bytes.

your code
   │  log.info(...)
   ▼
┌───────────────────────────────┐
│  Facade: SLF4J (or Log4j2 API)│   ← the interface you compile against
└──────────────┬────────────────┘
               │ bound at runtime
   ┌───────────┼────────────┬──────────────┐
   ▼           ▼            ▼              ▼
Logback   Log4j2 Core   java.util.logging  ...
(the engine that buffers, formats, and flushes)

SLF4J — the de-facto standard facade. Your app should log against this.
Logback — the reference SLF4J implementation. Solid, widely deployed.
Log4j2 — the performance-focused implementation, famous for its lock-free async loggers.
java.util.logging (JUL) — built into the JDK, rarely chosen on purpose.

Why the split? So you can swap engines without touching a single log. call. Everything interesting in this post — the buffering, the flushing, the async magic — happens in the implementation layer.

The anatomy of a single log call

Before we talk flushing, let's see what one log.info(...) actually does. There are five stages:

1. Level check      → is INFO enabled for this logger? (cheap, often the fastest bail-out)
2. Build LogEvent   → capture message, timestamp, thread, MDC context, maybe a stack trace
3. Filter           → run any configured filters
4. Layout / encode  → turn the event into bytes ("2026-07-28 12:00:01 INFO ...")
5. Append           → write those bytes to the destination (file, console, socket)

Stage 5 — the append — is where sync vs. async and flush-vs-no-flush live. It's also, by far, the most expensive stage, because it may touch the disk.

Pro tip already: Stage 1 is why you sometimes see if (log.isDebugEnabled()). It skips stages 2–5 when the level is off. With modern parameterized logging (log.debug("x={}", x)) the framework does this check for you before building the string — so log.debug("x=" + x) is the real anti-pattern, because the string concatenation happens regardless.

Sync logging: the default, and its two hidden layers

"Synchronous" means the append happens on your application thread. Your thread doesn't return from log.info(...) until the write is done. Simple, predictable — and where all the flush nuance lives.
Here's the subtlety most people miss: between your log statement and the actual disk, there are two separate buffers.

 your app thread
      │  writes formatted bytes
      ▼
┌─────────────────────┐
│ App-level buffer    │   ← BufferedOutputStream inside the appender
│ (e.g. 4 KB)         │      flush() empties THIS
└──────────┬──────────┘
           │ flush()
           ▼
┌─────────────────────┐
│ OS page cache       │   ← the kernel's copy, still in RAM
│ (kernel memory)     │      fsync() empties THIS
└──────────┬──────────┘
           │ fsync()
           ▼
┌─────────────────────┐
│ Physical disk       │   ← now it survives a power loss
└─────────────────────┘

Two different operations empty two different buffers, and people constantly confuse them:

flush() pushes bytes from the application buffer into the OS page cache. After a flush, another process (like tail -f) can see your log line. But it is still in RAM — a kernel panic or power loss loses it.
fsync() (via FileChannel.force()) forces the OS to write the page cache to physical storage. This is what actually makes a log line survive a crash — and it's dramatically slower. Most logging frameworks give you knobs for the first buffer and, effectively, never touch the second by default. That's the durability tradeoff hiding in plain sight. ### immediateFlush: the knob that matters most Both Logback and Log4j2 file appenders expose immediateFlush: Logback:

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>app.log</file>
    <immediateFlush>true</immediateFlush>  <!-- default: true -->
    <encoder>
        <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
    </encoder>
</appender>

Log4j2:

<File name="FILE" fileName="app.log" immediateFlush="true">
    <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
</File>

What it does:

immediateFlush=true (the default): call flush() after every log event. Your line is in the OS cache the instant the call returns. Safe if the JVM crashes (the OS still has the bytes and will write them). But it means a syscall per log line — the throughput killer under load.
immediateFlush=false: let the BufferedOutputStream fill up (typically 8 KB) and flush only when it's full. Far fewer syscalls, much higher throughput. The cost: if the JVM dies, whatever's sitting in the app buffer (up to 8 KB of your most recent, most interesting logs) is gone. That's the fundamental sync-flush tradeoff in one sentence: flush every line for safety, or buffer for speed.

Note: Log4j2 automatically forces immediateFlush=false behavior for its async loggers — because in the async world, the fix for durability is different (more on that below).

So does sync logging survive a crash?

Depends on which crash and which flush setting:

Failure	`immediateFlush=true`	`immediateFlush=false`	With `fsync`
JVM crash (exception, OOM)	✅ safe (OS has it)	⚠️ lose app buffer	✅ safe
Kill -9 the process	✅ safe (OS has it)	⚠️ lose app buffer	✅ safe
OS kernel panic	❌ lose page cache	❌ lose more	✅ safe
Power loss	❌ lose page cache	❌ lose more	✅ safe

Almost nobody does fsync per log line — it's punishingly slow (milliseconds per call). Logs are treated as "best effort durable," and that's usually the right call. Just know the guarantee you're actually getting.

Async logging: get off the hot path

Sync logging's real problem isn't correctness — it's that your request thread pays the I/O bill. If the disk hiccups, if a log rotation stalls, if the buffer flushes at the wrong moment, that latency lands directly on the user request that happened to log at that instant. This is a classic source of mysterious p99 spikes.
Async logging fixes this by handing the log event to another thread and returning immediately:

 app thread                         background thread
     │  log.info(...)                     │
     │──── enqueue event ────►  [ queue ] │
     │  returns instantly                 │──► format + write + flush
     ▼                                    ▼
 keep serving the request         does the slow I/O

Your app thread's job shrinks to "drop the event in a queue and move on." The slow work — formatting, writing, flushing — happens on a dedicated logging thread that nobody's waiting on.
There are two very different implementations of this idea, and the difference is the whole ballgame.

Flavor 1: Logback / Log4j2 `AsyncAppender` (a blocking queue)

This is the classic approach: wrap a real appender in an async one backed by a BlockingQueue (an ArrayBlockingQueue).

<!-- Logback -->
<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>256</queueSize>              <!-- default: 256 -->
    <discardingThreshold>51</discardingThreshold>  <!-- default: 20% of queueSize -->
    <neverBlock>false</neverBlock>          <!-- default: false -->
    <appender-ref ref="FILE"/>
</appender>

The three knobs that decide its behavior under stress:

queueSize — how many events can wait in line. Bigger = absorbs bigger bursts, uses more memory.
discardingThreshold — when the queue gets this full, drop lower-priority events (TRACE/DEBUG/INFO) and keep WARN/ERROR. Logback defaults this to 20% of the queue remaining. Set it to 0 to never discard.
neverBlock — what to do when the queue is completely full:
- false (default): the app thread blocks until space frees up. You keep every log, but now you've reintroduced the exact latency you were trying to avoid — async silently becomes sync under load.
- true: drop the event and move on. Latency stays flat, but you lose logs during bursts. There is no free lunch here. A bounded queue under sustained overload has only three options: block the producer, drop events, or grow unbounded (OOM). Every async logger is just choosing which of these to do, and when. ### Flavor 2: Log4j2 Async Loggers (the LMAX Disruptor) Log4j2's headline feature is Async Loggers, built on the LMAX Disruptor — a lock-free ring buffer that came out of high-frequency trading. This is a genuinely different beast from a blocking queue, and it's why Log4j2 benchmarks so aggressively.

<!-- Make ALL loggers async (system property) -->
<!-- -Dlog4j2.contextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector -->
<!-- Or mix: specific loggers async, rest sync -->
<AsyncLogger name="com.myapp" level="info"/>
<Root level="info">
    <AppenderRef ref="FILE"/>
</Root>

Why a ring buffer instead of a queue? Two reasons:
1. Lock-free = no contention. A BlockingQueue uses locks; when many threads log at once, they fight over that lock and serialize. The Disruptor uses a pre-allocated ring buffer and atomic sequence counters (CAS) instead of locks. Producers and the consumer coordinate via cursor positions, not mutual exclusion. At high thread counts this is the difference — Log4j2's own numbers show async loggers sustaining millions of messages/sec where a blocking queue plateaus.

        ring buffer (pre-allocated slots, reused forever)
        ┌───┬───┬───┬───┬───┬───┬───┬───┐
        │ 5 │ 6 │ 7 │   │   │ 1 │ 2 │ 3 │
        └───┴───┴───┴─▲─┴───┴───┴───┴─▲─┘
                      │               │
              consumer cursor    producer cursor
              (writes to disk)   (app threads publish here)

2. Garbage-free. The slots in the ring buffer are allocated once and reused. A queue allocates a new node per event, feeding the garbage collector. The Disruptor pre-allocates, so in steady state it creates (almost) no garbage — which means no GC pauses caused by logging. Log4j2 pairs this with a "garbage-free" layout mode that reuses StringBuilders and buffers, so you can log hard with near-zero allocation.

What happens when the ring buffer fills? `AsyncQueueFullPolicy`

Same fundamental problem as before — a bounded buffer can overflow — and Log4j2 makes the policy explicit:

Default policy: the producing thread blocks (busy-spins/waits) until a slot frees up. No lost logs, but backpressure hits your app thread.
Discard policy: drop events at or below a configured level (default: drop INFO and below) when full. Keeps latency flat, loses low-priority logs.
You can also plug in a custom policy. And there's a sharp edge worth knowing: if a log call happens on the background consumer thread itself (e.g. logging from inside a layout or an exception handler), blocking would deadlock — so Log4j2 detects this and routes it synchronously instead.

The durability twist: async can lose logs a sync setup wouldn't

Here's the tradeoff people forget. With async logging, when your app thread returns from log.error("about to crash"), that event is just sitting in a queue in memory. It hasn't been formatted, let alone written or flushed.
If the JVM crashes in the next millisecond, that error log — the one explaining the crash — is gone. With synchronous immediateFlush=true logging, the same line would have been in the OS cache and survived.
This is the cruel irony of async logging: it's fastest exactly when you're logging the most, which is often right before something goes wrong.
Mitigations:

Shutdown hooks / graceful drain. Both frameworks try to flush the queue on orderly shutdown. This handles clean exits, not kill -9 or hard crashes.
Log fatal errors synchronously. A common pattern: async for INFO/DEBUG, but route ERROR/FATAL through a synchronous, immediate-flush appender so the important stuff is durable.
Accept the loss. For high-volume, low-value logs (access logs, debug traces), losing the last few hundred on a hard crash is fine. Match the guarantee to the value of the log.

Putting numbers to it (and the benchmarking trap)

Rough ordering of throughput, slowest to fastest:

sync + immediateFlush=true        ▓▓                      (syscall per line)
sync + immediateFlush=false       ▓▓▓▓▓▓                  (buffered)
async AsyncAppender (queue)       ▓▓▓▓▓▓▓▓▓▓
async Loggers (Disruptor)         ▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓▓

But — and every honest benchmark says this — your mileage will vary wildly, because:

Peak vs. sustained throughput are different questions. Async is fantastic at absorbing bursts. But your disk's real write bandwidth is a hard ceiling. If you sustain more log volume than the disk can drain, the queue fills and async degrades to whatever its full-policy is (blocking or dropping). Async doesn't make your disk faster — it just decouples your app from disk jitter.
Layout cost is often the real bottleneck. A fancy pattern with caller location (%class, %line, %method) forces a stack-trace walk on every log line — that can cost more than the write itself. Avoid location info in hot paths.
Microbenchmarks lie. Logging in a tight loop with nothing else running doesn't reflect a real app where the GC, the CPU cache, and other threads are all contending. The practical takeaway isn't a number — it's a decision tree.

A practical decision guide

Default for most services:
Async logging (Log4j2 Async Loggers if you can, Logback AsyncAppender otherwise), with a bounded queue sized to absorb your typical burst, and low-priority events discarded under pressure.
When you need every log line (audit, compliance, financial):
Synchronous + immediateFlush=true. Accept the throughput hit; you're buying durability. Add fsync only if you truly can't lose data on a power cut — and know it'll cost you.
When latency is sacred (trading, real-time):
Log4j2 Async Loggers with garbage-free layout and a discard policy — never let logging block a request thread, and never let it trigger GC.
A solid hybrid that covers most people:

INFO/DEBUG  → async, discard-under-pressure  (high volume, low value)
WARN/ERROR  → sync, immediateFlush=true       (low volume, high value)

You get speed for the noise and durability for the signal.

The five things to actually remember

A log call has two buffers below it. flush() empties the app buffer to the OS; fsync() empties the OS to disk. They are not the same, and only the second survives a power loss.
immediateFlush is the core sync knob. true = safe but a syscall per line; false = fast but you lose the app buffer on a crash.
Async moves I/O off your request thread — killing latency jitter — but every bounded queue must eventually block, drop, or OOM under sustained overload. Know which one yours does.
The Disruptor wins by being lock-free and garbage-free, not by magic. It beats blocking queues under high thread counts and avoids GC pauses.
Async trades durability for speed. The log explaining your crash is the one most likely to be lost in the queue. Route critical logs synchronously. Logging feels like the most boring line in your codebase. It's also one of the few that quietly touches concurrency, the memory hierarchy, syscalls, GC, and durability all at once. Now you know what that one line is really doing. 🚀 ---

What's your logging setup — sync-and-safe, or async-and-fast? And has "async logging ate my crash log" ever bitten you? Tell me in the comments.

NGINX, Actually Explained: Architecture, Config, and the Mental Model That Makes It Click

Mukul S — Wed, 29 Jul 2026 06:06:37 +0000

Most people meet NGINX as a magic file they copy-paste until the 502 goes away. This post is the opposite: a tour of the model behind that file, drawn straight from the official docs at nginx.org/en/docs. Once the model clicks, the config stops being scary.

Why NGINX is fast (and why the answer matters)

Classic web servers spawn a process or thread per connection. That's fine at 200 connections and catastrophic at 200,000 — each thread eats memory and forces the kernel to context-switch constantly. This is the famous C10K problem.
NGINX was built to dodge it. Instead of "one connection = one thread," it uses a small, fixed number of worker processes, each running a single-threaded, event-driven, non-blocking loop. One worker juggles thousands of concurrent connections by never sitting idle waiting on I/O.

That one design decision explains almost everything else about NGINX. Keep it in mind as we go.

The process model: master + workers

When NGINX starts, you get one master process and several worker processes.

          ┌─────────────────┐
          │  master process │   (runs as root, reads config, binds ports)
          └───────┬─────────┘
                  │ manages
      ┌───────────┼───────────┐
      ▼           ▼           ▼
  ┌────────┐  ┌────────┐  ┌────────┐
  │worker 0│  │worker 1│  │worker 2│   (do the actual request handling)
  └────────┘  └────────┘  └────────┘

The master process does the privileged, one-time work:

Reads and validates configuration
Binds to privileged ports (like :80 / :443)
Spawns, monitors, and restarts workers
Handles signals for graceful reloads and upgrades Worker processes do everything else — accepting connections, reading requests, talking to upstreams, sending responses. They're the hot path. A sane default is one worker per CPU core:

worker_processes auto;   # matches the number of available cores
events {
    worker_connections 1024;   # max simultaneous connections *per worker*
}

Your theoretical connection ceiling is roughly worker_processes × worker_connections. With 8 cores and 1024 connections each, that's ~8,000 connections without breaking a sweat — and that's a conservative default.

The trick that makes reloads zero-downtime

Run nginx -s reload and NGINX doesn't drop a single connection. The master:

Re-reads and validates the new config
Starts new workers with the new config
Tells old workers to stop accepting new connections
Old workers finish their in-flight requests, then exit This graceful choreography is why you can ship config changes to a busy production server in the middle of the day. --- ## The event loop: how one worker serves thousands Here's the part that trips people up. A single worker is single-threaded, yet handles thousands of connections. How? Instead of blocking on I/O, each worker asks the kernel: "tell me when any of these connections has something ready." On Linux that mechanism is epoll (it's kqueue on BSD/macOS). The worker then loops:

while (true) {
    events = wait_for_ready_connections()   // epoll_wait — the only place we "block"
    for (event in events) {
        handle(event)                        // never blocks; do a slice of work, move on
    }
}

The rule inside a worker is sacred: never block. A slow disk read or a slow upstream must not freeze the whole loop, because that loop is serving thousands of other clients. When work would block, NGINX either offloads it (thread pools for disk I/O) or parks the connection and comes back when the kernel says it's ready.
Choose the connection-processing method explicitly if you want, though NGINX auto-selects the best one for your OS:

events {
    use epoll;              # Linux
    worker_connections 4096;
    multi_accept on;        # accept as many new connections as possible per event
}

This is the whole "why is NGINX so fast" answer in one sentence: it turns I/O waiting into an event notification instead of a parked thread.

How NGINX processes a request

The docs have a dedicated page on this ("How nginx processes a request"), and it's worth internalizing. Requests are routed in two steps: which server block, then which location.

Step 1: pick the `server` block

NGINX matches the request against listen directives and the Host header (via server_name):

server {
    listen 80;
    server_name example.com www.example.com;
    # ...
}
server {
    listen 80 default_server;   # fallback when no server_name matches
    server_name _;
    return 444;                 # drop connections to unknown hosts
}

server_name matching order: exact name → leading wildcard (*.example.com) → trailing wildcard (www.example.*) → regex. First match wins.

Step 2: pick the `location`

Within the chosen server, NGINX matches the URI against location blocks. The matching rules are precise and worth memorizing:

location = /exact      { }   # 1. exact match — highest priority, stops search
location ^~ /assets/   { }   # 2. prefix match that *skips* regex if it wins
location ~ \.php$      { }   # 3. case-sensitive regex (first match wins)
location ~* \.(jpg|png)$ { } # 4. case-insensitive regex
location /             { }   # 5. plain prefix — longest match wins as fallback

The priority order is: = beats ^~ beats regex (~/~*) beats plain prefixes. Getting a 404 or serving the wrong file is almost always a location precedence surprise — this table is the cure.

The config blocks you'll actually use

NGINX config is a tree of contexts. Directives are only valid in certain contexts. Here's the shape:

# main context
worker_processes auto;
events { ... }               # connection processing
http {                       # everything HTTP lives here
    include mime.types;
    sendfile on;             # zero-copy file serving via the kernel
    upstream app { ... }     # a pool of backend servers
    server { ... }           # a virtual host
}
stream { ... }               # raw TCP/UDP proxying (databases, gRPC, etc.)

Serving static files

server {
    listen 80;
    server_name static.example.com;
    root /var/www/html;
    location / {
        try_files $uri $uri/ =404;   # try file, then dir, else 404
    }
    location /assets/ {
        expires 30d;                  # aggressive caching for hashed assets
        add_header Cache-Control "public, immutable";
    }
}

try_files is the workhorse here — it's how SPAs get their "always fall back to index.html" behavior:

location / {
    try_files $uri $uri/ /index.html;   # client-side routing friendly
}

Reverse proxy to an app server

This is probably why you're here. NGINX sits in front of your Node/Python/Go app and forwards requests:

upstream backend {
    server 127.0.0.1:3000;
    server 127.0.0.1:3001;
    # load balancing: round-robin by default
    # least_conn;                # send to the worker with fewest active conns
    # ip_hash;                   # sticky sessions by client IP
    keepalive 32;                # reuse upstream connections
}
server {
    listen 80;
    server_name api.example.com;
    location / {
        proxy_pass http://backend;
        proxy_set_header Host              $host;
        proxy_set_header X-Real-IP         $remote_addr;
        proxy_set_header X-Forwarded-For   $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Proto $scheme;
        proxy_http_version 1.1;
        proxy_set_header Connection "";    # required for upstream keepalive
    }
}

Those proxy_set_header lines matter more than they look. Without them, your backend sees NGINX's IP as the client, loses the original scheme, and can generate broken redirects. This four-line block is the single most copy-pasted (and most misunderstood) snippet in NGINX land.

Load balancing methods, at a glance

Method	Directive	Use when
Round robin	(default)	Backends are roughly equal
Least connections	`least_conn;`	Requests have uneven duration
IP hash	`ip_hash;`	You need sticky sessions
Weighted	`server ... weight=3;`	Backends have different capacity

HTTPS in about ten lines

The docs' "Configuring HTTPS servers" page boils down to this:

server {
    listen 443 ssl;
    server_name example.com;
    ssl_certificate     /etc/nginx/ssl/example.com.crt;
    ssl_certificate_key /etc/nginx/ssl/example.com.key;
    ssl_protocols       TLSv1.2 TLSv1.3;
    ssl_ciphers         HIGH:!aNULL:!MD5;
    ssl_session_cache   shared:SSL:10m;   # reuse handshakes across connections
}
# Redirect all HTTP to HTTPS
server {
    listen 80;
    server_name example.com;
    return 301 https://$host$request_uri;
}

`ssl_session_cache` is the performance sleeper: TLS handshakes are expensive, and caching sessions across connections cuts CPU noticeably on busy sites.

Rate limiting: cheap insurance

NGINX can shield your backend from bursts and abuse before a request ever reaches your app. It uses a leaky bucket algorithm:

http {
    # define a zone: 10MB of state, 10 requests/sec per client IP
    limit_req_zone $binary_remote_addr zone=api:10m rate=10r/s;
    server {
        location /api/ {
            limit_req zone=api burst=20 nodelay;   # allow short bursts of 20
            proxy_pass http://backend;
        }
    }
}

There's a sibling directive, `limit_conn`, for capping concurrent connections per client. Both live entirely in NGINX — no app code, no extra service.

The commands worth memorizing

nginx -t                 # test config syntax before applying — do this ALWAYS
nginx -s reload          # graceful reload, zero dropped connections
nginx -s quit            # graceful shutdown (finish in-flight requests)
nginx -s stop            # fast shutdown (drop everything now)
nginx -T                 # dump the full, resolved config (includes all `include`s)
nginx -v                 # version
nginx -V                 # version + build flags + configured modules

Rule of thumb: never `reload` without running `nginx -t` first. A syntax error caught by `-t` is a non-event; the same error hitting `reload` on some setups can take the server down.

Debugging: read the logs like a local

Two logs, two jobs:

nginx
http {
    log_format main '$remote_addr - $remote_user [$time_local] '
                    '"$request" $status $body_bytes_sent '
                    '"$http_referer" "$http_user_agent" '
                    'rt=$request_time uct="$upstream_connect_time" '
                    'urt="$upstream_response_time"';
    access_log /var/log/nginx/access.log main;
    error_log  /var/log/nginx/error.log warn;
}

Adding $request_time and $upstream_response_time to your access log is the fastest way to answer "is it NGINX or is it the backend that's slow?" — a question you will be asked during an incident.

For deep debugging, a build with `--with-debug` unlocks `error_log ... debug;`, which traces the request lifecycle in detail. That's covered in the docs' "A debugging log" page.

The mental model, in five lines

If you remember nothing else:

Master configures, workers serve. Privilege separation + zero-downtime reloads.
One worker, one event loop, thousands of connections. Never block the loop.
Requests route in two steps: server block, then location — and precedence is not intuitive, so learn the table.
Contexts nest: main → http → server → location. Directives are context-scoped.
nginx -t before every reload. Always. Everything in the config file is a consequence of these five ideas. Once you see the event loop behind the directives, NGINX stops being a black box and starts being the most predictable thing in your stack. ---

Where to go next in the docs

Beginner's Guide — a hands-on first config
How nginx processes a request — the routing internals in depth
Admin Guide — proxying, load balancing, compression, caching
Module reference — every directive, grouped by module (ngx_http_core_module, ngx_http_proxy_module, ngx_http_upstream_module, …)

All at nginx.org/en/docs.

Found this useful? Drop your gnarliest NGINX config gotcha in the comments — the location precedence ones are always a good time. 🚀