Skip to content

fix: emit a single "event" key when the event-name tag collides with a user key#132

Open
OmarAlJarrah wants to merge 2 commits into
mainfrom
fix/structured-log-duplicate-event-key
Open

fix: emit a single "event" key when the event-name tag collides with a user key#132
OmarAlJarrah wants to merge 2 commits into
mainfrom
fix/structured-log-duplicate-event-key

Conversation

@OmarAlJarrah

Copy link
Copy Markdown
Member

Problem

LoggingEvent.log() always emitted the structured event-name tag under the reserved "event" key whenever .event(name) was called with a non-empty name, with no de-duplication against the other key sources (the logger's global context, the folded MDC, and per-event field(...)). SLF4J's addKeyValue appends rather than replaces, so a "event" key supplied by any of those sources produced a second KeyValuePair with the same name on the event, which JSON appenders serialise as invalid duplicate-key JSON.

Reproduction:

logger.atInfo().event("request.start").field("event", "override").log()

This emitted two event entries. The same happened when the logger's global context or the MDC carried an "event" key.

Change

The event-name tag is now authoritative for the "event" key. When a non-empty name is set, any "event" key arriving from the global context, the folded MDC, or a per-event field(...) is suppressed, so the event carries the "event" key exactly once with the name tag's value. When no name is set (or it was cleared), a user-supplied "event" key passes through unchanged as an ordinary field.

This extends the same single-emission guarantee already in place for the global-context / MDC / field sources to the event-name code path.

The three folding loops in log() are extracted into small private helpers (emitGlobalContext, emitMdc, emitFields), which keeps the method under the cyclomatic-complexity threshold and removes the multi-jump loop bodies.

Tests

Added regression tests in LoggingEventTest, alongside the existing "emitted exactly once" tests, covering the name-tag collision with a per-event field, with a global-context key, and with an MDC key, plus a guard that a user "event" field still passes through when no name tag is set.

Gated build

Ran scoped (no daemon):

./gradlew :sdk-core:test :sdk-core:ktlintCheck :sdk-core:detekt :sdk-core:apiCheck --no-daemon

Result: BUILD SUCCESSFUL. No public-API change, so no apiDump was required.

Closes #116

…user key

LoggingEvent.log() always emitted the structured event-name tag under the
reserved "event" key whenever event(name) was called, with no de-duplication
against the other key sources (global context, MDC, per-event field). Because
SLF4J's addKeyValue appends rather than replaces, a "event" key supplied by the
global context, the folded MDC, or a field(...) produced a second KeyValuePair
with the same name, which JSON appenders serialise as invalid duplicate-key JSON.

The event-name tag is now authoritative for the "event" key: when a non-empty
name is set, any "event" key from the global context, MDC, or a per-event field
is suppressed so the event carries the key exactly once. When no name is set, a
user-supplied "event" key passes through unchanged.

The three folding loops in log() are extracted into small private helpers, which
keeps the method under the cyclomatic-complexity threshold and removes the
multi-jump loop bodies.
@OmarAlJarrah OmarAlJarrah changed the title Emit a single "event" key when the event-name tag collides with a user key fix: emit a single "event" key when the event-name tag collides with a user key Jun 17, 2026
@OmarAlJarrah

Copy link
Copy Markdown
Member Author

Fixes a real duplicate-key bug: when event(name) sets a non-empty event-name tag, an "event" key arriving from globalContext, the folded MDC, or a per-event field() would be appended a second time via addKeyValue, yielding two event KeyValuePairs and invalid duplicate-key JSON. Pulling the emit logic into emitGlobalContext/emitMdc/emitFields and skipping the reserved EVENT_KEY from each when a name tag is present is the right shape — the name tag becomes the single authoritative event, and a user event key is left intact when no name is set. Looks good to merge.

I verified the suppression only triggers when a name tag is actually set (the over-suppression guard test confirms a user event key still flows through otherwise), that all three collision sources are covered, and that there's no public API change. Tests are clear and exercise each path.

When event(name) sets the authoritative event-name tag, a per-event
field("event", ...) collides with the reserved EVENT_KEY and its value is
dropped so the tag stays the single "event" entry. That drop was silent.

Surface it at DEBUG via a small warnOnDroppedEventField helper, so the
override is visible while debugging without adding noise on the normal path:
DEBUG is off by default, and only the explicit field() collision is flagged
(ambient "event" keys from the global context or MDC defer to the tag
silently, as before). The disabled-path cost is a single containsKey check.

Also thread the already-read globalContext and mdcKeys into emitMdc instead
of re-reading them off the logger.
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.

Structured log can emit a duplicate "event" key when the event-name tag collides with a user key

1 participant