Skip to main content
Back to path

Welcome to a Grasp lesson

Create a free account to keep studying and create your own study path.

Lesson 74

Outage Timeline Reconstruction with Traces, Logs, and Metrics

Recommended resources

Introduction

In our previous lesson, we established a systematic framework for root cause analysis, moving from the "what" of an incident to the "why." We discussed the importance of a structured methodology—like the SRE "Triage, Examine, Diagnose" model—and the power of high-cardinality observability. Now, it's time to put that theory into practice.

This lesson directly addresses the learning outcome: Analyze a distributed system outage scenario using traces, logs, and metrics to construct a timeline of events. We will simulate a live-fire exercise, walking through a realistic outage in a multi-service environment. Your task will be to act as the lead investigator, using the available telemetry to piece together the sequence of events, isolate the fault, and identify the root cause. This process of timeline reconstruction is one of the most powerful diagnostic techniques in a Principal Engineer's toolkit.

The Investigator's Toolkit: Traces, Logs, and Metrics

Before we dive into the scenario, let's solidify our understanding of the primary tool for this kind of investigation: the distributed trace. At Google, the foundation for this capability was laid by Dapper, a system designed to provide visibility into complex service interactions with minimal overhead. Since you're interested in Google's foundational papers, understanding Dapper's core concepts is essential.

Dapper, a Large-Scale Distributed Systems Tracing ...

This paper from Google Research details the design and motivation behind Dapper. It's the intellectual predecessor to modern open-source tracing systems like Jaeger and Zipkin and is a cornerstone of observability within Google.

Please read two key sections: The Introduction (introduction) outlines the challenges of understanding systems like Google Search and establishes the core design goals: low overhead, application-level transparency, and scalability. Section 2, Distributed Tracing in Dapper (the core data model), explains the concepts of trace trees, spans, and annotations. Pay close attention to how trace id, span id, and parent id are used to reconstruct the causal relationships between remote procedure calls (RPCs).

To complement the dense academic paper, the following video provides a more conversational walkthrough of the same core concepts, which can help solidify your understanding.

Google Dapper - Distributed Tracing | Distributed Systems Deep Dives With Ex-Google SWE

This video, from the "Distributed Systems Deep Dives" series, effectively breaks down the Dapper paper.

Focus on these segments: The explanation of traces and spans visually demonstrates how nested RPCs form a tree structure. The discussion on span data details the specific timestamps collected and how Dapper accounts for clock skew—a critical detail in distributed systems. This segment explains how an engineer uses a trace to understand the full request path and identify unexpected behavior, which is the heart of our analysis today.

A trace tells you the path and timing of a single request (the "what" and "where"). Metrics tell you the aggregate health of the system over time (the "when"). Logs provide the detailed, ground-level truth about specific events (the "why"). The magic of modern RCA happens when you can seamlessly pivot between these three views.

The following short video demonstrates this workflow using the popular open-source Grafana stack. While Google's internal tools differ, the principles of correlation are identical.

Correlate Your Metrics, Logs & Traces with the curated OSS observability stack from Grafana Labs

This video from Grafana Labs, "Correlate Your Metrics, Logs & Traces," provides a concise demonstration of the workflow we're about to simulate.

Watch the entire short video (full demo). Notice how the investigation flows from a metric spike (Prometheus) to the relevant logs (Loki) and then to a specific trace (Tempo) to pinpoint the source of latency. This is the exact pattern we will follow.

Outage Scenario: The Checkout Service is Failing

It's 14:06 on a Tuesday. PagerDuty fires an alert: "P1: High 5xx Error Rate on CheckoutService". Users are reporting that they cannot complete purchases. As the Principal Engineer on call for the e-commerce platform, you are leading the investigation.

Your platform consists of several key microservices:

  • API Gateway: The public entry point.
  • CheckoutService: Orchestrates the checkout flow.
  • OrderService: Creates and manages orders. It depends on the InventoryService.
  • InventoryService: Manages stock levels for all products. It relies on a dedicated database.
  • NotificationService: Sends emails and SMS messages.

You open your observability dashboard. The goal is to reconstruct the timeline of the incident to find the first deviation from normal behavior. This is the most important step, as it prevents you from getting distracted by downstream symptoms.

This example of a tracing UI shows a dependency graph, correlated errors, and logs. This is the type of integrated view you would use to begin your investigation.

Step 1: Analyze Metrics to Find the "When"

You look at a dashboard plotting the error rates and p99 latencies for all services in the checkout flow.

  • CheckoutService: 5xx error rate began climbing sharply at 14:05. Latency is also elevated. This matches the alert.
  • OrderService: 5xx error rate also began climbing at 14:05.
  • InventoryService: Error rate is normal. However, its p99 latency metric began to spike at 14:03, a full two minutes before the user-facing errors appeared.
  • NotificationService: All metrics are normal.

Analysis: The InventoryService is the first component to show an anomaly. This is our strongest lead. The two-minute delay between its latency spike and the CheckoutService errors is characteristic of a cascading failure, where timeouts propagate up the call stack. Chasing the CheckoutService errors would be a waste of time; the problem likely originates further down.

Step 2: Isolate with Traces to Find the "Where"

Now that your primary suspect is the InventoryService, you need to confirm where inside that service the latency is occurring. You filter for traces corresponding to requests that passed through the CheckoutService between 14:03 and 14:05 and ended in an error.

You find a representative trace and open it in the trace view.

This interface, similar to the one described in the Dapper paper, provides multiple views for analysis. Panel 5, the trace timeline view, is what you are now examining.

The trace timeline (similar to panel 5 in the image above) shows the end-to-end request flow:

  1. A 15ms span for the API Gateway.
  2. A 5000ms span for the CheckoutService.
  3. Nested inside CheckoutService, a 4980ms span for OrderService.
  4. Nested inside OrderService, a 4950ms span for a call to InventoryService. This is the problem.
  5. Nested inside InventoryService, you see a 4900ms span labeled db.query. The call to the database is taking almost 5 seconds, eventually causing the upstream OrderService to time out.

Analysis: The trace confirms that the latency originates within the InventoryService and is specifically tied to its database interactions. You have successfully isolated the fault from the entire distributed system down to a single component's outbound call.

Step 3: Pinpoint with Logs to Find the "Why"

You now know the "where" (the InventoryService's database call). The final question is "why." You click on the db.query span in your tracing UI, which automatically pivots to the logs for the InventoryService from that exact moment in time, already filtered by the trace.id.

The logs show the following message, repeated thousands of times:

time="14:03:15" level=error msg="Failed to acquire DB connection" error="context deadline exceeded; connection pool exhausted"

This is the smoking gun. The service is slow because it can't get a connection to its database. The connection pool is empty.

Step 4: Correlate with Change Events to Find the Root Cause

Why did the connection pool suddenly become exhausted at 14:03? This is unlikely to be a code bug that suddenly manifested. The most probable cause is a change. You query your deployment and configuration change log.

You find the following entry:

  • Timestamp: 14:00
  • Service: InventoryService
  • Change: Configuration Push - helm_vars.yaml
  • Author: automation-bot
  • Diff: - db.max_connections: 100
    + db.max_connections: 10

A typo in a configuration file, deployed automatically at 14:00, reduced the database connection pool size by 90%. Under normal traffic, the pool began to exhaust three minutes later, triggering the cascading failure. This is the root cause.

The Reconstructed Timeline

By following this systematic process, you have constructed a precise, evidence-backed timeline of the incident. This is the core of any post-mortem document.

  • 14:00: A configuration change is deployed to InventoryService, incorrectly setting db.max_connections to 10.
  • 14:03: Under normal load, the InventoryService's database connection pool becomes saturated. Its p99 latency metric begins to spike.
  • 14:05: Upstream calls from OrderService to InventoryService begin to time out after waiting for a database connection. The OrderService's error rate metric begins to climb.
  • 14:05: CheckoutService calls to the failing OrderService also begin to time out, returning 5xx errors to the user.
  • 14:06: An SLO-based alert fires for the CheckoutService's error rate, paging the on-call engineer.
  • 14:15: The on-call engineer, following the timeline of anomalies, identifies the incorrect configuration and initiates a rollback.

This step-by-step reconstruction, starting from the earliest anomaly, is the key to efficient RCA in a distributed environment. It avoids the "fog of war" where multiple services are alerting simultaneously.

Conclusion

In this lesson, we transitioned from the theory of RCA to its practical application. We walked through a realistic outage, demonstrating how to systematically diagnose a cascading failure in a complex microservices architecture.

The key takeaways from this exercise are:

  • Timeline reconstruction is paramount. The most critical skill in a large-scale outage is to build a timeline of events, starting from the earliest anomaly in your metrics.
  • Metrics, logs, and traces are a synergistic trio. You used metrics to find when the problem started, traces to find where it was located, and logs to find out why it was happening.
  • Most incidents are caused by change. Always correlate the incident timeline with deployment, configuration, and infrastructure change logs.
  • Distributed tracing is non-negotiable. Without the ability to trace a request end-to-end, as pioneered by systems like Dapper, isolating a fault in a deep call stack becomes a matter of guesswork.

You have now analyzed an outage using the primary data sources available to an engineer. In our next lesson, we will continue this practical focus by tackling the learning outcome: Apply diagnostic techniques to pinpoint the root cause of a performance bottleneck in a given scenario. We will shift from a full outage to a more subtle "tail latency" problem, which requires an even finer-grained diagnostic approach.