Skip to content

Save and restore only the touched MDC keys in the SLF4J handler#14

Merged
merlimat merged 1 commit into
mainfrom
fix-slf4j-mdc-restore
Jun 10, 2026
Merged

Save and restore only the touched MDC keys in the SLF4J handler#14
merlimat merged 1 commit into
mainfrom
fix-slf4j-mdc-restore

Conversation

@merlimat

Copy link
Copy Markdown
Owner

Summary

emitWithMdc() copied the entire MDC map on every structured event: getCopyOfContextMap() on entry (full HashMap copy), and setContextMap() on exit (another full copy inside the adapter). The cost scaled with the ambient MDC size — request ids, trace ids, tenant, etc. — rather than with the event being logged, on every structured call. The empty-MDC case was cheap, which is exactly why the existing benchmarks never showed it.

A small MdcRestore helper now records the prior value of each key the event writes (two parallel arrays sized to the event, grown on demand) and restores in reverse order, so duplicate keys across the chain (logger context attr + per-event attr + ambient MDC entry) land back on the first-seen ambient value with no dedup bookkeeping. slog no longer performs any whole-map copies of its own: O(event attrs) instead of O(MDC size).

Honest cost framing: on logback, its internal copy-on-write (triggered by any MDC write after a logging event captured the live map) remains — that's logback semantics every MDC writer pays. Everything attributable to slog is gone; on plain-HashMap adapters the win is total.

One documented edge: an ambient value that was explicitly null is restored as absent — the two are indistinguishable through MDC.get().

Testing

New Slf4jMdcRestoreTest — the first coverage this path has had. Five tests run end-to-end through the slf4j→log4j2 bridge, so the during-the-call assertions check what the backend actually captured (event context data) and the after assertions check the caller-visible MDC:

  • ambient MDC visible to the backend and preserved after the call
  • overlapping key restored to its ambient value
  • duplicate keys across the chain restore the first-seen prior value
  • durationMs does not leak into the caller MDC
  • restore buffer grows correctly past its initial capacity (20 attrs)

Full check passes (all test tasks).

emitWithMdc() copied the entire MDC map on every structured event:
getCopyOfContextMap() on entry, and setContextMap() on exit (another
full copy inside the adapter). The cost scaled with the ambient MDC
size - request ids, trace ids, etc. - rather than with the event.

A small MdcRestore helper now records the prior value of each key the
event writes (two parallel arrays sized to the event) and restores in
reverse order, so duplicate keys across the chain land back on the
first-seen ambient value without any dedup bookkeeping. slog no longer
performs any whole-map copies of its own: O(event attrs) instead of
O(MDC size). One documented edge: an ambient value that was explicitly
null is restored as absent - the two are indistinguishable through
MDC.get().

Add Slf4jMdcRestoreTest: five tests running through the slf4j->log4j2
bridge, asserting what the backend captured during the call and the
caller-visible MDC after it. This path previously had no test
coverage.
@merlimat merlimat merged commit 925ea42 into main Jun 10, 2026
7 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant