Async Logging, Filters, Structured JSON and PII

Chapter 17 ended with a warning: an appender runs on the thread that logs. This chapter makes logging cheap, then makes it useful to machines, then makes it safe.

Logging is synchronous by default

Every log.info(...) runs the appenders right away on the request thread. Writing to a console is quick, but writing to a file, a database or Kafka takes time. Under heavy traffic, that time adds to every request's latency. Services with heavy traffic should log asynchronously.

There are two flavors:

	AsyncAppender	Async loggers
Library	Logback (and Log4j2)	Log4j2 only
What is async	only the appender's work	the whole logging pipeline
Fits	moderate traffic	very high traffic

Logback offers only the AsyncAppender; Log4j2 offers both. With Logback, as here, the AsyncAppender is the tool.

The AsyncAppender

The AsyncAppender is a wrapper:

• it holds a queue of log events;
• it has a worker thread that takes events from the queue and calls the real appender;
• the real appender still does the actual writing.

The request thread only puts the event in the queue and moves on.

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>logs/app.log</file>
    <append>false</append>
    <encoder>
        <pattern>%d %-5level %logger - %msg%n</pattern>
    </encoder>
</appender>

<appender name="ASYNC_FILE" class="ch.qos.logback.classic.AsyncAppender">
    <queueSize>1000</queueSize>
    <discardingThreshold>10</discardingThreshold>
    <appender-ref ref="FILE"/>        <!-- the real appender -->
</appender>

<logger name="com.example.payment.PaymentController" level="INFO" additivity="false">
    <appender-ref ref="ASYNC_FILE"/>
</logger>

The file still shows the original thread name ([http-nio-8080-exec-1]): Logback captures it when the event is created, before it is queued.

Settings

• queueSize: capacity of the queue (default 256). There is one worker thread.
• discardingThreshold: a number of free slots, not a percentage. When fewer than this many slots remain, the appender drops events of level TRACE, DEBUG and INFO and keeps only WARN and ERROR. The default is one fifth of queueSize (when the queue is 80% full); 0 means never discard. With queueSize=1000 and discardingThreshold=10, INFO and below are dropped only when fewer than 10 slots are left.
• neverBlock: what happens when the queue is completely full. With false (the default), the logging thread waits for space, so the request slows down. With true, the event is dropped and the thread carries on.

On shutdown

When the application stops, the AsyncAppender stops accepting events and tries to flush the queue, but only for a limited time (maxFlushTime, 1 second by default). Events still queued after that are lost.

Keep errors synchronous

Async logging can lose events: discarded under pressure, dropped with neverBlock, or left in the queue at shutdown. For most levels that is acceptable. For ERROR, often the one line that explains an outage, it is not. A sound pattern: WARN and below asynchronous, ERROR synchronous. Appender filters do the routing.

Filters

A filter on an appender decides, per event, ACCEPT, DENY or NEUTRAL (no opinion; let the next filter, or the default, decide).

<!-- async path: everything except ERROR -->
<appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
        <level>ERROR</level>
        <onMatch>DENY</onMatch>          <!-- ERROR: refuse -->
        <onMismatch>NEUTRAL</onMismatch> <!-- anything else: no objection -->
    </filter>
    <appender-ref ref="FILE_NOT_CRITICAL"/>
</appender>

<appender name="FILE_NOT_CRITICAL" class="ch.qos.logback.core.FileAppender">
    <file>logs/non_critical_app.log</file>
    <encoder>
        <pattern>%d %-5level [%thread] %logger - %msg%n</pattern>
    </encoder>
</appender>

<!-- sync path: ERROR and above only -->
<appender name="FILE_CRITICAL" class="ch.qos.logback.core.FileAppender">
    <file>logs/critical_app.log</file>
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>ERROR</level>             <!-- drop anything below ERROR -->
    </filter>
    <encoder>
        <pattern>%d %-5level [%thread] %logger - %msg%n</pattern>
    </encoder>
</appender>

<logger name="com.example.payment.PaymentController" level="INFO" additivity="false">
    <appender-ref ref="ASYNC"/>
    <appender-ref ref="FILE_CRITICAL"/>
</logger>

• LevelFilter matches one exact level and applies onMatch or onMismatch.
• ThresholdFilter denies everything below a level.
• Filters on the AsyncAppender run before the event is queued, so denied events never take queue space.
• Each file appender needs its own encoder; without one, it cannot write.

Logging INFO, WARN and an ERROR with an exception:

non_critical_app.log:  INFO info log / WARN warn log / INFO payment is successful for alice
critical_app.log:      ERROR Payment failed for User alice
                       java.lang.Exception: Payment failed
                           at com.example.payment.PaymentController.getPayments(...)

Log patterns

An encoder's <pattern> turns an event into a line. Each % word is a converter. Logback's PatternLayout class lists them all, each backed by a small converter class, for example:

public class LevelConverter extends ClassicConverter {
    public String convert(ILoggingEvent le) {
        return le.getLevel().toString();
    }
}

The common ones:

Converter	Prints
%d / %d{yyyy-MM-dd HH:mm:ss.SSS}	date and time (default or given format)
%level / %-5level	level (padded to 5 characters)
%thread	thread name
%logger / %logger{36}	logger name (abbreviated to ~36 characters)
%msg	the message
%n	line separator
%X{key}	the MDC value for key (below)
%ex	the exception's stack trace (added automatically if absent)

Placeholders, not concatenation

log.info("User " + name + " created with id " + id);   // avoid
log.info("User {} created with id {}", name, id);      // do this

With concatenation, the string is built every time, even when the logger's level would discard the statement. With {} placeholders, SLF4J formats the message only if the event is accepted. (The arguments themselves are still evaluated, so avoid expensive calls in them.)

For exceptions, pass the exception as the last argument, without a placeholder for it:

try {
    ...
} catch (Exception e) {
    log.error("Payment failed for User {}", userName, e);
}

SLF4J sees a final Throwable with no matching {} and prints its full stack trace. If you wrote log.error("... {}", e.getMessage()), you would lose the stack trace.

Structured logging (JSON)

A pattern produces text for humans. Log aggregation tools must parse it back into fields (date, level, logger, message) and they do that with regular expressions. That is fragile:

2025-12-17 12:04:16,181 INFO com.example.PaymentController - info log and payment id 123
2025-12-17 12:04:16,181 | INFO | com.example.PaymentController | info log and payment id 123

Two appenders with different separators or date formats need two parsers, and a value inside the message, such as the payment ID, cannot be searched as a field at all.

Structured logging writes each event as JSON, with every piece of information in a named field. Tools read it without guessing, and you can filter on any field (payment_id = 123).

You do not need JSON everywhere. Use it for logs you will query, filter or aggregate, which in practice means the logs shipped to an aggregation platform.

Not like this

<pattern>{"time":"%d", "level":"%level", "msg":"%msg"}</pattern>

Hand-written JSON in a pattern breaks as soon as a message contains a quote or a newline (a stack trace always does), and grows unmanageable as fields are added.

Use LogstashEncoder

<dependency>
    <groupId>net.logstash.logback</groupId>
    <artifactId>logstash-logback-encoder</artifactId>
    <version>7.4</version>
</dependency>

<appender name="JSON_CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
</appender>

<logger name="com.example.payment.PaymentController" level="INFO" additivity="false">
    <appender-ref ref="JSON_CONSOLE"/>
</logger>

LogstashEncoder reads each event and writes proper, escaped JSON:

{"@timestamp":"2025-12-17T12:04:16.181+05:30","@version":"1","message":"info log",
 "logger_name":"com.example.payment.PaymentController","thread_name":"http-nio-8080-exec-1",
 "level":"INFO","level_value":20000}

An exception adds a stack_trace field. The field names come from the library's LogstashFieldNames class. Caller information (caller_class_name, caller_method_name, caller_line_number...) is off by default because collecting it is slow; turn it on with <includeCallerData>true</includeCallerData>.

Adding your own fields: MDC

To add request-specific fields such as a payment ID, use MDC (Mapped Diagnostic Context), a per-thread map of values (kept in a ThreadLocal) that is attached to every log event:

@GetMapping("/payments")
public String getPayments() {
    MDC.put("payment_id", "123");
    log.info("payment is successful");
    MDC.clear();              // threads are reused: always clean up
    return "successfully fetched all payments";
}

LogstashEncoder includes MDC entries as fields automatically:

{..., "message":"payment is successful", "level":"INFO", "payment_id":"123"}

To leave them out, set <includeMdc>false</includeMdc> in the encoder. MDC is what connects logs across services, so chapter 19 covers it in depth.

Never log personal data

PII (personally identifiable information) is any data that identifies a person, directly or indirectly: name with address, phone number, email, national ID numbers (Aadhaar, PAN, SSN), passwords, OTPs, card numbers... Logs are copied to many systems and kept for a long time, and they are read by many people. PII in logs is a compliance problem (GDPR and similar laws) and a security risk.

The golden rule: if you are not sure whether a value is PII, do not log it.

As a safety net, the encoder can mask named fields:

<appender name="JSON_CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder class="net.logstash.logback.encoder.LogstashEncoder">
        <jsonGeneratorDecorator class="net.logstash.logback.mask.MaskingJsonGeneratorDecorator">
            <defaultMask>*****</defaultMask>
            <path>password</path>
            <path>token</path>
            <path>creditCard</path>
        </jsonGeneratorDecorator>
    </encoder>
</appender>

MDC.put("payment_id", "123");
MDC.put("password", "myPassword");      // a mistake...
log.info("payment is successful");

{..., "message":"payment is successful", "password":"*****", "payment_id":"123"}

Masking works on field names. It does not inspect free text: log.info("password is {}", pwd) still prints the password inside message. Masking catches mistakes in structured fields; the real protection is not logging PII in the first place.

Next: Every piece is now in place: trace IDs from chapter 15, MDC, JSON logs. Chapter 19 puts them together into distributed logging: one request's logs, from every service, found with one search.

Check yourself

1. Why can synchronous logging hurt a busy service?
2. What is the difference between Logback's AsyncAppender and Log4j2's async loggers?
3. What does the AsyncAppender add around a real appender?
4. What are the defaults for queueSize and the number of worker threads?
5. What does discardingThreshold=10 mean, and what is dropped?
6. What does neverBlock=true change?
7. Can async logging lose events at shutdown? Why?
8. Why keep ERROR logs synchronous, and how do filters do it?
9. What do LevelFilter and ThresholdFilter each do?
10. Why use {} placeholders instead of string concatenation?
11. How do you log an exception with its stack trace?
12. Why are text patterns hard for log aggregation tools?
13. Why not write JSON by hand in a <pattern>?
14. How do you add a payment_id field to JSON logs?
15. What is PII, and what is the golden rule?
16. What does MaskingJsonGeneratorDecorator protect, and what does it not?

Answers

1. Appenders run on the request thread; slow destinations (file, DB, Kafka) add their time to every request.
2. The AsyncAppender makes only the appender's work asynchronous; Log4j2's async loggers make the whole logging pipeline asynchronous and suit very high traffic.
3. An in-memory queue and a worker thread that takes events from it and calls the real appender.
4. 256 events; one worker thread.
5. When fewer than 10 free slots remain in the queue, events of level TRACE, DEBUG and INFO are dropped; WARN and ERROR are kept.
6. When the queue is full, events are dropped instead of making the logging thread wait.
7. Yes. It flushes for a limited time (maxFlushTime); events still queued after that are lost.
8. ERROR events are the most important and must not be discarded or lost. A LevelFilter denies ERROR on the async appender, and a ThresholdFilter passes only ERROR to a synchronous appender.
9. LevelFilter matches one exact level and applies onMatch/onMismatch; ThresholdFilter denies everything below a level.
10. Concatenation always builds the string; placeholders format it only if the event is accepted.
11. Pass the exception as the last argument without a placeholder for it: log.error("... {}", value, e).
12. They must parse free text with regular expressions, which break with different separators and formats, and cannot search values buried in messages.
13. It is not escaped (quotes and newlines in messages or stack traces break it) and is hard to maintain.
14. MDC.put("payment_id", "123") before logging (and clear it after); LogstashEncoder adds MDC entries as fields.
15. Data that identifies a person directly or indirectly (phone, email, ID numbers, passwords, OTPs, card numbers...). If unsure whether something is PII, do not log it.
16. It masks the values of named JSON fields (such as an MDC password); it does not detect PII inside message text.