Implement API Logging and Audit Trails

Overview

Sooner or later a compliance review asks the uncomfortable question: who changed what, when, and from where? Request/response logs help you debug and measure performance; audit trails answer that question in append-only storage, which is what SOC 2, ISO 27001, and GDPR auditors actually ask for. General request logging is covered in the logging recipe; this one focuses on the audit side: correlation IDs, redaction, and tamper-resistant storage.

When to Use

• You need to debug production API issues without reproducing them locally
• Compliance requirements mandate a record of sensitive operations (who changed what, when)
• You run distributed services and need to trace one request across them
• Skip this if your API is a low-traffic internal tool with no sensitive operations — a request log alone is enough

Solution

Python (FastAPI)

import json
import logging
import uuid
from datetime import datetime, timezone

from fastapi import Request
from fastapi.middleware.base import BaseHTTPMiddleware

logging.basicConfig(level=logging.INFO)
request_logger = logging.getLogger("api.requests")
audit_logger = logging.getLogger("api.audit")

class AuditMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next):
        correlation_id = request.headers.get("x-correlation-id") or str(uuid.uuid4())
        request.state.correlation_id = correlation_id

        response = await call_next(request)

        request_logger.info(json.dumps({
            "timestamp": datetime.now(timezone.utc).isoformat(),
            "correlation_id": correlation_id,
            "method": request.method,
            "path": str(request.url),
            "status_code": response.status_code,
            "user_agent": request.headers.get("user-agent"),
            "client_ip": request.client.host,
        }))

        # Audit record: only for state-changing or sensitive operations
        if request.method not in ("GET", "HEAD", "OPTIONS"):
            audit_logger.info(json.dumps({
                "timestamp": datetime.now(timezone.utc).isoformat(),
                "correlation_id": correlation_id,
                "actor": getattr(request.state, "user_id", "anonymous"),
                "action": request.method,
                "resource": request.url.path,
                "outcome": "success" if response.status_code < 400 else "failure",
                "client_ip": request.client.host,
            }))

        response.headers["X-Correlation-Id"] = correlation_id
        return response

JavaScript (Express)

const { v4: uuidv4 } = require('uuid');
const winston = require('winston');

const logger = winston.createLogger({
  format: winston.format.json(),
  transports: [new winston.transports.Console()],
});

function auditMiddleware(req, res, next) {
  const correlationId = req.headers['x-correlation-id'] || uuidv4();
  req.correlationId = correlationId;
  res.setHeader('X-Correlation-Id', correlationId);

  const start = Date.now();
  res.on('finish', () => {
    logger.info('api_request', {
      correlation_id: correlationId,
      method: req.method,
      path: req.path,
      status_code: res.statusCode,
      duration_ms: Date.now() - start,
      client_ip: req.ip,
      user_agent: req.get('user-agent'),
    });

    // Audit record: only for state-changing or sensitive operations
    if (!['GET', 'HEAD', 'OPTIONS'].includes(req.method)) {
      logger.info('api_audit', {
        timestamp: new Date().toISOString(),
        correlation_id: correlationId,
        actor: (req.user && req.user.id) || 'anonymous',
        action: req.method,
        resource: req.path,
        outcome: res.statusCode < 400 ? 'success' : 'failure',
        client_ip: req.ip,
      });
    }
  });
  next();
}

module.exports = auditMiddleware;

Java (Spring)

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;
import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.UUID;

@Component
public class AuditFilter extends OncePerRequestFilter {
    private static final Logger logger = LoggerFactory.getLogger("api.requests");
    private static final Logger auditLogger = LoggerFactory.getLogger("api.audit");

    @Override
    protected void doFilterInternal(HttpServletRequest request,
                                    HttpServletResponse response,
                                    FilterChain filterChain) throws ServletException, IOException {
        String correlationId = request.getHeader("X-Correlation-Id");
        if (correlationId == null) correlationId = UUID.randomUUID().toString();

        MDC.put("correlationId", correlationId);
        response.setHeader("X-Correlation-Id", correlationId);

        long start = System.currentTimeMillis();
        try {
            filterChain.doFilter(request, response);
        } finally {
            logger.info("method={} path={} status={} duration={}ms",
                request.getMethod(),
                request.getRequestURI(),
                response.getStatus(),
                System.currentTimeMillis() - start);

            // Audit record: only for state-changing or sensitive operations
            if (!"GET".equals(request.getMethod()) && !"HEAD".equals(request.getMethod())) {
                auditLogger.info("correlationId={} actor={} action={} resource={} outcome={} ip={}",
                    correlationId,
                    request.getUserPrincipal() != null
                        ? request.getUserPrincipal().getName() : "anonymous",
                    request.getMethod(),
                    request.getRequestURI(),
                    response.getStatus() < 400 ? "success" : "failure",
                    request.getRemoteAddr());
            }
            MDC.clear();
        }
    }
}

How It Works

1. The middleware assigns (or honors) a correlation ID at the edge and echoes it back in X-Correlation-Id so clients and downstream services can reference the same request — the correlation ID pattern covers the propagation mechanics in depth.
2. Structured output (JSON, MDC fields) makes every entry machine-parseable: ELK, Datadog, Loki, or CloudWatch can filter by field instead of regexing text.
3. Two log streams matter. Operational logs are ephemeral and high-volume; audit logs are low-volume, long-retention, and often legally required. Keep them in separate sinks with different access controls — see log aggregation for the shipping side.
4. The audit record must include timestamp (UTC), actor, action, resource, outcome, and origin IP — the OWASP Logging Cheat Sheet calls these out explicitly, and anything less fails a compliance review.

What to Audit

Not every request deserves an audit entry — the signal drowns if you log reads. Reserve the audit stream for operations an auditor would ask about:

• Authentication events: logins, failed logins, token issuance, password changes
• Privilege changes: role grants, permission updates, admin actions
• Sensitive data access: reads or exports of PII, payment data, bulk downloads
• Configuration changes: settings, API keys, webhook endpoints, feature flags
• Data mutations: create, update, and delete on protected resources

Read-only traffic stays in the operational log. Anything that changes state or touches sensitive data deserves an audit entry — the code above emits one for non-GET requests as a starting point; tighten the filter to match your threat model.

Variants

Tool	Language	Output	Best for
structlog	Python	JSON	Semantic logging with context binding
Pino	JavaScript	JSON	High-performance Node.js logging (async by design)
Logback + MDC	Java	JSON/Pattern	Thread-local context in Spring

Each of these has a built-in way to keep secrets out of the output — configure it before the logger sees production traffic:

// Pino — redact fields before they reach the sink
const logger = pino({ redact: ['req.headers.authorization', '*.password'] });

# structlog — drop sensitive keys in a processor
def redact(logger, method, event):
    return {k: ("[REDACTED]" if "password" in k or "token" in k else v)
            for k, v in event.items()}

<!-- Logback — mask values in the encoder pattern -->
<pattern>%replace(%msg){'password=\w+', 'password=[REDACTED]'}</pattern>

Best Practices

• Never log sensitive data — passwords, tokens, and PII get masked or hashed before they reach the log pipeline.
• Propagate the correlation ID through every downstream call, not just at the edge: a trace dies at the first service that drops the header.
• Log asynchronously — use buffers so a slow sink never blocks the request path.
• Separate audit from debug logs — audit entries need append-only or WORM storage, longer retention, and tighter access control. Ship them to a SIEM or hash-chain them so tampering is detectable, not just stored.
• Log at the right level: INFO for normal traffic, WARN for degraded behavior, ERROR for failures needing intervention, DEBUG only in development.
• Rotate and archive — compress old logs and move them to cold storage (S3 Glacier) before disk becomes the incident.

Common Mistakes

• Logging request/response bodies by default — many frameworks capture full payloads including passwords and API keys. Configure redaction before enabling body logging anywhere near production.
• Synchronous logging on the request path — a sync write to a remote sink can add milliseconds per call; async mode exists in Winston, Pino, and Log4j for a reason.
• Forgetting to clear thread-local context. MDC or request.state leaking between requests produces audit entries attributed to the wrong user.
• Logging everything at INFO — volume that hides signal; sample routine traffic, keep all WARN/ERROR.
• Storing audit and application logs together: an operator who can purge app logs can also erase the evidence trail.

Troubleshooting

• PII shows up in logs: the redaction filter runs after serialization or only covers known field names. Redact by key pattern (password, token, authorization) and by value shape (JWT, credit-card regex).
• Correlation IDs break at the gateway or proxy: an upstream proxy strips X-Correlation-Id. Whitelist the header in the proxy and regenerate only when absent — never overwrite an incoming one.
• MDC/context empty inside async code: thread-local context doesn’t cross thread boundaries. Capture the ID before the async handoff or use a propagating executor.
• Audit gaps during traffic spikes: the log sink applies backpressure and drops entries — I’ve watched whole bursts vanish from the trail during an incident that needed them most. Use a local buffer with disk overflow so bursts can’t silently erase the trail.
• Client IP shows the proxy, not the user: behind a load balancer, request.client.host or req.ip returns the proxy address. Trust X-Forwarded-For only from known proxies — Express needs app.set('trust proxy', ...), FastAPI a ProxyHeadersMiddleware.

Operations at Scale

Ballpark figures as of late 2026 — validate against current pricing and your own volume before budgeting:

Component	Approx. cost (1M logs/day)	Notes
ELK self-hosted	$200–$500/month	3-node cluster, ~100 GB storage
Datadog	$1,500–$3,000/month	Ingestion + retention
CloudWatch	$150–$400/month	~$0.50/GB ingest, ~$0.03/GB storage
Loki + Grafana	$100–$300/month	Self-hosted, S3 backend
Audit archive (S3 Glacier)	~$0.004/GB/month	7-year retention costs almost nothing

Volume grows fast: 10K req/s is roughly 35–80 GB of logs/day for minimal access entries (~40–90 bytes each), but full audit records with actor, resource, and outcome fields run 200–500 bytes and push the same traffic to 170–430 GB/day. Synchronous writes to a remote sink add milliseconds per request and can cut throughput sharply; an async buffer with background flush keeps overhead near zero. For cost control, sample routine INFO entries (e.g., 10%) while keeping every WARN and ERROR. In microservices, one user request may touch 5–15 services — OpenTelemetry complements logs with the full call graph.

Production Checklist

• Sensitive fields (passwords, tokens, PII) redacted or hashed before logging
• Correlation ID generated at the edge and propagated to all services
• Audit entries include timestamp (UTC), actor, action, resource, outcome
• Audit storage is append-only or WORM and access-controlled
• Log level set via environment variable, not hardcoded
• Async logging enabled with a buffer of at least 1,000 entries
• Rotation configured (e.g., 100 MB max file, 30-day retention per policy)
• Log shipping to centralized storage handles backpressure without drops
• Alerts on ERROR rate and on >2× normal log volume
• Output verified in staging: format, redaction, and correlation IDs

Testing Strategy

• Redaction: send requests with API keys and PII in headers and bodies; assert the output shows [REDACTED] or ***.
• Correlation propagation: fire one request and assert the same ID appears in every log entry it produces.
• Immutability: write an audit entry, try to modify it, and verify the append-only store rejects the write.
• Retention: create entries older than the retention window and verify archival or deletion runs on schedule.

Further Reading

• OWASP Logging Cheat Sheet — what to log, what to exclude, and how to handle injection.
• W3C Trace Context — the standard behind cross-service correlation headers.
• Pino documentation — high-performance structured logging for Node.js.
• structlog documentation — context-bound structured logging for Python.
• Runnable companion examples — the three middlewares from this page as runnable projects.