Structured loggingeasy0-2 years
A teammate argues that a `log.debug("processing order " + order.describe())` line is harmless in production because DEBUG is disabled there — "if it's disabled, nothing happens." Is that true?
Not for this specific line — "disabled" only skips the write, not the work already done to build the message. log.debug("processing order " + order.describe()) concatenates a string and calls order.describe() before debug is even entered, so both run on every call whether or not the level is enabled. SLF4J's placeholder form, log.debug("processing order {}", order), defers the work: the message is assembled only if DEBUG is enabled, and toString() on the argument is never called otherwise. The fix isn't wrapping the call in if (log.isDebugEnabled()) — though that also works — it's passing the object through the placeholder instead of pre-building the string yourself.
A correlation id set at the start of a request via `MDC.put("correlationId", id)` shows up correctly on most log lines, but occasionally a log line from a completely different request carries it. What's the mechanism, and why does it only ever seem to happen under load?`grep "order 1041" app.log` returns lines about order 1041 and also lines about order 10412. Why, and how does switching to structured JSON logs fix it — not just "make it searchable", but mechanically?