Observability · advanced

Logs show success but the user sees failure: reconcile layers and timing

When a success event in logs does not match what the user sees, the fault lies in the boundary between layers or in the way success is defined. This guide walks through reconciling distributed layers and timing so that observability evidence matches user-visible behavior, rather than papering over the gap.

The symptoms

  • Server logs, traces, or metrics record a 200/OK or "processed" outcome, while the user reports a failure, timeout, or missing result on the same interaction.
  • The same request identifier appears as success in one service's logs but as error or absent in a downstream service, edge component, or client telemetry.
  • Dashboards show a green SLO while user-facing error rates, support tickets, or synthetic checks report breakage at the same time window.
  • Replay tooling shows a "successful" event being emitted just before, after, or in parallel with a user-visible failure, with no obvious correlation between them.

Likely causes

  • Different layers define success independently: one layer logs when its local operation completes (e.g., enqueued, accepted, persisted locally) while another layer owns the user-visible outcome (e.g., delivered, rendered, applied).
  • Clock skew or timestamp source mismatch across services makes a later failure look like it happened before a logged success, hiding the causal order.
  • Asynchronous fan-out: the request returns to the user before background work finishes, and the background work is what actually determines the user's outcome.
  • Lossy or sampled observability: high-cardinality failure events are dropped, redacted, or routed to a different pipeline than the success events that survive sampling.
  • Version skew: the code path emitting the success log differs from the code path serving the user (canary, feature flag, blue/green, stale client cache).

First ten minutes

  1. 01Pin down the user's reported outcome in observable terms: what they saw, what they expected, and the time window, including their timezone, so server timestamps can be aligned.
  2. 02Obtain the request identifier from the user-visible surface (correlation header, session id, trace id) and locate the corresponding trace in the tracing backend.
  3. 03List every layer that emitted a "success" or "complete" event for that request id, and for each, record its definition of success and the timestamp source it used.
  4. 04Identify which layer the user actually interacts with at the moment of failure (UI, edge, gateway, worker, third party) and confirm whether that layer has its own telemetry distinct from the success-emitting layer.
  5. 05Compare the trace's span timeline against the user's reported timeline; flag spans whose logical order disagrees with their emitted timestamps.

Evidence to collect

  • The full trace (all spans) for the affected request id, including child spans of background workers and retries.
  • Structured log fields with the same request id across each layer: status code, outcome field, error field, and the exact timestamp and clock domain used.
  • User-side evidence: client logs, browser console, mobile crash report, support ticket transcript, or synthetic monitor output for the same time window.
  • Configuration snapshot of the relevant services at the time of the event: feature flags, deploy version, sampling rate, and any canary routing rules.
  • Any downstream system that the user depends on (queue depth, dead-letter counts, third-party webhooks) at the moment of the user's reported failure.

Where to look

  • The boundary between synchronous request handling and asynchronous post-processing, where the response to the user diverges from the work that determines the outcome.
  • The boundary between the service emitting the success log and the component actually serving the user (edge cache, CDN, mobile shell, partner API).
  • The boundary where sampling, redaction, or routing decisions differ between success and failure events for the same logical operation.
  • The boundary between clock domains: server clock, container clock, client clock, and any external system whose timestamp is included in logs.

Diagnostic steps

  1. 01For each "success" event, write down its operational definition in one sentence (e.g., "DB row written", "message enqueued", "response sent") and compare it against the user's definition of success ("data visible", "email received").
  2. 02Walk the trace and confirm every span is a child of the user-facing entry span; orphan or sibling spans are candidates for the work the user is actually waiting on.
  3. 03Reorder spans by their causal dependencies (parent-child edges, retries, async triggers) and check whether the emitted timestamps preserve that order; if not, identify the clock that disagrees.
  4. 04Search the trace for spans whose status or outcome field is missing or defaulted; these are often the layer that silently drops failure signals.
  5. 05Compare sampling decisions: confirm that the failure path and the success path for the same request id are both retained, not just the cheaper or happier path.
  6. 06Verify the deployed binary or feature-flag state matches the build that produced the success log; mismatches mean the log describes a code path the user never executed.

Common mistakes

  • Treating any single 200 response as proof the system worked, without checking whether the response is the one the user ultimately depends on.
  • Assuming all services share a clock; mixing UTC server timestamps with client-local timestamps in the same timeline hides ordering bugs.
  • Reading only the structured "status" field and ignoring adjacent fields such as error, retry_count, degraded, or partial that explain what really happened.
  • Trusting dashboards that aggregate only success-coded events, which can stay green while user-visible failures grow in untracked paths.
  • Stopping investigation at the first "successful" service instead of following the request id through every layer that can affect the user's outcome.

Safe fixes

  • Define a shared success contract per user-visible operation, agreed by all emitting layers, and add an end-to-end check (synthetic or shadow) that exercises the full path the user actually takes.
  • After confirming a mismatch between layer-local success and user outcome, adjust logs and traces to record both the local definition and the end-to-end definition on the same event; do not delete the existing success log without first archiving the evidence.
  • Normalize timestamps to a single clock domain on the span or log envelope, and document which clock is authoritative for ordering.
  • Ensure failure events are subject to the same retention and routing as success events; if a redaction or sampling rule hides them, scope the rule so it does not hide the user-visible failure path.
  • When the divergence is caused by asynchronous work, emit a separate end-to-end completion event tied to the same trace id once the background work resolves, and alert on its absence.

Prove the fix

  1. 01A synthetic check that performs the full user-visible operation end-to-end and asserts both the layer-local success event and the end-to-end completion event appear under the same trace id within a bounded time.
  2. 02A reconciliation query that joins the success-emitting layer's logs with the user-facing layer's telemetry by trace id and reports any request where the two outcomes disagree.
  3. 03A clock-ordering check: for a sample of traces, verify that emitted timestamps respect the causal order of spans; regressions indicate a clock-domain regression.
  4. 04A sampling parity check: confirm that for the same request id, both success-path and failure-path spans are retained at the configured rate.
  5. 05A user-side evidence check: client or synthetic reports for the operation show the same outcome as the end-to-end event in the same window.

Prevention and next steps

  • Make every observability event carry the trace id and the operation id, and require both to be present in any alert, dashboard, or runbook reference.
  • Define success in user-visible terms before defining service-level success metrics, and link each service metric to the user-visible metric it is meant to support.
  • Standardize on a single clock domain for trace ordering and document the rule alongside any service that emits wall-clock timestamps.
  • Treat background work as part of the user-visible request until proven otherwise: give it a span under the same trace and a completion event the user can be measured against.

Safe commands and checks

grep -n "trace_id" <service_log_path> | head -n 20
awk -F',' '$1=="<trace_id>" {print}' <merged_trace_export.csv>
sort -t',' -k3 <trace_spans.csv> | head -n 50
grep -E '"outcome":"(success|complete|ok)"' <service_log_path> | wc -l