InsightsDevOps
Structured logging that helps during incidents
How to make application logs useful when something is broken, with JSON output, a consistent field schema, request and trace IDs, sensible levels, and a lid on cost.
Published November 19, 20245 min read
Logs are usually written for the developer who is building the feature. They are read, much later, by someone on call who did not write the code, under time pressure, searching across dozens of services at once. Most logging problems come from that gap.
A line like Failed to process order 8812 for user anna.berg@mail.test: timeout is readable for one person looking at one file. It is hard to search, impossible to aggregate, and it leaks a customer's email address into a system that many people can read. Structured logging fixes the first two problems, and a few rules fix the third.
Log events as JSON
Structured logs are records with named fields instead of free text. JSON, one object per line, is the format every log pipeline understands without custom parsing:
{"time":"2024-11-19T09:42:17.381Z","level":"ERROR","service":"orders","env":"production","version":"2.14.0","msg":"payment authorization failed","order_id":"ord_8812","payment_provider":"adyen","duration_ms":3012,"error":"context deadline exceeded","trace_id":"4bf92f3577b34da6a3ce929d0e0e4736","span_id":"00f067aa0ba902b7","request_id":"req_7Hk2"}The message stays short and constant: "payment authorization failed", not a sentence with values interpolated into it. Variable data goes in fields. That way you can count every occurrence of the same event, and filter by order_id or payment_provider without regular expressions.
Most languages have a mature library for this. Go has log/slog in the standard library since Go 1.21. Python has structlog or the standard logging module with a JSON formatter. Java has Logback or Log4j 2 with JSON encoders. Node.js has pino.
Agree on a field schema
Structured logs only help across services if the same thing has the same name everywhere. If one service writes userId, another user_id and a third uid, every cross-service query becomes three queries.
Define a small set of standard fields and put them in a shared logging library or template:
| Field | Content | Set by |
|---|---|---|
time | RFC 3339 timestamp in UTC | Logger |
level | DEBUG, INFO, WARN or ERROR | Logger |
service, env, version | Which deployment produced the event | Logger, from environment |
msg | Short, constant description of the event | Code |
trace_id, span_id | Distributed trace context | Middleware |
request_id | ID of the inbound request | Middleware |
error | Error message, with stack trace for unexpected errors | Code |
duration_ms | Duration of the operation, always in milliseconds | Code |
Units belong in field names or in the schema, never left to guess. If the platform already uses OpenTelemetry, its semantic conventions are a reasonable source of names for HTTP, database and messaging attributes.
Correlate with request and trace IDs
During an incident, the most valuable thing a log line can carry is a way to find every other line from the same request. Two IDs do this:
- A request ID generated at the edge, at the load balancer or API gateway, and passed downstream in a header. It is simple and works even without tracing.
- A trace ID from distributed tracing. With W3C Trace Context, it arrives in the
traceparentheader, and an OpenTelemetry SDK makes it available in the request context.
Adding these fields by hand in every log call does not survive contact with a real codebase. Attach them once, in middleware, to a logger carried in the request context:
func WithRequestLogger(base *slog.Logger, next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
requestID := r.Header.Get("X-Request-Id")
if requestID == "" {
requestID = newRequestID()
}
logger := base.With("request_id", requestID)
if sc := trace.SpanContextFromContext(r.Context()); sc.IsValid() {
logger = logger.With(
"trace_id", sc.TraceID().String(),
"span_id", sc.SpanID().String(),
)
}
ctx := contextWithLogger(r.Context(), logger)
next.ServeHTTP(w, r.WithContext(ctx))
})
}With trace IDs in logs, most observability backends can link from a slow span straight to the log lines it produced, and back. That link is often the fastest path from "latency is up" to the actual error.
Use levels to mean something
Levels are only useful if they are used consistently. A working set of definitions:
- ERROR: something failed and needs attention: a request could not be completed, data could not be written. Not for expected conditions like a user entering a wrong password.
- WARN: something unexpected happened but was handled: a retry succeeded, a fallback was used. A rising rate of warnings is often the earliest sign of trouble.
- INFO: significant business or lifecycle events: service started, order placed, job completed. Not one line per function call.
- DEBUG: detail for developers. Off in production by default, but able to be enabled per service at runtime without a redeploy.
Log an error once, where it is handled, rather than at every layer it passes through. Five copies of the same failure make error counts meaningless.
What not to log
Logs are copied to more places, kept longer and read by more people than application databases. Treat them accordingly:
- Secrets: passwords, API keys, session tokens,
Authorizationheaders, connection strings. Redact them in the logging library so a carelesslog(request)cannot leak them. - Personal data: email addresses, names, phone numbers, addresses, payment card data. Log an internal user or customer ID instead. Under regulations like GDPR, personal data in logs extends your retention and deletion obligations to the logging system.
- Full request and response bodies, except in short-lived debug sessions. They are large, and they almost always contain one of the above.
Keep cost under control
Log volume grows with traffic, and most hosted log platforms charge for ingestion and retention. Logging cost often surprises teams only after the bill arrives. Some measures that cut volume without losing value:
- Do not log successful health checks or other high-frequency, low-value requests.
- Sample routine INFO events on very high-traffic paths, while keeping every WARN and ERROR.
- Prefer metrics for counting. A counter of orders per minute costs a fraction of one log line per order.
- Tier retention. Keep recent logs searchable in the hot tier for days or weeks, and move older ones to cheap object storage for audit purposes.
- Watch volume per service. A dashboard of ingested bytes by
serviceturns a sudden logging loop into a ticket instead of an invoice.
Where to start
- Switch each service's logger to JSON output on stdout, and let the platform collect it.
- Publish a field schema with a handful of standard fields, and implement it in a shared library.
- Add middleware that attaches
request_idandtrace_idto every log line. - Write down level definitions and apply them in code review.
- Add key-based redaction for secrets and personal data in the logging library.
- Remove health-check logging, then review ingestion volume per service and set retention tiers.