The useful unit of application logging is a decision, not a line of prose. For a media SaaS rolling out a pricing rule behind a flag, emit JSON events that connect one request to its trace, tenant, actor, flag variant, rule result, and resource usage. Keep direct personal data out through an allowlist. Then compare cost and correctness by variant in an evaluation harness before widening exposure.
TL;DR: generate a request ID at the application edge, preserve a valid W3C trace ID when one exists, and attach both through request-scoped context. Use opaque internal IDs for tenant_id and actor_id; never treat masking after serialization as a privacy boundary. Log a dedicated pricing-decision event with stable field names and bounded values. This makes a flag rollout inspectable without turning every log record into an expensive bag of labels.
The tempting first version is a middleware that dumps request headers, bodies, and a message such as pricing succeeded. It feels complete in a notebook. It fails the production question: did the candidate rule change resource consumption or outcomes for a particular cohort, and can an operator follow the affected request without searching for an email address?
Schema drift hurts.
What should a SaaS application log for each structured request?
Start from the questions the rollout must answer. A request ID joins application events inside one request. A trace ID joins work across services that participate in the same distributed trace. They are related, but they are not interchangeable. W3C Trace Context defines the traceparent header and its fixed fields; in version 00, a trace ID is 32 lowercase hexadecimal characters and a parent ID is 16. The example below accepts the trace ID only after validating the complete header shape, including rejection of all-zero identifiers. That exactness matters because a near-match accepted at the edge can create correlation data that looks valid until an investigation depends on it.
Identity needs more restraint. tenant_id supports cost ownership, while actor_id can distinguish an authenticated user or service account. Both should be opaque application identifiers. Names, email addresses, authorization headers, cookies, article text, search queries, payment details, and raw prompts do not belong in the event. If support needs to locate an actor from an email address, resolve that through an access-controlled application workflow and then search by the internal ID.
For this rollout, one focused event is enough:
| Field | Purpose | Cardinality rule |
|---|---|---|
request_id, trace_id
|
Correlation during investigation | Keep in logs and traces, not metric labels |
tenant_id, actor_id
|
Ownership and access-scoped lookup | Opaque IDs; restrict access and retention |
flag, variant
|
Identify the evaluated rollout branch | Enumerated, bounded values |
rule_version |
Reproduce pricing logic | Deployment-controlled value |
media_kind |
Compare stable workload classes | Small enum such as article or video
|
duration_ms |
Attribute application work | Numeric observation |
input_tokens, output_tokens
|
Attribute model usage when invoked | Counts, never prompt or response text |
outcome |
Feed the evaluation set | Small enum, not an exception message |
Do not put request_id, trace_id, actor_id, or tenant_id into Prometheus label sets. Prometheus recommends labels whose possible values do not grow without bound; per-request and per-user identifiers violate that constraint. Logs retain those dimensions for investigation, while metrics aggregate on bounded fields such as variant, media kind, and outcome.
Build request context at the FastAPI boundary
Python's contextvars module gives each asynchronous request its own context. The middleware below generates an application request ID, extracts a valid incoming trace ID when present, and returns the request ID to the caller. It does not echo an untrusted incoming request ID into logs.
import contextvars
import json
import logging
import re
import time
import uuid
from collections.abc import Awaitable, Callable
from typing import Any
from fastapi import FastAPI, Request, Response
request_context: contextvars.ContextVar[dict[str, str]] = contextvars.ContextVar(
"request_context", default={}
)
TRACEPARENT = re.compile(
r"^(?!ff)[0-9a-f]{2}-(?!0{32})[0-9a-f]{32}-(?!0{16})[0-9a-f]{16}-[0-9a-f]{2}$"
)
def trace_id_from(request: Request) -> str:
traceparent = request.headers.get("traceparent", "").lower()
if TRACEPARENT.fullmatch(traceparent):
return traceparent.split("-")[1]
return uuid.uuid4().hex
class JsonFormatter(logging.Formatter):
def format(self, record: logging.LogRecord) -> str:
event = {
"timestamp": self.formatTime(record, "%Y-%m-%dT%H:%M:%S%z"),
"level": record.levelname.lower(),
"logger": record.name,
"message": record.getMessage(),
**request_context.get(),
}
fields = getattr(record, "event_fields", {})
event.update(allowlisted(fields))
if record.exc_info:
event["error_type"] = record.exc_info[0].__name__
return json.dumps(event, separators=(",", ":"), sort_keys=True)
app = FastAPI()
handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logger = logging.getLogger("pricing")
logger.handlers = [handler]
logger.setLevel(logging.INFO)
logger.propagate = False
@app.middleware("http")
async def add_request_context(
request: Request,
call_next: Callable[[Request], Awaitable[Response]],
) -> Response:
request_id = str(uuid.uuid4())
token = request_context.set(
{"request_id": request_id, "trace_id": trace_id_from(request)}
)
started = time.perf_counter()
try:
response = await call_next(request)
response.headers["X-Request-ID"] = request_id
return response
finally:
logger.info(
"request.completed",
extra={
"event_fields": {
"event": "request.completed",
"method": request.method,
"route": request.scope.get("route").path
if request.scope.get("route")
else "unmatched",
"duration_ms": round((time.perf_counter() - started) * 1000, 2),
}
},
)
request_context.reset(token)
There is one deliberate compromise here: a request without a valid distributed trace gets a locally generated trace ID for correlation, but this snippet does not create spans or propagate a new traceparent downstream. In an instrumented service, the tracing SDK should own span creation and propagation, and the logger should read the active span context. Inventing half a tracing system in logging middleware creates split traces.
This approach has limitations. The local fallback improves log correlation inside one process, yet it cannot provide parent-child timing, sampling decisions, or downstream propagation. The trade-off is acceptable for an application that only needs request-local JSON logs; it is the wrong endpoint for a distributed system that needs causal traces. In that case, use standards-based tracing instrumentation as the source of trace context and treat the logger as a consumer. Context variables have another boundary: work handed to an external queue needs explicit correlation fields in the message envelope because request-local Python context does not travel through a broker. Those boundaries should be tests, not tribal knowledge.
The formatter also records only the exception class. Stack traces are operationally useful, but exception messages can contain submitted values. A production error pipeline should apply the same field policy to stack data and limit access separately.
Make PII exclusion structural
Redaction by regular expression is a weak final control. Email patterns miss names, free-form addresses, bearer tokens, and domain-specific identifiers; broad patterns also destroy useful technical values. An allowlist gives the schema an explicit edge. Unknown fields disappear.
Add this function before the formatter is used:
ALLOWED_FIELDS = {
"event",
"method",
"route",
"duration_ms",
"tenant_id",
"actor_id",
"flag",
"variant",
"rule_version",
"media_kind",
"input_tokens",
"output_tokens",
"outcome",
}
def allowlisted(fields: dict[str, Any]) -> dict[str, Any]:
clean: dict[str, Any] = {}
for key, value in fields.items():
if key not in ALLOWED_FIELDS:
continue
if isinstance(value, (str, int, float, bool)) or value is None:
clean[key] = value
return clean
This is intentionally boring.
It blocks nested dictionaries, so a future developer cannot casually attach request.model_dump() or an entire model response. Hashing an email is not a universal escape hatch: a stable hash remains linkable, and low-entropy values can be guessed. Prefer an existing opaque ID with a documented lifecycle. The cost of this choice is maintenance: every new field requires a schema review and deployment, and aggressive exclusion can remove details that would help diagnose an unfamiliar failure. That is preferable to silent collection, but it means the team must review dropped-field counters and update the schema deliberately rather than assuming the first allowlist is permanent.
Authentication code should place only those opaque IDs into request context after verification. Logging filters do not replace authorization, retention limits, transport encryption, or deletion procedures. They reduce what enters the pipeline in the first place.
Emit a flag decision that an eval can score
The pricing function should return both its result and a small audit object. That keeps the log call next to the decision rather than reconstructing the variant later from deployment state. The sample uses Decimal for a deterministic rule and validates variants explicitly.
from dataclasses import dataclass
from decimal import Decimal
from typing import Literal
Variant = Literal["control", "candidate"]
@dataclass(frozen=True)
class PricingDecision:
amount: Decimal
variant: Variant
rule_version: str
def calculate_price(
base_amount: Decimal,
media_kind: Literal["article", "video"],
variant: Variant,
) -> PricingDecision:
if base_amount < 0:
raise ValueError("base_amount must be non-negative")
if variant == "candidate" and media_kind == "video":
return PricingDecision(
amount=(base_amount * Decimal("1.08")).quantize(Decimal("0.01")),
variant=variant,
rule_version="media-video-2",
)
return PricingDecision(
amount=base_amount.quantize(Decimal("0.01")),
variant=variant,
rule_version="media-control-1",
)
def record_decision(
decision: PricingDecision,
tenant_id: str,
actor_id: str,
media_kind: str,
duration_ms: float,
input_tokens: int = 0,
output_tokens: int = 0,
) -> None:
logger.info(
"pricing.rule_evaluated",
extra={
"event_fields": {
"event": "pricing.rule_evaluated",
"tenant_id": tenant_id,
"actor_id": actor_id,
"flag": "media_pricing_rule",
"variant": decision.variant,
"rule_version": decision.rule_version,
"media_kind": media_kind,
"duration_ms": duration_ms,
"input_tokens": input_tokens,
"output_tokens": output_tokens,
"outcome": "accepted",
}
},
)
The multiplier is example policy, not a recommendation. More important, the event omits the actual amount. Amounts may be legitimate operational data, but they are unnecessary for the stated cost-attribution question and create a wider data-governance surface. A finance-owned audit record can carry financial details under a different retention and access policy.
If AI enrichment participates in the request, record provider-reported input and output token counts after the call. Do not estimate them from raw prompt text inside the logger. The eval harness can aggregate counts by variant, rule_version, and media_kind, then join correctness labels from a controlled evaluation dataset. That is the notebook-to-production bridge: the same bounded dimensions used in the experiment survive deployment.
Decide whether the rollout should advance
Do not promote the candidate because its logs look clean. Before copying this design or widening the flag, define the comparison window and score at least four dimensions: pricing correctness against approved fixtures, error rate, latency distribution, and resource consumption. If an AI step exists, include token counts and model-quality evals. Compare like with like by media kind; a shift toward video traffic can otherwise masquerade as a variant effect.
Cardinality is part of the decision. Count distinct values for every proposed metric label and reject identifiers or unconstrained strings. Sample high-volume success logs only after confirming that decision counts and cost sums remain unbiased; always preserve the sampling rule as configuration, not folklore. Errors may need a different sampling policy.
Roll back on an explicit correctness or budget threshold defined by the team that owns the rule. The threshold cannot be derived from observability plumbing, and inventing a universal percentage would be fake precision. Also verify that malformed trace headers do not break requests, unknown log fields are discarded, concurrent requests never exchange context, and no fixture containing an email, token, or article body appears in captured output.
One more trap: logs are evidence, not the pricing ledger. Retries and duplicated delivery can produce multiple events for one logical operation. Financial reconciliation needs an idempotent transaction record with its own consistency rules; logging remains the diagnostic and evaluation view.
The rollout is ready when operators can explain a variant's outcome and resource use from bounded dimensions, follow an individual failure through request and trace identifiers, and do neither by collecting a reader's content or identity. Measure those properties before adopting the pattern. Pretty JSON is secondary.
References
- W3C Trace Context Recommendation: https://www.w3.org/TR/trace-context/
- Python
contextvarsdocumentation: https://docs.python.org/3/library/contextvars.html - Python logging cookbook: https://docs.python.org/3/howto/logging-cookbook.html
- OWASP Logging Cheat Sheet: https://cheatsheetseries.owasp.org/cheatsheets/Logging_Cheat_Sheet.html
- Prometheus metric and label naming guidance: https://prometheus.io/docs/practices/naming/
Further reading
- OpenTelemetry log data model: https://opentelemetry.io/docs/specs/otel/logs/data-model/
- OpenFeature evaluation context specification: https://openfeature.dev/specification/sections/evaluation-context/
Top comments (0)