12.2 Structured JSON Logs

Advanced

What you will learn

1. The escape=json format parameter and what it actually escapes.

2. The quoting discipline: when a field may be a bare number, and when it must be a string.

3. The war story: "connect":, — how a first run breaks, and the two maps that fixed it.

4. $request_id — the join key that makes logs correlatable.

5. Shipping: from tailing files to syslog to sidecars.

1. The parameter

log_format golden_json escape=json '{ ... "uri":"$request_uri", ... }';

Without escape=json, a " in a User-Agent, a \ in a path, or a newline smuggled into a header breaks your line's JSON-ness — one malformed line and many shippers choke, skip, or worse, split. With the parameter, nginx escapes values per JSON rules ( " → \", control chars → \uXXXX). It is two decades of "someone put a quote in a header" distilled into one flag.

The property holds continuously, not just on the first line: run jq -e over the whole log — any regression is caught the day someone edits the format (that is exactly how the war story below was found).

2. The quoting discipline

JSON cares about types, and log variables don't have them — you choose, per field:

log_format golden_json escape=json
    '{'
    '"status":$status,'              # bare number: ALWAYS present
    '"bytes":$body_bytes_sent,'      # bare number: ALWAYS present
    '"latency":$request_time,'       # bare number: ALWAYS present
    '"addr":"$upstream_addr",'       # STRING: empties on HITs,
    '"status":"$upstream_status",'   #        comma-chains on retries
    '"connect":"$up_connect",'       #        map-coerced (below)
    ...

The rule, earned the hard way:

A field may be an unquoted number only if the variable is guaranteed non-empty AND single-valued. Everything else is a string.

$status, $body_bytes_sent, $request_time qualify. Upstream timers do not: they go empty when no upstream ran (cache HIT, return-served requests) and comma-chain when retries happened — and "response":0.001, 0.002 is invalid JSON just as surely as "response":,.

3. The war story (a real-world bug)

Our first run of this format failed its own jq -e check. The golden.log line for a cache HIT contained:

"connect":,

$upstream_connect_time was empty — no upstream connection happened — and the format had it unquoted. Every HIT broke the stream. The fix is two maps that coerce empty to "0" plus quoting (the exact config lines):

map $upstream_connect_time  $up_connect { default $upstream_connect_time;  "" "0"; }
map $upstream_response_time $up_respons { default $upstream_response_time; "" "0"; }

'"connect":"$up_connect",'      # never empty, still a string

Alternative designs worth knowing: leave empties as strings and let the consumer tonumber them; or split chains with jq ( split(", ")). What's not optional is the decision — the empty/chain contracts from Lesson 12.1 must be handled in the format or the pipeline, never ignored.

4. $request_id — the join key

"request_id": "d700d126655c3574cc3133ca17b2011f"

Generated per request (1.11.0+), unique across workers. Forward it upstream ( proxy_set_header X-Request-Id $request_id;), have the app log it, and suddenly: the gateway line, the app log line, and the error-log entry for the same request share a handle. Retries? NGINX's subrequest to the second upstream keeps the same $request_id — the retry chain in upstream.status plus a stable id is complete failure forensics. (Bonus: return it to clients as X-Request-Id and support tickets arrive pre-correlated.)

5. Shipping the stream

Buffering, one line: buffer=64k flush=1s buys throughput at the price of up to flush seconds of lines lost on a hard crash — audit-grade streams stay unbuffered — and the full trade (flush triggers, loss bound, error_log's exemption, the both-at-once shape) is Lesson 12.1's write mechanics.

Try it yourself

• jq -e . golden.log — every line you generate must pass jq -e; then walk every field of the format above, including the map-coerced timers.

• Break it on purpose: temporarily un-quote "connect":"$up_connect" → "connect":$up_connect, reload, hit /api/x twice, jq -e the file — watch the HIT line fail. Restore. (Five minutes that will save you a week someday.)

• Generate traffic with quotes: curl -H 'User-Agent: "quoted "agent"' http://127.0.0.1:9400/fast/x — then check the log line is still valid JSON (add the UA to the format first).

Q&A

Q: Why not let the shipper parse text logs into JSON? A: Because now TWO schemas exist (nginx's text, shipper's parse) and every format change risks silent misparse. Emit JSON at the source; parsing is a solved problem everywhere downstream.

Q: Numbers-as-strings annoy my dashboard. Can I cast in log_format? A: No casting exists — hence the map-coercion pattern. Downstream, tonumber in jq / to_float in your shipper is one call.

Q: How big is too big for a log line? A: Beyond ~1–2 KB/request you're likely logging payloads disguised as metadata (URIs with giant query strings, full referers). Truncate deliberately ( map + regex) if clients can send pathological URIs — a 64 KB URI will otherwise be logged verbatim, per request.

Takeaways

• escape=json makes values safe; your quoting discipline makes the line valid — bare numbers only for guaranteed non-empty single-valued fields.

• The shipped-bug story ( "connect":, on cache HITs) and its map-coercion fix are the pattern to copy and the mistake to never repeat.

• $request_id is the join key across nginx, upstreams, apps, and support tickets — emit it, forward it, return it.

• Ship via file+tailer by default, syslog when a collector owns ingestion; buffer for throughput, stay unbuffered for audits.