The default nginx access log is fine for counting hits and not much else. I found this out the annoying way, trying to figure out why a handful of requests were taking eight seconds while everything else on the same endpoint returned in under 200ms. The default combined format gave me the request, the status code, and the response size – nothing about where the time actually went. Was it the backend? A slow upstream connection? Nginx itself buffering something? The log couldn’t say, because it wasn’t recording the numbers that would answer the question.
What the default format is missing
The stock combined log format, defined in nginx’s default configuration, looks roughly like this:
log_format combined '$remote_addr - $remote_user [$time_local] '
'"$request" $status $body_bytes_sent '
'"$http_referer" "$http_user_agent"';
It tells you what happened and when, but not how long anything took or, if nginx is acting as a reverse proxy, what the upstream server reported back. For anything beyond basic traffic auditing – which is most real debugging – you need a custom format.
A log format built for debugging
Nginx exposes several timing and upstream variables that aren’t in any default format but are documented in the ngx_http_log_module reference. The ones I add to nearly every reverse-proxy config:
log_format timed '$remote_addr - [$time_local] "$request" '
'$status $body_bytes_sent '
'rt=$request_time uct=$upstream_connect_time '
'urt=$upstream_response_time '
'upstream=$upstream_addr ustatus=$upstream_status';
access_log /var/log/nginx/access.log timed;
$request_time is the total time nginx spent on the request, from first byte received to last byte sent to the client. $upstream_response_time is how long the backend took to respond. $upstream_connect_time is how long it took just to establish the connection to that backend. Put those three together and you can tell, without guessing, whether slowness is happening in your application, in the network path to it, or somewhere in nginx’s own handling of the client connection.
Reading the numbers
The diagnostic value is almost entirely in comparing these fields against each other, not reading any single one in isolation. If upstream_response_time is close to request_time, the backend is the bottleneck – go look at application logs, slow query logs, whatever’s behind nginx. If upstream_response_time is small but request_time is large, the time is being spent somewhere nginx controls: often a slow client on the other end of a large response, or buffering settings that are holding data longer than necessary. A high upstream_connect_time specifically points at network or backend availability issues – the backend is slow to accept a connection, not slow to respond once connected, which usually means something different is wrong (connection pool exhaustion, an overloaded backend, DNS resolution delay).
On a setup with multiple upstream servers behind a single location block, $upstream_addr and $upstream_status matter just as much – they tell you which specific backend served a slow or failing request, which turns “the API is sometimes slow” into “server three in the pool is sometimes slow,” a much more useful starting point.
Finding the outliers
Once the format includes request_time, finding slow requests is a matter of filtering the log rather than guessing:
awk '{ for (i=1; i<=NF; i++) if ($i ~ /^rt=/) { split($i, a, "="); if (a[2]+0 > 1.0) print } }' access.log
That pulls out every line where the request took more than a second, which is usually a small enough set to read through directly and spot the pattern – a specific endpoint, a specific upstream, a specific time of day correlating with a cron job or traffic spike.
Separating error log noise from real signal
The error log deserves the same attention as access logs, but its default verbosity (error level) mixes genuinely actionable problems – a backend refusing connections, a misconfigured upstream – with routine noise like clients disconnecting mid-request, which nginx logs as an error even though it’s a completely normal thing for a browser tab to do. Bumping the level down to warn for production cuts a lot of that noise:
error_log /var/log/nginx/error.log warn;
What’s left after that filter tends to be worth reading in full rather than grepping through, since it’s a much shorter list once routine client disconnects are gone.
Rotation gotchas that bite later
One thing that trips people up after adding a custom format: log rotation with logrotate renames the current log file, but nginx keeps writing to the file descriptor it already opened, which now points at the renamed (or deleted) file rather than the new one at the original path. Without a signal telling nginx to reopen its log files, you end up writing to a file nothing can see, and rotation quietly breaks logging until the next reload. The fix is a postrotate block that sends the reopen signal:
postrotate
nginx -s reopen
endscript
It’s a small addition, but skipping it is the single most common reason a “working” custom log format stops producing anything useful a week or two after it was set up.