← Learnings

Designing a system you can't debug

Your server's running somewhere you can't attach a debugger to, and everything you'll ever know about it is whatever it wrote down while it was running. So the decisions that matter all happened long before anything broke: what it records, how much of that we can afford to keep, and how any of it gets off the box. That's an architecture. It's also the one nobody draws.

Logs are just text

A log's a line of text with a timestamp. 14:20:11 error constraint violation on user_email. One line per moment worth recording, written by whatever code happened to be running at the time. The strength is that it can say literally anything — that constraint violation is a string somebody typed once, in the place where it happened, and it came through intact. Nobody had to guess in advance that this particular failure would matter one day.

We pay for that twice. One line per event means volume tracks traffic: twice the signups, twice the lines. And text has no structure to count over, so asking how many errors happened in the last hour means reading every line from the last hour and checking each one. Every time.

Metrics: the numbers we overwrite

Unlike logs, metrics aren't appended — they're overwritten. If signups_failed sits at 1,847, the next failure just bumps it to 1,848. The counter already existed; we just changed its value. That one tiny detail drives everything else about how metrics work. Most importantly, it means your storage costs have absolutely nothing to do with your traffic volume.

Ten failures or ten million, you're keeping one number. That's what makes a metric cheap enough to check every fifteen seconds, forever — which is exactly what an alert has to do. But the request is gone. Adding 1 to a counter keeps no record of which user, which endpoint, or what the error said. A metric tells you something's wrong and how bad. Never which request, and never why.

You get a little structure back with labels. signups_failed{reason="duplicate_email"} is a different counter from signups_failed{reason="timeout"}, and every combination you allow is another number to store. That's also how a metrics bill gets away from you — one of the three knobs further down.

Traces follow one request around

A trace follows a single request through every service it touches, and records how long each leg took. A signup comes in. On the way through it checks the address is free, writes the user row, sets up the new account's feeds and a good few more things besides — a dozen steps, one after another. Each step is a span, and the trace is the tree of spans that makes up the whole request.

The pieces have to find each other first. Each service makes its own spans in its own process. What turns them into one trace is a single ID riding along with the request: the first service invents it, sticks it on the call it makes, and everyone downstream reads it and passes it on unchanged. Anything else written while that request is in flight can stamp itself with the same ID — which is how a log line ends up knowing which trace it belongs to.

It's the only one of the three that shows you where time went across a service boundary. Logs from five services are five separate piles in five places, each one convinced it did its bit fine. A trace is one picture, in order, with the slow leg sitting right there in the middle of it.

What it costs is that we can't keep them all. Recording every span of every request is enormously expensive, so you keep a small fraction — one request in a hundred is a normal sampling rate — and bin the rest. Which is also why you can never count with traces. A trace won't tell you your error rate; it has no idea what it threw away.

The same signup, three different ways

Here's a single signup that took 4,812 ms and failed, written down all three ways at once.

ONE SIGNUP · 4,812 MS · FAILED · trace_id=4f2a9c METRICS signup_duration_seconds · p99 · last 6h 6.00 14:00NOW SLO 2.0S 4.81S EVERY SIGNUP, FOLDED TOGETHER. CROSSED THE OBJECTIVE AT 14:20. CARRIES NO REQUEST ID — THERE IS NO WAY BACK TO A SINGLE SIGNUP. TRACES SIGNUP · 4,812 MS TX 7 · 3,901 MS · 81% OF THE REQUEST 12 TRANSACTIONS, IN SEQUENCE · DRAWN TO SCALE LOGS 14:20:07.914 level=info trace_id=4f2a9c msg="creating user" 14:20:07.916 level=info trace_id=4f2a9c msg="saving feeds" 14:20:11.817 level=error trace_id=4f2a9c msg="constraint violation on user_email" 14:20:12.726 level=info trace_id=4f2a9c msg="rollback complete" THE ONLY LINE THAT NAMES A CAUSE · trace_id TIES ALL FOUR TO THE TRACE ABOVE
FIG 1 · ONE SIGNUP, WRITTEN DOWN THREE WAYS

The metric's p99 duration, and that dashed line marked SLO is the two-second target it's meant to stay under. It crossed at 14:20 and reads 4.81 seconds now. Enough to know something's wrong, how badly, and roughly when it started. Not enough to know which signup — this one's been folded in with a few thousand others, and the number is all that's left of it.

An average would've hidden it completely. Take a hundred signups where ninety-five come back in 200 ms and five take 4,812 ms. The average is 431 ms, which looks perfectly healthy. The p99 is 4,812 ms, because the slowest one percent is exactly what it reports. Averages bury a bad tail by dividing it across everyone who had a fine time.

The trace kept the shape. Twelve transactions ran one after another, and number 7 took 3,901 of the 4,812 ms. That's where to look. The log says what actually broke — a constraint violation on user_email. There was never a counter for that, because nobody knew to make one.

What ties the trace to the logs is trace_id=4f2a9c sitting on every one of them. The metric hasn't got one and can't — a point on that chart is a summary of thousands of requests, so there's no single request for it to name. That ID is how you get from "something's slow" to "here's the line that explains it". Without it you've got three piles that happen to be in the same building.

Why we can't just pick one

Each one's good at precisely what the other two can't do, and that's not a coincidence. It falls out of the decision each one made about what to keep.

THE QUESTION WHAT IT FORCES YOU TO STORE AND SO IT CANNOT METRICS IS IT WRONG, AND HOW BAD EVERY 15S, ALL TRAFFIC COUNT IT, DISCARD THE INDIVIDUAL REQUEST NAME A SINGLE REQUEST, OR SAY WHY IT FAILED TRACES WHERE DID THE TIME GO ONE REQUEST, EVERY HOP THE WHOLE TREE FOR ONE REQUEST — SO, SAMPLED GIVE YOU A RATE, BECAUSE IT ONLY SAW 1 IN 100 LOGS WHAT ACTUALLY HAPPENED ONE CASE, FULL DETAIL THE TEXT, EVERY LINE OF IT BE ASKED CHEAPLY — TEXT HAS NOTHING TO COUNT EACH ROW'S STORAGE DECISION IS WHAT RULES OUT THE OTHER TWO ROWS' QUESTIONS. THAT IS THE WHOLE REASON THERE ARE THREE OF THEM.
FIG 2 · WHAT EACH ONE STORES, AND WHAT THAT DECISION COSTS IT

Counting and discarding is what makes a metric cheap and anonymous. Keeping the whole request is what makes a trace detailed and partial. Keeping every word is what makes a log complete and slow. You don't get to pick the good half of any of those. And there's no fourth option hiding somewhere — if anything could store full per-request detail on all your traffic and answer questions about it in fifteen seconds for the price of a counter, we'd all have bought it by now and the other three would be gone.

THE SAME THREE DECISIONS, PLOTTED AGAINST EACH OTHER METRICS COUNTED, NOT KEPT LOGS EVERY LINE, IN FULL TRACES THE WHOLE REQUEST, 1 IN 100 OF THEM WHERE THE BILL LIVES NOTHING LIVES HERE LITTLE DETAIL, AND ONLY A SAMPLE OF THAT ALL OF THEM 1 IN 100 NOTHING THE WHOLE THING HOW MUCH WE KEEP ABOUT ONE REQUEST HOW MANY REQUESTS WE KEEP IT FOR
FIG 3 · THE FOURTH CORNER IS EMPTY, AND THAT'S NOT AN ACCIDENT

So we run all three. And the moment we do, we're running a pipeline: something has to decide how much of each to keep, and something has to get it off the box.

We can't keep all of it

Each of the three has a knob, and they're three different knobs, because the three grow in different ways.

Metrics grow with labels, not traffic. A million requests cost what a thousand do, but every distinct combination of label values is another number to store forever. Twelve endpoints times five status codes times three instances is 180 counters — nothing at all. Put a user ID in a label and it's 180 per user.

Logs grow with traffic, and the knob is the level. Most of what a service writes is debug, and usually not by a little — leave debug on for a day and the info-level lines are a rounding error next to it. Setting the level to info throws all of that away before it's ever written down, and dropping back to debug is how we get the detail back when we need it. It's a coarse knob. Each step moves volume by roughly an order of magnitude, and it's almost always left on the wrong setting.

Traces grow with traffic too, and the knob is which ones you keep. Keeping one in a hundred sounds like it should make them useless: the signup that failed is one request among a hundred, so the odds of it being the one you kept are exactly as bad as they sound. That'd be true if the choice were random. There's a version where it is.

Head sampling decides at the very start, before anything's happened. Each request tosses a weighted coin on arrival and the losers are never recorded. Your own service does this to itself, in process. The one thing it has to do is send the answer along with the ID, so everyone downstream obeys the same toss instead of throwing their own. Otherwise you'd keep the first half of a request and bin the second. It's cheap. It also loses failures exactly as carelessly as it loses everything else, because the coin was tossed before anyone knew the request was going to fail.

Tail sampling waits instead. Every span goes into a buffer. Once enough time's passed, something looks at how the request actually went and only then decides: keep it if any part of it errored, keep it if it ran long, keep a thin random slice of the ordinary ones so there's something healthy to compare against. That something can't be your application. Each of your services only ever sees its own spans: the one that answered in 4 ms has no idea the database spent four seconds on it afterwards. The decision has to happen where every span of the request arrives, which means a separate process outside your services that they all send to. Usually just called a collector.

Two things make that expensive, and they're why plenty of teams settle for head sampling. Nothing tells the collector a request has finished. So it waits on a timer, judges whatever turned up, and holds every span of every in-flight request in memory meanwhile. All the spans of one request also have to land on the same collector instance, or none of them ever sees a whole trace.

What you get for the trouble is that the one-in-a-hundred rate only applies to the ordinary requests. Failures and slow ones get kept outright, which is why the trace in FIG 1 is in front of you at all — 4,812 ms clears any latency rule anyone would set. You investigate with traces because the interesting ones were kept on purpose, not because you got lucky.

All of which quietly assumes slow is rare. When everything's slow at once, every trace matches the rule, and the sampler isn't confused about what to do — it wants all of them. What runs out is room. The buffer holds a fixed number of traces, 50,000 by default, and it's circular: once it's full, each new trace overwrites the oldest, which leaves before anybody judged it. There's a compounding bit too. Requests keep arriving at the same rate but each one now takes longer, so more of them are in flight at any given moment, and the buffer fills fastest during exactly the event we sized it for. Eviction is oldest-first, not policy-aware. It'll drop an errored trace to make room for an ordinary slow one, at the moment we'd most want to keep it.

We survive that, and the reason's worth being precise about. Metrics don't grow with traffic, so a slowdown costs them nothing at all. They go on counting at full fidelity while the trace pipeline's buckling — how bad it is, when it started, which endpoint, none of it sampled. They still can't name a single request. But when everything's slow we don't need a particular one, and any trace that did survive shows where the time went. Three knobs because the three grow differently, and things that grow differently don't fall over at the same moment.

OpenTelemetry: getting it off the box

OpenTelemetry is the standard for producing metrics, traces and logs, and for shipping them somewhere you can look at them. Two separate reasons to care.

The first: that travelling ID only works if everybody agrees on its shape. A log is written by one service on its own. A metric is counted by one service on its own. But a trace crosses services, so every one of them has to read and write that ID the same way, in a header they've all agreed on. It's called traceparent, and it carries the sampling decision along with it.

When two services disagree you don't get an error. You get two half-traces that each look complete, which is worse than getting nothing. There used to be four formats in common use — Zipkin's, Jaeger's, AWS X-Ray's and Datadog's — and a request crossing between them lost its identity at the boundary. OpenTelemetry's the one everyone settled on. Adopting tracing is more or less adopting it.

The second: it keeps your code out of the vendor decision.

YOUR CODE startSpan() SDK STARTED AT BOOT COLLECTOR ONE CONFIG FILE OTel API OTLP X-RAYDATADOGGRAFANA PICK ANY, OR SEVERAL WITH NO SDK STARTED, THE API RESOLVES TO A NO-OP — ONE FUNCTION CALL, NOTHING RECORDED. CHANGING VENDOR MEANS EDITING THE COLLECTOR CONFIG. THE CODE NEVER MOVES.
FIG 4 · HOW TELEMETRY LEAVES YOUR CODE, AND THE TWO PROPERTIES THAT MATTER

Four pieces, worth telling apart. The specification says what a span or a metric or a log record contains. The SDKs are the libraries you import in Node or Python or Go. OTLP is the wire protocol they send over. And the Collector is that separate process from the last section, under its proper name — it takes OTLP in, makes the calls that need a view of the whole trace, and forwards what survives wherever you configured. One backend, or several at once.

Your code only ever touches the API. Which backend the data lands in is decided in the Collector's config file, so switching vendor is a config change, not a rewrite of every instrumented method. Tail sampling lives there too, and so does dropping a label you decided you couldn't afford — which means all three knobs sit in one process, and none of them are in your application.

One more thing about that API, and it's the part worth holding on to. It works whether or not anything behind it has been set up at all. If nothing starts an SDK at boot, every instrumented call quietly becomes a no-op — costs a function call, records nothing, doesn't crash. That's deliberate, so instrumentation can sit in code that isn't currently exporting anywhere. It also means a service can be covered in tracing decorators and be sending absolutely nothing, and from the inside the two look identical. The only way to tell is from the other end, by whether anything ever arrives.

So the architecture's smaller than it looks. Three shapes of data, because three storage decisions rule each other out. Three knobs, because we can't afford all of it — labels, levels, and which traces survive. One standard for getting it off the box, so the vendor's a config file instead of a rewrite. Everything after that is picking numbers.

And all of it has to be decided in advance. At three in the morning, in front of a system you can't attach a debugger to, you don't get to add the log line you wish you'd written.