Deconstructing Distributed Tracing

♪ ♪ Reconstructing distributed tracing. Hello, everyone. My name is Laza Nikolov, and I am a developer advocate at Sentry. Today on my talk, we're going to talk about distributed tracing. First explain what it is. Then we're going to get into a little history on the debugging tools to find out why distributed tracing existed in the first place. And then in order to understand it better, we're going to rebuild distributed tracing from scratch or at least just the concept of it.

All right, so let's dive in. Distributed tracing is a powerful technique that allows you to track the flow and timing of requests and operations as they flow through your system. This is especially useful for full stack and for microservice applications. Distributed tracing helps you understand the performance of the system and also identify any bottlenecks. It's especially useful for debugging complex and weird bugs like race condition bugs that require a lot more than just a console lock and a stack trace. It's not new by any means. There are white papers mentioning tracing since the early 2000s, but it got popularized during the 2010s. So to understand why it exists, we need to go back in time.

As our libraries and frameworks evolved, so did our debugging tools. For example, back in the early days of Apache Server, logs were one of the few methods for debugging. As requests arrived, Apache forked a child process and handled the requests. If you wanted to debug what happened during that specific request, you could just pull the process's logs and you'll see the whole operation flow. And that worked. We were happy. Then we got basic concurrency. Think of IIS in ASP.NET. Instead of forking a process for every request, we started handling multiple requests in a single process, but in a separate thread. Logs are still a good debugging method, but to isolate the request's logs, we need to prefix them with the thread name and then filter the log messages based on it. Not a big deal, but we made it work. Then we got advanced concurrency. Our frameworks evolved into async, multithreaded, futures and promises, event loop-based frameworks. This is Node.js. So now our request can start at one thread, but finish at a different one, going through many other threads along the way.

Prefixing them with the thread name doesn't really solve our problem now. We need to prefix them with something unique to the request itself, and that's what we did. We generated a unique ID for each request and prefixed it, our logs.

But our frameworks didn't stop evolving. About 10 years ago, Docker and AWS made way for containerized services. And now our backends don't even live on one single machine. Each container and microservice handled multiple requests and produced its own logs. Our logs are all over the place now. It was very hard to make sense of the operation flow, so we needed a better debugging tool that can trace the operations as they jump between containers and services. That's when distributed tracing became a necessary tool for debugging.

In order to understand how it works, we're going to reinvent it from scratch. Since our backends now have a very distributed nature, we needed to define a vehicle for each request that will follow it around and capture debugging data along the way. Let's call that a trace. The trace will start when the operation flow starts, and it's going to have a unique ID. That can be the frontend, for example.

If we think about logs, they usually tell us what happened at a particular time. They try to mimic the structure of our code. So let's invent that now. Let's invent something that's going to describe the smallest unit of work, like an HTTP request or a function call or anything specific that our software does at a specific time. We're going to call that a span, and we're going to create one immediately when the trace starts. That's going to be our root span.

So just like the log, the spans are going to mimic the structure of our software. But since we're reinventing it, let's make it much smarter than simple messages. So since spans are the smallest unit of work, like a single function, and we know that one function can invoke another function, which in turn can also invoke a third function, we're going to design our spans so they can create child spans, which can to create their own child spans and so on. Now we can really mirror the structure of our software with this. We have a span hierarchy, but we need to remember which span is a child of which span. To do that, we're going to need something to identify each span. So we will assign an ID to each span as we create them. We also need to save the parent span ID. So let's create a space inside each span so it can hold data like its ID and its parent ID.

But why stop there? We got space for more data. Let's keep a set of tags so we can search and aggregate and group them later. Let's also keep a status field that's going to indicate whether the spans work, finish successfully or not. We can basically keep any kind of data that can be useful later on.

Since we know when we create them, let's introduce a finish method that'll write down when the spans finished. So now we can calculate how long the spans took. We have enough info to chart them now. And if we do, we're going to be able to identify performance bottlenecks easily. I mean, there'll be obvious that span should not take that much.

But still, how do we distribute this now? How can we continue this trace on the backend? We had the trace and its ID. We also have a bunch of spans attached to it. Let's create a trace context that's going to concatenate the trace ID and the ID of the last span into a string. We can now transfer this string so our backend or the next processing units can parse it and continue tracing, starting from the last span. Since it's going to be a string, we can easily transfer it, whether it's a client, a microservice, a cron job, or it's in JavaScript or Python or PHP, as long as it can parse and read a string, it can continue our trace. And that's distributed tracing.