12.1 The Access Log as a Data System

Advanced

What you will learn

1. log_format as schema design — and the fields that earn their place.

2. The two audiences: humans/grep (classic) and machines (structured) — and why you'd run both on the same requests.

3. Variable contracts: which fields are always present, which go empty, and which become comma-chains.

4. Write mechanics: per-request writes, buffering, access_log off for the paths that must not log.

1. Formats are schemas

A log_format is a data contract you're signing with every future consumer — dashboards, alerts, audits, and the grep you'll run during an incident. The classic format, deliberately human-shaped:

log_format classic '$remote_addr - [$time_local] "$request" $status '
                   '$body_bytes_sent in ${request_time}s '
                   'up=$upstream_addr ct=$upstream_connect_time '
                   'cache=$upstream_cache_status gz=$gzip_ratio';

And the same request, both formats, same worker, zero extra cost (real receipts):

127.0.0.1 - [23/Sep/2026:01:33:56 +0000] "GET /fast/format-demo?run=24568 HTTP/1.1" 200 263 in 0.000s up=127.0.0.1:9001 ct=0.000 cache=- gz=-

{
  "ts": "2026-09-23T01:33:56+00:00",
  "request_id": "d700d126655c3574cc3133ca17b2011f",
  "client": "127.0.0.1",
  "method": "GET",
  "uri": "/fast/format-demo?run=24568",
  "status": 200,
  "bytes": 263,
  "latency": 0.000,
  "upstream": { "addr": "127.0.0.1:9001", "status": "200",
                "connect": "0.000", "response": "0.000" },
  "cache": "", "gzip_ratio": "",
  "server_name": "127.0.0.1", "scheme": "http",
  "tls_protocol": "", "tls_cipher": ""
}

Two access_log directives in one server — nginx writes both lines per request. The human line goes to terminals and grep; the machine line goes to your shipper. Keeping both is cheaper than arguing about which to keep.

2. Field selection — what earns a slot

The JSON format above is the "golden signals" set (Lesson 12.3 justifies each). The general selection test:

1. Can an alert act on it? (status, latency, upstream health)

2. Can a dashboard trend it? (cache status, gzip ratio)

3. Can an investigation join on it? ( $request_id, $time_iso8601, upstream addr)

4. Does it identify blast radius? (host, scheme, TLS fields)

Fields nobody reads are noise at scale — every byte is written per request, per worker, forever. (One busy edge node writing a 400-byte line at 50k rps is emitting 20 MB/s of telemetry — suddenly buffer= (§4's mechanics) and field restraint are the same conversation.)

3. Variable contracts — the part that bites

Three contracts exist, and knowing which is which prevents a whole class of pipeline bugs:

The receipts (real lines — a cache HIT has no upstream at all):

{"uri":"/api/data?run=10531","cache":"MISS","upstream":"127.0.0.1:9001"}
{"uri":"/api/data?run=10531","cache":"HIT","upstream":""}

Both facts are signal, not noise: cache:HIT + empty upstream is the receipt of a saved round trip (Module 8's "vanished round trip," now visible in data). Lesson 12.2 turns these contracts into a JSON quoting discipline.

4. Write mechanics

• Per-request, at log phase — the line is written when the request completes, by the worker that served it. Everything you log is after the fact: you cannot log a request that never finished (aborted connections still log — $bytes_sent shows what actually left).

• $time_iso8601 over $time_local for machine formats — ISO 8601 parses without locale tables; your log shipper and your future self agree.

• Multiple access_log lines all fire — classic + JSON + an audit format can coexist; each costs one write.

• Buffering is a throughput/loss contract, per access_log directive : buffer=64k flush=1s batches the per-request write syscalls — §2's 20 MB/s edge node trades ~50,000 writes/sec for ~320 64 KB flushes — and the buffer drains on three triggers: the next line that doesn't fit, the flush= interval, file close (reload, nginx -s reopen, worker exit). The exception is the hard crash — SIGKILL, power loss — which takes up to flush seconds of lines with it ( buffer= without flush= bounds nothing in time). Rule of thumb: buffer the high-volume golden log, never the audit log; the parameters are per-directive, so the performance format runs buffered while the audit format runs unbuffered on the same requests. error_log has no buffer= at all — its lines are written as they happen, which is why severity, not batching, is its volume control (12.5).

• access_log off; where silence is correct: health checks (they'll dominate your volume and skew every chart), the metrics endpoint itself, and any high-frequency probe traffic. The example config silences the http-level default for exactly this reason — compiled defaults point at /var/log/nginx/, which in containers is usually wrong anyway.

• Order of writing vs reading — the log line exists only after the response is done. Anything needing during-request visibility is error_log or metrics territory (12.4, 12.5).

Try it yourself

• nginx -t && nginx -s reload — apply the two formats above on your own server, then:

• tail -f /var/log/nginx/classic.log and tail -f /var/log/nginx/golden.log side by side while you curl :9400/fast/x, :9400/api/x twice, :9400/boom/

• Watch which fields go empty on the cache HIT — predict before you look.

Q&A

Q: Why not just log everything and sort it out downstream? A: Volume is a cost line, PII is a liability line, and signal lost in noise is an outage you didn't diagnose. Curation IS the feature.

Q: ${request_time}s — why the braces? A: Delimiting a variable inside surrounding text: $request_times would parse as an unknown variable. Braces are free; use them whenever a letter follows a variable.

Q: Does logging slow requests down? A: Marginal per line — but it's a write syscall per request without buffering. At scale, access_log ... buffer=64k flush=1s; batches writes (§4 shows the trade: up to flush seconds of lines can vanish in a hard crash).

Takeaways

• log_format is a schema: select fields by alertability, trendability, joinability, and blast radius — not by habit.

• Run both formats on the same requests: humans and machines have different diets, and dual logging is cheaper than consensus.

• Variables have contracts — always-present, sometimes-empty, comma-chaining — and the empty-on-HIT upstream field is signal, not a bug.

• Silence is a feature: access_log off for health checks and metrics endpoints keeps your data honest.