Structured loggingeasy0-2 years
`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?
grep matches a sequence of characters anywhere in a line, and "order 1041" is a literal substring of "order 10412" — grep has no concept of "1041" as a distinct value with boundaries, only as text that either appears or doesn't. A structured JSON log line puts the order id in its own field, "orderId":1041, as a genuine value rather than a phrase embedded in a sentence, so a query tool like jq can ask select(.orderId == 1041) — an equality check on a typed field — instead of a substring search on free text. jq's comparison is exact: 1041 equals 1041 and not 10412, because it's comparing two numbers, not scanning characters.
PreviousA 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?Next A username field is logged with `log.info("login attempt for " + username)`, and an attacker submits a username containing an embedded newline followed by a fabricated 'login succeeded for admin' line. Walk through exactly what ends up in the log file, and explain precisely why switching to structured JSON logging closes this — not generally, but mechanically.
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?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?