[D] [Research] Performance Overhead of Tracing Data in Asy nc Loggers: Map-Injection vs Native Fields [logging-log4j2]

GitHub user ramanathan1504 created a discussion: [Research] Performance Overhead of Tracing Data in Async Loggers: Map-Injection vs Native Fields

Following discussions on Slack regarding [Issue #1976](https://github.com/apache/logging-log4j2/issues/1976) and [PR #4171](https://github.com/apache/logging-log4j2/pull/4171), [PR #4175](https://github.com/apache/logging-log4j2/pull/4175) with @ppkarwasz and @vy, I wanted to open this thread to gather research on how different observability frameworks currently pass distributed tracing data (`traceId`, `spanId`, `traceFlags`) to Log4j across asynchronous boundaries.

The core question we need to figure out: **Do existing Map-based APIs (like `ContextDataProvider` or SLF4J MDC) handle async thread handoffs efficiently enough, or does Log4j need a new native fast-path (like a `TraceContextProvider` SPI with native `LogEvent` fields) to achieve zero-allocation tracing?**

### The "Baggage" Reality
Before diving into the data, it's important to call out one key reality upfront: frameworks like OpenTelemetry don't just inject Trace IDs—they also inject "Baggage" (dynamic user-defined tags). Because native fields can't handle dynamic baggage, **any complete solution must gracefully handle both a fast-path for the standard W3C IDs, and a map-fallback for Baggage.**

Here is the verified state of the ecosystem today:

---

### 1. Micrometer Tracing / Spring Boot (The SLF4J MDC Path)
Frameworks like Micrometer (the default in Spring Boot 3) rely heavily on the SLF4J `MDCAdapter`, which pushes trace IDs directly into Log4j's `ThreadContext` map. 

* **The Bottleneck:** When using Asynchronous Loggers (LMAX Disruptor), Log4j is forced to perform a deep, copy-on-write clone of the entire `ThreadContext` map to safely hand the data over to the background thread. Under high throughput, this generates massive JVM heap garbage and triggers frequent GC pauses.
* **Maintainer Feedback:** I discussed this with `Jonatan Ivanov` (Micrometer/Spring Boot maintainer). He was very supportive of a native SPI to bypass the MDC, noting that Spring Boot already implements a similar native interface (`SpanContextSupplier`) specifically to fetch Trace/Span IDs natively for Prometheus exemplars without map allocations.

### 2. OpenTelemetry & APMs (The `ContextDataProvider` Path)
To avoid the `ThreadContext` deep-copy issue, modern APM agents (like OpenTelemetry and Elastic APM) bypass the MDC by implementing Log4j's `ContextDataProvider` SPI.

* **The Code:** Looking at OTel's [`OpenTelemetryContextDataProvider.java`](https://github.com/open-telemetry/opentelemetry-java-instrumentation/blob/main/instrumentation/log4j/log4j-context-data/log4j-context-data-2.17/library-autoconfigure/src/main/java/io/opentelemetry/instrumentation/log4j/contextdata/v2_17/OpenTelemetryContextDataProvider.java), the agent is forced to allocate a `new StringMap()` (and its backing arrays) for *every single log event* to supply the data. 
* **The Bottleneck:** While this avoids the MDC, it introduces a new penalty. Log4j's `ContextDataInjector` must safely merge this data. In an Async environment, if the RingBuffer slot's map is frozen, Log4j must allocate a *new* map to safely complete the merge, resulting in heap allocations and `O(log N)` binary search overhead on the hot path.
* **Maintainer Feedback:** I discussed this with the OpenTelemetry team (`Lauri Tulmin`). He confirmed that while native fields are great for the core IDs, OTel still needs the map injection anyway to support dynamic Baggage. 

---

### 3. The Benchmark Data (Map-merging vs. Native Fields)

To quantify the overhead of these current approaches, I ran a JMH GC Allocation profile (`-prof gc`) simulating the Async RingBuffer handoff. 

| Benchmark Scenario | Mode | Score (Throughput) | Alloc Rate |
| :--- | :--- | :--- | :--- |
| **`baseline`** (No tracing) | thrpt | `1.210 ops/us` | `1280 B/op` |
| **`nativeTracing`** (Native Fields SPI) | thrpt | `1.193 ops/us` | `1280 B/op` **(+0 Bytes)** |
| **`threadContextTracing`** (SLF4J / MDC) | thrpt | `1.071 ops/us` | `1552 B/op` *(+272 Bytes)* |
| **`contextDataProviderTracing`** (OTel Map) | thrpt | `0.668 ops/us` | `2752 B/op` *(+1472 Bytes)* |

*Note: The `contextDataProvider` simulation accounts for both the OTel Map instantiation and the Log4j internal `ContextDataInjector` merge/unfreeze allocations.*

---

### Where Does This Leave Us?

The data and maintainer feedback reveal a difficult reality: As long as core tracing metadata is injected into a **Map-based structure**, we incur heavy allocation and merging overhead during asynchronous logging boundaries (cutting throughput by ~45% and generating +1,472 bytes of garbage per event). 

However, as Volkan and the OTel team pointed out, adding native fields to `LogEvent` doesn't magically solve everything if agents still have to inject dynamic Baggage via maps anyway.

So, what is the best path forward for Log4j?
1. **Can we optimize Map Merging?** Is there a way to optimize `ContextDataProvider` and `ContextDataInjector` to be 100% garbage-free when merging maps into frozen async events?
2. **Is a Hybrid Approach Justified?** Given that W3C tracing is now a universal application standard, does it warrant its own native fields on `LogEvent` to guarantee a zero-allocation fast-path for the IDs, even if dynamic Baggage remains relegated to the map?

Looking forward to the community's thoughts!

GitHub link: https://github.com/apache/logging-log4j2/discussions/4179

----
This is an automatically sent email for [email protected].
To unsubscribe, please send an email to: [email protected]