Structured logging: a failed JSON encode corrupts the next log event written on the same thread #51154

When WritableJson.toByteArray(Charset) fails part-way through writing, the partial output is left behind in the thread-local AppendableByteArray buffer and is emitted as a prefix to the next value encoded on that thread. In structured logging this means a single failed log event corrupts the following log event into invalid JSON.

This is a regression in 4.1.0: AppendableByteArray was introduced in this line (see #50369), replacing a per-call ByteArrayOutputStream. 4.0.x and earlier are not affected.

Minimal reproduction (no logging involved)

It is not specific to duplicate names. See Two notes on scope below.

JsonWriter<String> duplicate = JsonWriter.of(members -> {
  members.add("name", s -> s);
  members.add("name", s -> s);   // any mid-encode failure will do; see note below
});
JsonWriter<String> healthy = JsonWriter.of(members -> members.add("ok", s -> s));

try {
  duplicate.write("first").toByteArray();
}
catch (RuntimeException ex) {
  System.out.println("failed as expected: " + ex.getMessage());
}

// completely unrelated writer, same thread
System.out.println(new String(healthy.write("second").toByteArray()));

4.1.0:

failed as expected: The name 'name' has already been written
{"name":"first",{"ok":"second"}

4.0.7 (same program, same classpath otherwise):

failed as expected: The name 'name' has already been written
{"ok":"second"}

How this shows up in structured logging

With nothing but the built-in formats configured:

logging.structured.format.file=logstash
logging.file.name=app.jsonl

MDC.put("mdc-key", "mdc-value");

LOG.atInfo()
   .addKeyValue("message", "duplicate-via-kvp")   // collides with the formatter's own field
   .log("EVENT-A duplicate key");

LOG.atInfo().log("EVENT-B next event same thread");

app.jsonl — EVENT-A is truncated mid-object (trailing comma, no closing brace) and EVENT-B is appended to the same line, so the line is not parseable as JSON:

{"@timestamp":"...","@version":"1","message":"EVENT-A duplicate key","logger_name":"...","thread_name":"main","level":"INFO","level_value":20000,"mdc-key":"mdc-value",{"@timestamp":"...","message":"EVENT-B next event same thread",...}

Reproduced the same way with logging.structured.format.file=ecs, and with a colliding MDC key instead of a key/value pair. So each occurrence costs two events: the failing one is dropped (as covered by #45217) and the next one on that thread is corrupted.

Cause

JsonWriterStructuredLogFormatter.formatAsBytes encodes into AppendableByteArray.get(charset), a thread-local reused buffer. The only reset() call is inside AppendableByteArray.toByteArray(), which is never reached when the write throws, so the partial bytes survive into the next call:

// WritableJson
default byte[] toByteArray(Charset charset) {
  Assert.notNull(charset, "'charset' must not be null");
  try {
    AppendableByteArray appendable = AppendableByteArray.get(charset);
    to(appendable);                    // throws -> buffer keeps partial output
    return appendable.toByteArray();   // never reached, so reset() never runs
  }
  catch (IOException ex) {
    throw new UncheckedIOException(ex);
  }
}

Two notes on scope:

• It is not specific to duplicate names. Any failure mid-encode leaks. Verified with a value that throws while being written:

  members.add("boom", s -> (WritableJson) out -> { throw new IOException("serialization failed"); });
  // next write on same thread -> {"first":"value","boom":{"ok":"second"}

  So ValueProcessor failures, exceptions inside an application-supplied WritableJson value, and exceeded nesting depth all corrupt the following event too.

• The String path is unaffected, since WritableJson.toJsonString() allocates a fresh StringBuilder per call. Only the byte path leaks — i.e. Logback's StructuredLogEncoder.encode and Log4j2's StructuredLogLayout.toByteArray, both of which call formatAsBytes.

Suggested fix

Ensure the thread-local buffer cannot carry partial output across calls — either reset in a finally:

default byte[] toByteArray(Charset charset) {
  Assert.notNull(charset, "'charset' must not be null");
  AppendableByteArray appendable = AppendableByteArray.get(charset);
  try {
    to(appendable);
    return appendable.toByteArray();
  }
  catch (IOException ex) {
    throw new UncheckedIOException(ex);
  }
  finally {
    appendable.reset();
  }
}

or reset on acquire in AppendableByteArray.get(Charset), which additionally covers any future caller that abandons a buffer.

This is independent of #45217: even if duplicate names become warnings rather than errors, other encode failures would still corrupt the next event.

Environment

• Spring Boot 4.1.0 (regression; verified unaffected on 4.0.7)
• Logback 1.5.34, Java 25