Structured Logging Patterns for ADK Java, in depth: a field schema for agent events, MDC versus RxJava, a key-value logging plugin, JSON encoders and keeping content out of logs

A schema for agent log records

Decide the fields before writing code, and keep the names stable, because dashboards and alerts will depend on them. A schema that covers agent work:

The message text stays short and constant, such as "model response". Everything you might filter or aggregate on goes in a field. A good test: if you would ever write a regular expression to extract a value from your logs, that value should have been a field.

Why MDC is not enough

The standard Java answer to correlation is the Mapped Diagnostic Context: put request_id in MDC at the edge and every log line on that thread carries it. MDC is a ThreadLocal, and that is the problem. ADK Java is built on RxJava, and the runtime itself owns no threads, as the runtime thread model article explains. In the simplest setup much of the flow runs on the subscribing thread and MDC appears to work. It stops working the moment work hops: a tool run on an executor, a subscribeOn or observeOn in your code, a reactive web handler, a parallel agent. Lines from those threads carry no ids, or worse, stale ids left by the previous task on a pooled thread.

ADK does carry one context across hops: OpenTelemetry's. The plugin manager and flows wrap their work with Tracing.withContext, so Span.current() inside a callback is the right span. Nothing does the same for MDC. That leads to the main rule of this article: do not rely on ambient thread state for agent ids. Read them from the callback context, which ADK hands to every hook, and attach them to each record.

A structured log plugin

A plugin is the natural place to emit agent records, because it sees every model and tool call in every agent. ADK logs through SLF4J; with SLF4J 2.x on the classpath its fluent API attaches key-value pairs to one event without touching MDC:

public final class StructuredLogPlugin extends BasePlugin {
  private static final Logger log = LoggerFactory.getLogger("agent.events");
  private final ConcurrentHashMap<String, Long> started = new ConcurrentHashMap<>();

  public StructuredLogPlugin() { super("structured_log"); }

  private static LoggingEventBuilder ids(LoggingEventBuilder b, CallbackContext ctx) {
    SpanContext span = Span.current().getSpanContext();
    b.addKeyValue("invocation_id", ctx.invocationId())
     .addKeyValue("session_id", ctx.sessionId())
     .addKeyValue("agent", ctx.agentName());
    if (span.isValid()) {
      b.addKeyValue("trace_id", span.getTraceId()).addKeyValue("span_id", span.getSpanId());
    }
    return b;
  }

  private static String key(CallbackContext ctx) {
    return ctx.invocationId() + "/" + ctx.agentName();
  }

  @Override
  public Maybe<LlmResponse> beforeModelCallback(CallbackContext ctx, LlmRequest.Builder req) {
    started.put(key(ctx), System.nanoTime());
    return Maybe.empty();
  }

  @Override
  public Maybe<LlmResponse> afterModelCallback(CallbackContext ctx, LlmResponse resp) {
    Long t0 = started.remove(key(ctx));
    LoggingEventBuilder b = ids(log.atInfo(), ctx).addKeyValue("event", "model.response");
    if (t0 != null) b.addKeyValue("latency_ms", (System.nanoTime() - t0) / 1_000_000);
    resp.usageMetadata().ifPresent(u -> {
      u.promptTokenCount().ifPresent(n -> b.addKeyValue("tokens_in", n));
      u.candidatesTokenCount().ifPresent(n -> b.addKeyValue("tokens_out", n));
    });
    resp.finishReason().ifPresent(f -> b.addKeyValue("finish_reason", f.toString()));
    b.log("model response");
    return Maybe.empty();
  }

  @Override
  public Maybe<Map<String, Object>> onToolErrorCallback(
      BaseTool tool, Map<String, Object> args, ToolContext ctx, Throwable error) {
    ids(log.atWarn(), ctx)
        .addKeyValue("event", "tool.error")
        .addKeyValue("tool", tool.name())
        .addKeyValue("function_call_id", ctx.functionCallId().orElse(null))
        .addKeyValue("error_class", error.getClass().getName())
        .addKeyValue("arg_keys", String.join(",", args.keySet()))
        .log("tool failed");
    return Maybe.empty();
  }
}

Every hook returns empty, so the plugin never changes behaviour and never displaces an agent's own callbacks; see Agent Hooks and the Middleware Pattern for why that matters. The tool error record logs argument names, not values. The timing key includes the agent name because parallel sub-agents share one invocation id. Add matching records for afterToolCallback and onModelErrorCallback in the same style.

Correlating your own log lines

Your own application code still logs through ordinary loggers, and you may want those lines correlated too. Two options. The clean one is to pass the ids: tools receive a ToolContext and can log with the same fluent builder. The pragmatic one is to copy MDC across RxJava's schedulers with a global hook:

RxJavaPlugins.setScheduleHandler(task -> {
  Map<String, String> captured = MDC.getCopyOfContextMap();
  return () -> {
    Map<String, String> previous = MDC.getCopyOfContextMap();
    if (captured != null) MDC.setContextMap(captured); else MDC.clear();
    try {
      task.run();
    } finally {
      if (previous != null) MDC.setContextMap(previous); else MDC.clear();
    }
  };
});

Know its limits before relying on it. It covers only work scheduled through RxJava schedulers, not your own ExecutorService or CompletableFuture calls; it is one global handler per JVM, so it replaces any handler another library installed; it copies on every scheduled task, which costs a little on hot paths; and it propagates whatever MDC the scheduling thread had, so it is only as correct as the code that set it. Treat it as a convenience for application lines, never as the source of agent ids.

Encoders and JSON output

Key-value pairs only become fields if the encoder writes them. On Spring Boot 3.4 or later you can switch the console or file output to JSON with one property, choosing Elastic Common Schema, Logstash or Graylog's GELF:

# application.properties
logging.structured.format.console=ecs
# or keep readable console output and write JSON to a file
# logging.structured.format.file=logstash
# logging.file.name=/var/log/agent/app.json

Spring's documentation states that MDC is included in these formats. Whether SLF4J fluent key-value pairs appear, and under which names, depends on your Boot version and format, so verify it rather than assume it. Outside Boot, Logback's JSON encoder or the widely used logstash-logback-encoder are the usual choices. Whatever you pick, add one test that logs a record through the real configuration, parses the line as JSON and asserts that invocation_id is a top-level field. It takes ten minutes and catches the most common failure: a schema that exists only in code.

Content and personal data

Agents handle text that users wrote, and logs are usually kept longer and guarded less than the session store. ADK's shipped LoggingPlugin prints text parts, function calls and function responses at INFO, which is useful on a laptop and a liability in production. The pattern for production records:

• Log sizes and hashes, not text: message length, number of parts, a hash of the prompt if you need to spot repeats.
• Log argument names and result keys for tools, not values.
• Hash user ids with a keyed hash so analysts can count users without seeing ids.
• Keep full content, when you need it for debugging, in a separate store with its own retention and access rules, referenced from the log by invocation id; ADK Java Audit Logging covers that store.
• Set com.google.adk loggers to WARN in production unless you are debugging, and remove LoggingPlugin from production plugin lists.

Worked example: the forty-second answer

A user reports that one answer took forty seconds. Support gives you the session id. Query 1: session_id = s-41 AND event = model.response, sorted by time, returns six records in two invocations; one invocation, e-7f3c, has four model calls with latencies of 1.9, 2.4, 2.2 and 3.1 seconds, which adds up to under ten. Query 2: invocation_id = e-7f3c across all events shows a tool.error for ledger_lookup with error_class a socket timeout, followed by a successful retry. The gap between the two tool records is 30 seconds, the client's default read timeout. Query 3 uses the trace_id on the error line to open the trace and confirm the tool span's duration.

Three queries, no text search, and the cause is the tool client's timeout setting, not the model. Without invocation_id on the tool error line, which came from an executor thread, the second query would have returned nothing, and the investigation would have started with the model.

Volume and change control

Volume grows with tool rounds, so budget it. One record per model call and one per tool call, at INFO, is affordable for most services; per-chunk streaming logs are not. Sample successful records if you must, but never sample errors, and keep the sampling decision per invocation so a sampled turn is complete. Keep an event catalogue, a short document listing each event name and its fields, and review changes to it like an API change, because downstream queries break silently when a field is renamed.

Use levels for meaning, not volume. INFO is the per-call record you keep; WARN is a recovered problem such as a tool error the model routed around; ERROR is a failed invocation that someone should look at. DEBUG is for content and request detail, and it stays off in production except for a named logger switched on during an investigation, which Spring Boot Actuator lets you do at runtime through its loggers endpoint.

Failure modes

• Ids only in MDC. Lines from executor threads lose them, so exactly the lines you need during an incident are uncorrelated.
• Stale MDC on pooled threads. A missing clear leaves the previous request's ids on the next request's lines.
• Key-values dropped by the encoder. The code is right and the output has no fields; only a configuration test catches it.
• Content in logs. LoggingPlugin or a debug logger left on writes user text into long-retention storage.
• Field drift. invocationId in one service and invocation_id in another makes cross-service queries miss.
• High-cardinality labels. Copying session_id into metric labels instead of log fields explodes the metrics backend.

Trade-offs

What to do next

1. Write the field schema and event catalogue before changing code.
2. Add a structured log plugin that reads ids from the callback context and the trace id from OTel.
3. Switch output to JSON and add a test that parses a real line and checks the ids.
4. Remove LoggingPlugin from production and log sizes and hashes, not text.
5. Use the MDC bridge only for application lines, and clear MDC at every edge.
6. Rehearse a slow-turn investigation with three queries before you need it.