Ch.2: OpenTelemetry: How Engineers Debug in 3 Pivot Clicks

Transcript

0:00 Tuesday afternoon, two 14 P M. Your phone lights up. The checkout endpoint just jumped from two hundred milliseconds at p 99 to 4 seconds, and the error rate is climbing. You open the dashboard. Not even two A M this time. This one is happening while everyone is online. Right. Three pivot clicks. That is what turns this dashboard alert into "three retries against a degraded replica." Metrics, traces, and logs are the three signals of any modern system, and each answers a different shape of question.

0:30 One debug story, three tools, and the mechanism that ties them together. So the first move is the dashboard, every single time. For example, take this incident. You pull up the service health page, find checkout, and there it is. The p 99 latency line was flat at two hundred milliseconds all morning, and then at two 11 it steps straight up to 4 seconds. Right next to it, the error rate panel is sitting at 4 percent and climbing. So in the first 10 seconds, two questions are already answered. Yes, something is wrong. Yes, it is bad.

1:04 Exactly. And on a good day, you, Also see which deploy correlates with the step. Metrics size the problem, name when it started, and quantify how bad it is right now. That sets up the obvious follow-up question. Which request is hot. From that dashboard read, here is the trap. People think the dashboard tells them everything. It does not. Yeah. The dashboard is great at telling you something is wrong, and useless at telling you anything else. Right. It told you the system is hot. It did not tell you which request is hot, which of the 8 services is the slow one, or what is happening to those failing requests.

1:43 Sure. Three different questions, 0 answers. Honestly, we have all spent 90 minutes scrolling dashboards before realizing we should have opened the trace view 40 minutes earlier. The official docs are blunt about this. I think that is the standard new-engineer mistake, and now we can see why we need a different tool. So you tab over to the tracing backend. You filter the request list. Service, checkout. Duration, more than 3 seconds. The list comes back with maybe a dozen requests, all from the last few minutes.

2:13 Same time window as the dashboard, just sliced a different way. One row per request, not one number per minute. Yep. You pick the top of the list. 4.1 seconds. One click. So what is in that click? Let's hear it. From that one click, here's where it gets really interesting. Imagine a stack of horizontal bars. The top bar is the api gateway, 4.1 seconds long. Indented under it, the cart service, 3.9. Indented under that, inventory, 3.7. And indented under that, one tiny dark bar labeled inventory database query, 3.6.

2:52 Yeah. The first time you see a view like this, production debugging just becomes a different job. You sit there for a minute. It is that good. I think it stays that good every time. Right. Each bar is one span. Parent on top, children indented beneath. Now the question stops being is checkout slow, and becomes which span ate the time. So look at the math now. Total request time, 4.1 seconds. The api gateway adds basically nothing. Cart adds basically nothing. Inventory itself adds basically nothing.

3:27 The 3.6 seconds is entirely inside that one tiny bottom bar, the database query. Wait so the inventory team did not even cause this? Right. It is one specific call inventory made downstream, not the service itself. That is the kind of answer a metric does not give you. The dashboard would just say checkout is slow, and you would still be searching 40 hosts. But the trace stops at 3.6 seconds in the database call. It does not say why. For that, you need to know what was happening inside that exact span.

4:00 Yeah. Now you want the log lines for those 3.6 seconds. And here is the cleanest move in the whole flow. The trace ID and the span ID are already in each log line, because the logging library and the tracing library cooperate. They share context behind the scenes. So you click view logs, and the viewer comes up filtered to just this request, just this span. No copy-paste, no remembering the timestamp. And there are four lines waiting for you. The first three are identical in shape. Retry one of three, replica D B replica two, timeout. Retry two of three, replica D B replica two, timeout. Retry three of three, replica D B replica two, timeout.

4:44 The 4th line says, fallback to primary, success in 12 milliseconds. Oh, no way. So the story tells itself. Inventory tried to read from a degraded replica three times. Each timeout was about a second. Then it fell back to the primary and that worked instantly. Yep. Three clicks, total. Dashboard, trace, logs. 3 minutes flat. Compared to the 6 hours we used to spend grepping. But notice what just happened. The magic move was not any one of the three tools. It was that you could click from one to the next without re-orienting.

5:19 Yeah. Each click took the context with you. The same trace ID lived in the metric, in the trace, in the log records. Right. That is the whole game. Three shapes of question, three tools, one shared thread of identity tying them together. 6-minute debug instead of 6-hour. So let me name the three shapes. Metrics answer is something wrong, and how bad. That is the smoke alarm. Traces answer which path through the system is slow, and at which step. That is walking through the building to find the room.

5:52 And logs answer what exactly happened in that step. That is the surveillance footage in the room. Yeah. And the trap is treating them as interchangeable. They are not. A metric does not tell you which downstream call is slow. A trace does not name the error code unless someone attached it. A log does not let you count fleet-wide frequency on its own. Exactly. Each one is a different kind of question. The pivot between them is the value. The signals are the inventory; the pivot is the verb. And the reason the pivot works the same way everywhere is OpenTelemetry.

6:28 The official docs name it as the vendor-neutral standard for emitting traces, metrics, and logs. Same SDK in your application code, regardless of which signal type. The application stops caring whether the bytes leaving it are a metric, a span, or a log. Source links are in the description. Same wire format, called OTLP. That gives you one shared protocol across all three signals. From that unification, two words that get used interchangeably and should not be. Telemetry is the data your system emits about itself.

6:58 The numbers, the spans, the structured log records. Observability is what you can learn from that data later. The practice of asking questions of it. So you cannot really buy observability. You can only set up the telemetry that makes it possible. Exactly. The tooling lets you ask questions. The asking is on you. Which means a lot of engineers stop right here, and that is where the trap shows up. Common mistake. Every new engineer says some version of this out loud at some point. I have logs, why do I need any of this.

7:30 And it is a fair question. Sure. The honest answer is concrete. Imagine a new engineer on call who opens the dashboard during their first incident, watches the latency line climb, and burns 3 hours grepping 40 hosts before someone hands them the trace view. That is the standard story without these tools. Right. Take a system that is one machine. Logs are enough. Take a system that is 8 machines. They are not. Without the trace ID stitched through each log line, the three-click pivot simply does not exist.

8:03 One machine, you grep. 8 machines, you need the pivot. From that misconception back to the practical promise. Every production team that runs services calling services has the same three questions, and the engineers who can answer them in three pivot clicks are the ones who go home on time. Next time, we open up what a span actually is, the atom of every trace, and the piece of vocabulary the whole rest of the series builds on. Thanks for listening to Learning Podcasts.