Observability
Logs, metrics and traces: how to answer “what is my system doing, for whom, since when?” at 2 a.m. — structured logging with slog and pino, histograms and percentiles, OpenTelemetry tracing in Go and JavaScript, and SLOs with error budgets that tell you when to page a human.
The 30-second version
2 a.m.: "checkout is slow for some users"
You run a small online shop. Your phone buzzes at 2 a.m.: customers on social media say checkout spins for ages. You open your laptop. The only clues your code leaves behind look like this:
here
here 2
order saved
here
Error: timeoutEvery useful question is unanswerable:
- Which users? All of them, or only people paying by card? Only in one country?
- Which step? Loading the cart, reserving stock, charging the card, sending the email?
- Since when? Did it start with tonight's 23:40 deploy, or has it crept up all week?
- How bad? One slow request in a thousand, or half of them?
console.log("here") was fine while you were coding on your laptop. Once real users and several servers are involved, you need evidence that was designed to be searched later.
In software terms: Metrics are counts and timings added up over time, logs are individual event records, and traces follow one request through every step and service it touches. Together they are your system's Telemetry.
Which one would you reach for?
Each question below is best answered by one of the three. Pick one and see why:
What this page covers
- Structured logs you can search (§03), and a request ID that ties one request's lines together (§04).
- Metrics: counters, gauges and histograms (§05) — and why the average latency lies to you (§06).
- Traces: the waterfall of one request across services (§07), built with OpenTelemetry in Go and JavaScript (§08).
- SLOs and error budgets (§09) and alerts that wake you only when users are hurting (§10).
- What staff engineers worry about: cost, privacy, sampling, profiling in production (§11).
Three signals from one request
Follow one checkout request, POST /checkout for order 1042, and watch what each signal records:
What each one is good for
| Logs | Metrics | Traces | |
|---|---|---|---|
| What it is | One record per event: time + message + fields | Numbers added up over time: counts, sums, buckets | One tree of timed steps per request |
| Answers | Why did this specific thing fail? | Is something wrong? How much, since when? | Where did the time go, across services? |
| Cost grows with | Every event you log | Number of distinct label combinations (not traffic!) | Number of requests you keep |
| Typical retention | Days to weeks | Months to years | Days (and often only a sample) |
| Example | {"msg":"payment failed","order_id":1042,"err":"card_declined"} | http_requests_total{code="502"} 17 | checkout 412 ms → payments 380 ms → provider 371 ms |
How to read the metric example: http_requests_total is the metric's name, the part in {…} is its labels (here: only requests whose status code was 502), and 17 is its current value — 17 such requests so far.
The usual flow during an incident: a metric alert says the error rate is up → you open a trace of a failing request to see which step broke → you read that step's logs for the exact error.
Metrics are cheap — until they aren't
A metric doesn't store every request. It stores a running total: "checkout requests so far: 81,204". A million more requests just change the number. That's why metrics are cheap to keep for a year.
But metrics can be split by labels: route="/checkout", code="502". Every distinct combination of label values is stored as its own time series — its own separate counter. The number of distinct values a label can take is its Cardinality, and the series count is all the cardinalities multiplied together.
A worked example: 12 routes × 4 methods × 8 status codes = 384 series. Fine. Add a user_id label with 200,000 users and it's 76.8 million series. Your metrics bill (or your metrics server's memory) explodes.
Try it yourself:
Structured logs: lines a machine can search
"payment failed for order 1042" can only be read; {"msg":"payment failed","order_id":1042} can be filtered, counted and grouped by a machine.Before and after
Here's the same event logged two ways:
console.log("payment failed for order " + orderId +
" user " + userId + ": " + err.message);
// payment failed for order 1042 user u_77: card_declinedlogger.error({ order_id: orderId, user_id: userId,
err: err.message }, "payment failed");
// {"level":50,"msg":"payment failed","order_id":1042,"user_id":"u_77","err":"card_declined"}The left one looks friendlier, but try answering "how many payment failures per user tonight?" You'd write a fragile regular expression, and it breaks the day someone rewords the message. With the right one, a log tool runs the equivalent of WHERE msg = 'payment failed' GROUP BY user_id. That is Structured logging: the message stays constant, the details go in fields.
Levels: how loud is this line?
Every log line gets a Log level. You set a minimum level per environment, and lines below it are dropped before they're written.
| Level | Use it for | Example |
|---|---|---|
DEBUG | Detail you only want while investigating; usually off in production | "cart loaded, 3 items" |
INFO | Normal, noteworthy events | "checkout started", "order placed" |
WARN | Something odd that the code handled | "payment slow, retrying" |
ERROR | Something failed and a user or job was affected | "payment failed" |
Go: log/slog
Go's standard library has had a structured logger, log/slog, since Go 1.21:
package main
import (
"log/slog"
"os"
"time"
)
func main() {
// JSON lines to stdout; drop anything below Info.
logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{
Level: slog.LevelInfo,
}))
logger.Debug("cart loaded", "items", 3) // ← below Info: never written
logger.Info("checkout started", "order_id", 1042, "user_id", "u_77", "items", 3)
reqLog := logger.With("request_id", "req-7f3a") // ← every line from reqLog carries this field
reqLog.Warn("payment slow", "provider", "stripe", "took_ms", 2300)
reqLog.Error("payment failed",
slog.Int("order_id", 1042), // ← typed form: same result, no mistakes
slog.String("err", "card_declined"),
slog.Duration("took", 2300*time.Millisecond),
)
}Real output (Go 1.24):
{"time":"2026-10-30T15:33:22.055Z","level":"INFO","msg":"checkout started","order_id":1042,"user_id":"u_77","items":3}
{"time":"2026-10-30T15:33:22.055Z","level":"WARN","msg":"payment slow","request_id":"req-7f3a","provider":"stripe","took_ms":2300}
{"time":"2026-10-30T15:33:22.055Z","level":"ERROR","msg":"payment failed","request_id":"req-7f3a","order_id":1042,"err":"card_declined","took":2300000000}(Timestamps shortened here; the real ones have nanoseconds.)
JavaScript: pino
Node has no structured logger built in; pino is the most widely used fast one (npm i pino, version 10 here). The fields object comes first, the message second:
import pino from "pino";
const logger = pino({ level: "info" }); // drop anything below info
logger.debug({ items: 3 }, "cart loaded"); // ← dropped
logger.info({ order_id: 1042, user_id: "u_77" }, "checkout started");
logger.error({ order_id: 1042, err: new Error("card_declined") }, "payment failed");Real output (Node 22, pino 10.4; stack trace shortened):
{"level":30,"time":1793374451861,"pid":27813,"hostname":"vm","order_id":1042,"user_id":"u_77","msg":"checkout started"}
{"level":50,"time":1793374451862,"pid":27813,"hostname":"vm","order_id":1042,"err":{"type":"Error","message":"card_declined","stack":"Error: card_declined\n at file:///…/log.mjs:7:37 …"},"msg":"payment failed"}What's worth a log line?
- Events, not progress markers. "order placed", "payment failed" — not "here", "here 2", "entering function".
- The fields you'll filter by later: IDs (order, user, request), the step, the outcome, how long it took.
- One rich line beats ten thin ones. Many teams write one Wide event at the end of each request — route, user, status, duration, cart size, which payment provider — and need few other lines. You'll see the same idea again in traces (§07).
- Never passwords, tokens, full card numbers or other personal data. §04 shows how to make that hard to get wrong.
One request, many lines: request IDs and context
The problem: everyone talks at once
Three customers check out within the same 50 milliseconds. Each request writes four log lines, and they land in the log file interleaved. Which "payment failed" belongs to which "checkout started"? Click a request ID to filter:
The ID is a Request ID: a short random string created when the request arrives (or taken from an X-Request-Id HTTP header if the caller already made one). The hard part isn't creating it — it's getting it onto every line without passing it as a parameter through every function.
Go: carry it in the context
Go already passes a context.Context (ctx) as the first argument through request-handling code. It can carry values too. A Middleware puts the ID in, and a small wrapper around the slog handler takes it out for every line:
type ctxKey struct{} // a private key type: no other package can collide with it
// Callers may send their own ID; accept only short, plain ones (it ends up in every log line).
var validID = regexp.MustCompile(`^[A-Za-z0-9-]{1,64}$`)
// 1. Middleware: give every request an ID and put it in the request's context.
func withRequestID(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
id := r.Header.Get("X-Request-Id") // reuse the caller's ID if it sent one…
if !validID.MatchString(id) { // …but only if it looks like an ID
id = rand.Text()[:8] // crypto/rand, Go 1.24+: random letters and digits
}
w.Header().Set("X-Request-Id", id) // send it back, so a user can quote it to support
ctx := context.WithValue(r.Context(), ctxKey{}, id)
next.ServeHTTP(w, r.WithContext(ctx))
})
}
// 2. A slog handler that copies the ID from the context onto every line.
type ctxHandler struct{ slog.Handler }
func (h ctxHandler) Handle(ctx context.Context, rec slog.Record) error {
if id, ok := ctx.Value(ctxKey{}).(string); ok {
rec.AddAttrs(slog.String("request_id", id))
}
return h.Handler.Handle(ctx, rec)
}
func (h ctxHandler) WithAttrs(as []slog.Attr) slog.Handler { return ctxHandler{h.Handler.WithAttrs(as)} }
func (h ctxHandler) WithGroup(name string) slog.Handler { return ctxHandler{h.Handler.WithGroup(name)} }
// 3. Wire it up once at startup.
func main() {
slog.SetDefault(slog.New(ctxHandler{slog.NewJSONHandler(os.Stdout, nil)}))
mux := http.NewServeMux()
mux.HandleFunc("POST /checkout", func(w http.ResponseWriter, r *http.Request) {
ctx := r.Context()
slog.InfoContext(ctx, "checkout started", "user_id", "u_77") // ← pass ctx, not the ID
chargeCard(ctx, 1042)
})
http.ListenAndServe(":8080", withRequestID(mux))
}
func chargeCard(ctx context.Context, orderID int) {
slog.InfoContext(ctx, "charging card", "order_id", orderID)
}Real output for two requests (sent with X-Request-Id headers) and one without:
{"time":"…","level":"INFO","msg":"checkout started","user_id":"u_77","request_id":"req-7f3a"}
{"time":"…","level":"INFO","msg":"charging card","order_id":1042,"request_id":"req-7f3a"}
{"time":"…","level":"INFO","msg":"checkout started","user_id":"u_77","request_id":"req-b21c"}
{"time":"…","level":"INFO","msg":"charging card","order_id":1042,"request_id":"req-b21c"}
{"time":"…","level":"INFO","msg":"checkout started","user_id":"u_77","request_id":"XE6ATLQN"}
{"time":"…","level":"INFO","msg":"charging card","order_id":1042,"request_id":"XE6ATLQN"}JavaScript: AsyncLocalStorage
Node has no ctx parameter, but it has AsyncLocalStorage: you call als.run(value, fn) and anything fn does — including code that runs later, after await — can call als.getStore() to get that value back. We store a child logger that already has the ID baked in:
import pino from "pino";
import { AsyncLocalStorage } from "node:async_hooks";
import { randomUUID } from "node:crypto";
import http from "node:http";
const base = pino({ redact: ["card.number"] }); // ← see "Keeping secrets out" below
const als = new AsyncLocalStorage();
const log = () => als.getStore() ?? base; // this request's logger, or the base one
http.createServer((req, res) => {
const incoming = req.headers["x-request-id"] ?? "";
const requestId = /^[A-Za-z0-9-]{1,64}$/.test(incoming) ? incoming : randomUUID(); // never trust it blindly
res.setHeader("x-request-id", requestId);
als.run(base.child({ request_id: requestId }), async () => { // ← everything inside sees it
log().info({ path: req.url }, "checkout started");
await chargeCard(1042);
res.end("ok");
});
}).listen(8080);
async function chargeCard(orderId) {
await new Promise((r) => setTimeout(r, 10)); // pretend to call the payment API
log().info({ order_id: orderId, card: { number: "4242424242424242" } }, "charging card");
}Real output when two requests arrive together — note the IDs survive the await:
{"level":30,…,"request_id":"req-7f3a","path":"/checkout","msg":"checkout started"}
{"level":30,…,"request_id":"req-b21c","path":"/checkout","msg":"checkout started"}
{"level":30,…,"request_id":"req-7f3a","order_id":1042,"card":{"number":"[Redacted]"},"msg":"charging card"}
{"level":30,…,"request_id":"req-b21c","order_id":1042,"card":{"number":"[Redacted]"},"msg":"charging card"}Pass it on
Inside one service, context and AsyncLocalStorage carry the ID. Between services, send it as a header on every outgoing call (X-Request-Id: req-7f3a) so the payments service logs the same ID. Doing this by hand is tedious and easy to forget — which is exactly what trace context does for you automatically, with a standard header (§07). Once you have tracing, log the trace ID too and you can jump from any log line to its trace.
Keeping secrets out
Logs get copied everywhere: log tools, backups, laptops during an incident. Treat them as less private than your database. Card numbers, passwords, tokens and most Personal data must never land there — and "everyone remembers not to log it" doesn't scale. Make the safe thing automatic:
type Card struct {
Number string
Expiry string
}
// LogValue decides what a Card looks like in ANY log line, everywhere.
func (c Card) LogValue() slog.Value {
return slog.GroupValue(slog.String("last4", c.Number[len(c.Number)-4:]))
}
logger.Info("charging card", "card", card) // ← safe even if someone logs the whole struct
// {"time":"…","level":"INFO","msg":"charging card","card":{"last4":"4242"}}Metrics: counters, gauges and histograms
| Type | Use it for | Examples |
|---|---|---|
| Counter | Things that happen: count them | requests served, errors, bytes sent, orders placed |
| Gauge | A current level | requests in flight, queue length, memory in use, open DB connections |
| Histogram | How big or slow things were | request duration, response size, items per order |
How metrics get collected
The most common setup is Prometheus. Your program keeps its counters in memory and shows their current values on a plain-text page, usually GET /metrics. Every 15 seconds or so Prometheus scrapes that page and stores the numbers with a timestamp. Your program never remembers history; Prometheus does.
Here's a checkout handler instrumented with all three types:
import (
"github.com/prometheus/client_golang/prometheus"
"github.com/prometheus/client_golang/prometheus/promauto"
"github.com/prometheus/client_golang/prometheus/promhttp"
)
var (
requests = promauto.NewCounterVec(prometheus.CounterOpts{
Name: "http_requests_total",
Help: "HTTP requests handled, by route and status code.",
}, []string{"route", "code"}) // ← the label names
inFlight = promauto.NewGauge(prometheus.GaugeOpts{
Name: "http_requests_in_flight",
Help: "Requests being handled right now.",
})
duration = promauto.NewHistogramVec(prometheus.HistogramOpts{
Name: "http_request_duration_seconds",
Help: "How long requests took.",
Buckets: []float64{0.05, 0.1, 0.25, 0.5, 1, 2.5}, // ← bucket upper bounds, in seconds
}, []string{"route"})
)
// instrument wraps a handler and records the three metrics for it.
func instrument(route string, next http.HandlerFunc) http.HandlerFunc {
return func(w http.ResponseWriter, r *http.Request) {
inFlight.Inc()
start := time.Now()
rec := &statusRecorder{ResponseWriter: w, code: 200}
defer func() { // ← runs however the handler ends, even if it panics
p := recover()
if p != nil {
rec.code = http.StatusInternalServerError // a panic is a failed request
}
inFlight.Dec()
duration.WithLabelValues(route).Observe(time.Since(start).Seconds())
requests.WithLabelValues(route, strconv.Itoa(rec.code)).Inc()
if p != nil {
panic(p) // re-panic: net/http still logs it and closes the connection
}
}()
next(rec, r)
}
}
// statusRecorder remembers the status code the handler wrote.
type statusRecorder struct {
http.ResponseWriter
code int
}
func (s *statusRecorder) WriteHeader(code int) { s.code = code; s.ResponseWriter.WriteHeader(code) }
// in main:
// mux.HandleFunc("POST /checkout", instrument("/checkout", checkout))
// mux.Handle("GET /metrics", promhttp.Handler())We sent four checkout requests over real HTTP: 40, 80, 120 and 160 ms; the third returned 502, and the fourth hit a bug (a write to a nil map in Go, a throw in JS). The client saw 200, 200, 502 and then a dropped connection (Go) or a 500 (JS). Real output of /metrics from the Go version (client_golang 1.23.2), after net/http had printed http: panic serving …: assignment to entry in nil map and a stack trace to stderr:
# HELP http_request_duration_seconds How long requests took.
# TYPE http_request_duration_seconds histogram
http_request_duration_seconds_bucket{route="/checkout",le="0.05"} 1
http_request_duration_seconds_bucket{route="/checkout",le="0.1"} 2
http_request_duration_seconds_bucket{route="/checkout",le="0.25"} 4
http_request_duration_seconds_bucket{route="/checkout",le="0.5"} 4
http_request_duration_seconds_bucket{route="/checkout",le="1"} 4
http_request_duration_seconds_bucket{route="/checkout",le="2.5"} 4
http_request_duration_seconds_bucket{route="/checkout",le="+Inf"} 4
http_request_duration_seconds_sum{route="/checkout"} 0.414701359
http_request_duration_seconds_count{route="/checkout"} 4
# HELP http_requests_in_flight Requests being handled right now.
# TYPE http_requests_in_flight gauge
http_requests_in_flight 0
# HELP http_requests_total HTTP requests handled, by route and status code.
# TYPE http_requests_total counter
http_requests_total{code="200",route="/checkout"} 2
http_requests_total{code="500",route="/checkout"} 1
http_requests_total{code="502",route="/checkout"} 1The Node version (prom-client 15.1) printed the same counts, with the labels in the order they were declared: http_requests_total{route="/checkout",code="500"} 1. Without the panic/throw handling, the fourth request would be missing (Go) or counted as code="200" (JS).
How to read the histogram: le means "less than or equal to". The bucket le="0.1" says 2 requests took ≤ 100 ms; le="0.25" says all 4 took ≤ 250 ms. Buckets are cumulative — each one includes everything in the smaller ones. _sum and _count let you compute the average (0.415 / 4 ≈ 104 ms). §06 shows how to get percentiles out of these buckets, and why you'd want them.
Counters are read as rates
A raw counter value (81,204 requests since the process started) is almost never what you want. You want "how fast is it growing right now?" — requests per second. Prometheus's query language, PromQL, does that with rate():
rate() turns it into requests per second — 10, then 20 — and treats the drop as a restart, not as negative traffic.Worked example: the counter read 1,000 at 12:00:00 and 1,600 at 12:01:00. 600 requests in 60 seconds = 10 requests per second. rate() also notices when a counter drops back to 0 (the process restarted) and treats that as a reset, not as "−1,600 requests". That's why counters must only ever go up: if you decrement one, rate() will misread the drop as a restart.
A few queries you'll write constantly, read inside-out:
rate(http_requests_total[5m])
→ requests per second, averaged over the last 5 minutes, one line per series
sum by (route) (rate(http_requests_total{code=~"5.."}[5m]))
/ sum by (route) (rate(http_requests_total[5m]))
→ fraction of requests per route that failed with a 5xx status
histogram_quantile(0.99, sum by (le) (rate(http_request_duration_seconds_bucket[5m])))
→ p99 latency over the last 5 minutes (see §06){code=~"5.."} keeps only series whose code label matches the pattern "5 followed by any two characters". sum by (route) adds up all series that share a route, throwing away the other labels.
What to measure: RED and USE
You can't graph everything, so two short checklists cover most needs:
For every service (things that answer requests)
Rate — requests per second. Errors — failed requests per second (or the fraction). Duration — a latency histogram. If these three look healthy, users are usually happy. This is the RED method.
For every resource (things that get used up)
Utilization — how busy (CPU 70%, 18 of 20 DB connections in use). Saturation — how much work is waiting (requests queued for a connection). Errors — e.g. connection failures. This is the USE method.
Plus a few business numbers
Orders placed per minute, payments declined, sign-ups. These often catch problems no technical metric sees — like a broken "Buy" button that throws no errors at all.
Saturation is the one beginners skip, and it's often the earliest warning: a database pool at 20 of 20 connections with 40 requests waiting for one is in trouble, even if CPU looks calm. (Why queues blow up latency near 100% busy is in Worker pools: utilization.)
Percentiles: why the average lies
A worked example
100 checkout requests: 98 take 100 ms, and 2 get stuck behind a slow payment provider for 5 seconds.
- Mean (average): (98 × 100 + 2 × 5000) ÷ 100 = 198 ms. Nobody waited 198 ms! 98 people waited 100 ms and 2 people waited 5 s.
- p50 (the median): sort all 100 times; the middle one is 100 ms. Half the requests were faster, half slower.
- p99: the time that 99% of requests come in at or under — here the 99th of the 100 sorted values: 5,000 ms. (98 requests are faster, the 99th is exactly 5 s.)
A Percentile answers "what time do X% of requests stay under?" The mean blends the fast majority and the slow few into a number that hides both. The slow few are your Tail latency, and they're often the users who give up and leave.
Try it
Each button adds requests to the histogram. Watch the three markers. Then try "slow 1%": the mean barely moves while p99 jumps.
Things to notice:
- Adding a few slow requests moves p99 a lot and p50 not at all. The median only cares about the middle.
- The mean gets dragged by outliers. One 30-second timeout can shift the mean more than a thousand normal requests.
- "Two humps" (cache hit / cache miss) gives a mean that sits in the empty valley between them, where no actual request is.
Getting percentiles out of a histogram
A metric histogram (§05) doesn't store every request — only how many fell into each bucket. So percentiles are estimated: Prometheus's histogram_quantile(0.99, …) finds the bucket where the 99th percentile falls and assumes requests are spread evenly inside it.
Worked example with the buckets from §05: 1,000 requests, and the 99th percentile is request number 990. Suppose 985 requests are in buckets up to le="0.5" and 1,000 are in buckets up to le="1". Request 990 is the 5th of the 15 in the 0.5–1 s bucket, so the estimate is 0.5 + (5 ÷ 15) × 0.5 ≈ 0.67 s. The true value could be anything between 0.5 s and 1 s.
The latency histogram earlier in this section shows both: the exact p99 and the estimate from the buckets. Add some 2-second requests and see how far apart they get. That's why bucket boundaries matter:
- Put boundaries near the numbers you care about. If your target is "under 300 ms", have a bucket edge at 0.3.
- More buckets = better estimates but more cost: every bucket is its own Time series, multiplied by every label combination (§02).
- Newer formats — Prometheus native histograms and OpenTelemetry exponential histograms — pick many fine buckets automatically and store them compactly. Check whether your backend supports them before relying on it.
Never average percentiles
Say you run two checkout servers. You have the p99 of each. What's the p99 of the whole service? Not the average of the two. Percentiles don't add up: the 1% slowest requests overall might come entirely from one server. Drag the slider to change how traffic is split:
The correct way is to merge the raw data first, then take the percentile: add up the bucket counts from all servers (that's what sum by (le) did in §05's query), then call histogram_quantile once. That's why histograms are the right metric type for latency: buckets can be added together across servers and over time; finished percentiles can't.
Traces: the route replay of one request
Why logs and metrics aren't enough here
Your checkout doesn't run in one place. The request goes from the gateway to the checkout service, which calls inventory and payments, and payments calls an outside card provider. Metrics say "checkout p99 is 3 s". Each service's logs say what it did. Neither tells you that this particular slow request spent 2.8 of its 3 seconds waiting for the card provider's second retry.
That's what Distributed tracing records. Each step is a span:
- a name (
POST /checkout,SELECT orders,charge card), - a start time and duration,
- its Span ID and the span ID of its parent (the step that called it),
- the Trace ID, shared by every span of the same request,
- attributes (key–value fields like
order.id=1042,http.response.status_code=502; standard names like the second come from OpenTelemetry's Semantic conventions) and events (timestamped notes, such as an exception).
The first span — the one with no parent — is the Root span. All the others hang below it, which turns a pile of spans from five services back into one tree.
Reading a waterfall
Each bar is a span; its position is when it started and its length is how long it took. Children are indented below their parent. Switch scenarios and click any bar for its details:
How to read one, in order:
- Look at the longest bars on the deepest level. The time a parent spends is mostly time spent waiting for its children. The interesting bar is usually a leaf.
- Look for gaps. Time inside a parent that no child covers is the parent's own work (or something nobody instrumented).
- Look for staircases. Many short identical spans one after another (the N+1 scenario) means a loop doing one call per item. See N+1 queries.
- Look for things that could overlap but don't. Inventory and payments don't depend on each other; running them one after the other puts both on the Critical path.
How the trace ID crosses service boundaries
Inside one service, the current span lives in the same place as the request ID did in §04: Go's context.Context, Node's AsyncLocalStorage. Between services it travels in an HTTP header. The standard one, from the W3C Trace Context spec, is traceparent header:
The receiving service reads this header, creates its own span with the same trace ID and with 00f067aa0ba902b7 as the parent, and passes its own span ID on to whatever it calls next. This hand-off is Context propagation. If any service in the chain drops the header (an old proxy, a message queue, a hand-written HTTP client), the trace breaks in two, and you get two half-traces that nothing links together.
OpenTelemetry in Go and JavaScript
Three pieces
- The API (
go.opentelemetry.io/otel,@opentelemetry/api) is what your code calls: get a tracer, start a span, set attributes, end it. If nothing else is set up, every call does nothing, cheaply. - The SDK (
go.opentelemetry.io/otel/sdk,@opentelemetry/sdk-trace-node) is the engine plugged in at startup: it decides which spans to keep, batches them and hands them to… - an Exporter, which sends them somewhere: stdout for learning, OTLP to a vendor, or to an OpenTelemetry Collector (a relay program, §11) in production.
This split means a library can call the API and leave the choices to the application that uses it (§11).
Go: a checkout span that calls payments
import (
"go.opentelemetry.io/otel"
"go.opentelemetry.io/otel/attribute"
"go.opentelemetry.io/otel/codes"
"go.opentelemetry.io/otel/exporters/stdout/stdouttrace"
"go.opentelemetry.io/otel/propagation"
sdktrace "go.opentelemetry.io/otel/sdk/trace"
)
var tracer = otel.Tracer("shop/checkout") // ← name = which code made these spans
func main() {
exp, err := stdouttrace.New(stdouttrace.WithPrettyPrint())
if err != nil {
log.Fatal(err)
}
tp := sdktrace.NewTracerProvider(sdktrace.WithBatcher(exp)) // the SDK
defer tp.Shutdown(context.Background()) // ← flush spans before exiting
otel.SetTracerProvider(tp)
otel.SetTextMapPropagator(propagation.TraceContext{}) // use the W3C traceparent header
// … start the server …
}
func checkout(ctx context.Context, paymentsURL string, orderID int) error {
ctx, span := tracer.Start(ctx, "POST /checkout") // ← new span, child of whatever is in ctx
defer span.End()
span.SetAttributes(attribute.Int("order.id", orderID))
if err := reserveStock(ctx); err != nil { // ← pass ctx on, so children link up
span.RecordError(err)
span.SetStatus(codes.Error, "reserve failed")
return err
}
req, err := http.NewRequestWithContext(ctx, "POST", paymentsURL, nil)
if err != nil {
return err
}
otel.GetTextMapPropagator().Inject(ctx, propagation.HeaderCarrier(req.Header)) // ← adds traceparent
resp, err := http.DefaultClient.Do(req)
if err != nil {
span.RecordError(err)
span.SetStatus(codes.Error, "payments unreachable")
return err
}
defer resp.Body.Close()
if resp.StatusCode >= 500 { // ← an answer isn't a success: 502 is a failure too
err := fmt.Errorf("payments: %s", resp.Status)
span.RecordError(err)
span.SetStatus(codes.Error, err.Error())
return err
}
return nil
}
func reserveStock(ctx context.Context) error {
_, span := tracer.Start(ctx, "reserve stock")
defer span.End()
// … UPDATE stock …
return nil
}
// In the payments service's handler:
func charge(w http.ResponseWriter, r *http.Request) {
ctx := otel.GetTextMapPropagator().Extract(r.Context(), propagation.HeaderCarrier(r.Header))
_, span := tracer.Start(ctx, "charge card") // ← same trace, parent = checkout's span
defer span.End()
// …
}Real output (Go 1.24, OTel Go 1.41; trimmed — the real exporter prints every field). The payments server printed the header it received, then the exporter printed three spans:
payments got traceparent: 00-412cfbfb1cdef54fbf8367355f2eb099-57fb4a36b8e09dee-01
{ "Name": "reserve stock", "SpanContext": { "TraceID": "412cfbfb…eb099", "SpanID": "d233565327f793a1" },
"Parent": { "SpanID": "57fb4a36b8e09dee" }, "StartTime": "…26.1955Z", "EndTime": "…26.2057Z" }
{ "Name": "charge card", "SpanContext": { "TraceID": "412cfbfb…eb099", "SpanID": "4a81bbf8308c4293" },
"Parent": { "SpanID": "57fb4a36b8e09dee" }, "StartTime": "…26.2066Z", "EndTime": "…26.2368Z" }
{ "Name": "POST /checkout", "SpanContext": { "TraceID": "412cfbfb…eb099", "SpanID": "57fb4a36b8e09dee" },
"Parent": { "SpanID": "0000000000000000" },
"Attributes": [ { "Key": "order.id", "Value": { "Type": "INT64", "Value": 1042 } } ],
"Resource": [ { "Key": "service.name", "Value": { "Value": "unknown_service:oteldemo" } }, … ] }Read it as a tree: all three share one trace ID. POST /checkout has an all-zero parent, so it's the root; the other two point at its span ID 57fb4a36…, including charge card, which ran in "another service" and only knew its parent from the header. Spans are exported as they end, so children appear before their parent.
JavaScript: the same span
import { trace, context, propagation, SpanStatusCode } from "@opentelemetry/api";
import { NodeTracerProvider } from "@opentelemetry/sdk-trace-node";
import { SimpleSpanProcessor, ConsoleSpanExporter } from "@opentelemetry/sdk-trace-base";
import { resourceFromAttributes } from "@opentelemetry/resources";
import { ATTR_SERVICE_NAME } from "@opentelemetry/semantic-conventions";
const provider = new NodeTracerProvider({
resource: resourceFromAttributes({ [ATTR_SERVICE_NAME]: "checkout" }),
spanProcessors: [new SimpleSpanProcessor(new ConsoleSpanExporter())],
});
provider.register(); // ← sets the global provider, the async context manager and the W3C propagator
const tracer = trace.getTracer("shop/checkout");
async function checkout(orderId) {
return tracer.startActiveSpan("POST /checkout", async (span) => { // ← span is "current" inside
span.setAttribute("order.id", orderId);
try {
await reserveStock(); // its span becomes a child automatically
const headers = {};
propagation.inject(context.active(), headers); // ← adds traceparent
const res = await fetch(PAYMENTS_URL, { method: "POST", headers });
if (!res.ok) throw new Error(`payments: ${res.status}`);
} catch (err) {
span.recordException(err);
span.setStatus({ code: SpanStatusCode.ERROR, message: err.message });
throw err;
} finally {
span.end();
}
});
}
async function reserveStock() {
return tracer.startActiveSpan("reserve stock", async (span) => {
try { /* … UPDATE stock … */ } finally { span.end(); }
});
}Real output when payments answered 502 (Node 22, OTel JS SDK 2.12, API 1.9; trimmed):
{
resource: { attributes: { 'service.name': 'checkout' } },
traceId: '44dfdfd9ebc32096867b70522911a289',
parentSpanContext: { traceId: '44dfdfd9ebc32096867b70522911a289', spanId: '4c0726a2e4751374', … },
name: 'reserve stock',
id: 'aa6e740a66ad69cb',
duration: 10868.196,
status: { code: 0 },
…
}
{
resource: { attributes: { 'service.name': 'checkout' } },
traceId: '44dfdfd9ebc32096867b70522911a289',
parentSpanContext: undefined,
name: 'POST /checkout',
id: '4c0726a2e4751374',
duration: 30847.126,
attributes: { 'order.id': 1042 },
status: { code: 2, message: 'payments: 502' },
events: [ { name: 'exception', attributes: { 'exception.type': 'Error', 'exception.message': 'payments: 502', 'exception.stacktrace': 'Error: payments: 502\n at …' } } ],
…
}duration is in microseconds; status.code 2 means ERROR (0 is "unset", i.e. fine). The payments server received traceparent: 00-44dfdfd9ebc32096867b70522911a289-4c0726a2e4751374-01 — the root span's ID as the parent for whatever payments creates.
Propagation, step by step
1// ── checkout service ──2ctx, span := tracer.Start(ctx, "POST /checkout")3defer span.End()45req, _ := http.NewRequestWithContext(ctx, "POST", payURL, nil)6prop.Inject(ctx, propagation.HeaderCarrier(req.Header))7http.DefaultClient.Do(req)89// ── payments service, in its handler ──10ctx := prop.Extract(r.Context(), propagation.HeaderCarrier(r.Header))11_, span := tracer.Start(ctx, "charge card")12defer span.End()
traceparent header, so this is the start of a new trace. tracer.Start picks a random trace ID (4bf9…) and a random span ID (00f0…) and returns a new ctx holding the span.You rarely write most of this yourself
Instrumentation libraries create the standard spans and handle the headers for you. In Go, wrapping a handler with otelhttp.NewHandler(mux, "checkout") and the client transport with otelhttp.NewTransport(http.DefaultTransport) (from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp) gives you a span per incoming and outgoing request, with the header injected and read. In Node, @opentelemetry/auto-instrumentations-node patches http, fetch (undici), Express, pg, Redis clients and more when loaded at startup. You then add manual spans only for the steps that matter to your business — "reserve stock", "charge card" — and attributes like order.id and cart.items.
Sampling: you can't keep every trace
A busy shop does thousands of checkouts a minute; each trace may have dozens of spans. Storing all of them is expensive, and 99% look identical. So you keep a sample. Sampling comes in two flavours:
| Head sampling | Tail sampling | |
|---|---|---|
| Decides | At the start, before anything happens | After the trace finished |
| Rule example | "Keep 10% at random" | "Keep all errors, all > 1 s, and 1% of the rest" |
| Cost | Cheap: unsampled spans are never even recorded | Every span must be sent somewhere and buffered until the trace completes |
| Risk | Drops 90% of your rare, interesting failures too | More moving parts (usually done in the Collector, §11) |
| In OTel | sdktrace.ParentBased(sdktrace.TraceIDRatioBased(0.1)) | The Collector's tail_sampling processor |
The head sampler is plugged in where you create the provider:
tp := sdktrace.NewTracerProvider(
sdktrace.WithSampler(sdktrace.ParentBased(sdktrace.TraceIDRatioBased(0.1))), // keep 10% of new traces
sdktrace.WithBatcher(exp),
)The last flag in traceparent (01 = sampled) carries the head decision downstream. ParentBased means "if my caller decided, follow that decision", so a trace is either kept in every service or in none — otherwise you'd get traces with holes in the middle.
SLIs, SLOs and error budgets
Three words
- SLI (indicator) — a number measuring what users experience, almost always as a ratio of good events to valid events:
good checkouts ÷ all checkouts. "Good" might mean "returned 2xx and took under 1 s". - SLO (objective) — the target for that ratio over a window: ≥ 99.9% over a rolling 30 days.
- SLA (agreement) — a contract with customers, with money back if you miss it. Usually looser than your internal SLO, so you notice trouble before it costs you.
Choose SLIs from the user's point of view. "CPU below 80%" is not an SLI: users don't feel CPU. "Search results returned in under 300 ms" is.
# SLI for "checkout succeeds within 1 s", over the last 30 days
sum(rate(http_request_duration_seconds_bucket{route="/checkout", le="1"}[30d])) ← requests ≤ 1 s
- sum(rate(http_requests_total{route="/checkout", code=~"5.."}[30d])) ← minus failures
───────────────────────────────────────────────────────────────────────────
sum(rate(http_requests_total{route="/checkout"}[30d])) ← all requests(Approximate: a request that was both slow and failed is subtracted twice. Real setups usually count "good" events directly, with a dedicated counter, or a Recording rule — §10 shows one.)
What the nines buy you
The Error budget is simply 100% minus the SLO. Over 30 days (43,200 minutes):
| SLO | Budget (fraction bad) | As downtime per 30 days | With 1 M checkouts/month |
|---|---|---|---|
| 99% | 1% | 7 h 12 min | 10,000 may fail |
| 99.5% | 0.5% | 3 h 36 min | 5,000 |
| 99.9% | 0.1% | 43 min | 1,000 |
| 99.99% | 0.01% | 4 min 19 s | 100 |
Each extra nine costs roughly ten times more effort: redundancy, slower careful deploys, people on call. And your SLO can't really be better than your dependencies': if your card provider offers 99.95%, a 99.99% checkout SLO is a wish.
Spend the budget
Here's the idea that makes SLOs useful: the budget is meant to be spent. Each risky deploy, migration or experiment uses some. While budget remains, ship features fast. When it's nearly gone, the team agrees in advance (an error budget policy) to slow down — freeze risky launches and put the effort into reliability until the budget recovers.
Watch a 30-day window. Add incidents and see how much budget each one burns:
Notice that a slow leak can hurt as much as a dramatic outage. A 20-minute full outage at 99.9% eats nearly half the month's budget — but so does 0.5% of requests failing for 3 days (0.5% × 4,320 minutes ≈ 22 "bad minutes"), which no one notices without an SLO.
Alerts that deserve to wake someone
Why "error rate > 1%" is a bad alert
The obvious rule — "page if more than 1% of requests fail for 5 minutes" — fails in both directions:
- Too noisy. At 3 a.m. you get 20 requests a minute — 100 in 5 minutes. Two failures from one confused bot = 2 out of 100 = 2% errors, double the threshold. Someone's phone rings for nothing.
- Too blind. 0.5% of checkouts failing for a week never crosses 1%, yet at a 99.9% SLO it burns the whole month's budget in 6 days.
People who get paged for nothing learn to ignore pages. That's Alert fatigue, and it's how real outages get missed.
Burn rate
The Burn rate compares how fast you're failing with how fast your SLO allows:
burn rate = current error rate ÷ error rate the SLO allows
With a 99.9% SLO the allowed error rate is 0.1%. If 1.44% of requests are failing right now, the burn rate is 1.44 ÷ 0.1 = 14.4. At that pace the 30-day budget is gone in 30 ÷ 14.4 ≈ 2 days, and one hour at that pace uses 14.4 ÷ 720 hours = 2% of the month's budget.
So instead of thresholds on raw error rates, you alert on budget consumed:
| Severity | Burn rate | Measured over | Means | Action |
|---|---|---|---|---|
| Page | 14.4 | 1 hour (and 5 min) | 2% of the budget gone in an hour | Wake someone |
| Page | 6 | 6 hours (and 30 min) | 5% gone in 6 hours | Wake someone |
| Ticket | 1 | 3 days (and 6 hours) | 10% gone in 3 days | Look at it during work hours |
These numbers come from Google's SRE Workbook, chapter "Alerting on SLOs"; they're a good starting point, not a law.
Why two windows per rule?
The long window (1 hour) makes the alert ignore short blips — 2 minutes of errors barely move a 1-hour average. But a long window is also slow to stop firing: after you've fixed the problem, the 1-hour average stays high for up to an hour. So each rule also requires the short window (5 minutes, 1/12 of the long one) to be burning fast. When the problem is fixed, the 5-minute rate drops within minutes and the alert clears.
Compare three alert rules on the same traffic. Pick a scenario and see who fires, and when:
In Prometheus: recording rules, then alerts
Alerts need the error ratio over several windows (5 m, 30 m, 1 h, 6 h, 3 d), evaluated every minute. Instead of repeating the long query in every alert, you define each ratio once as a Recording rule: Prometheus runs the query on a schedule and saves the result as a new series with a name you choose. The names follow the convention level:metric:operation — here "SLO-level, checkout errors, ratio over 1 h".
groups:
# 1. Recording rules: compute the error ratio once per window, save it as a new series.
- name: checkout-slo-recording
rules:
- record: slo:checkout_errors:ratio_rate5m
expr: |
sum(rate(http_requests_total{route="/checkout", code=~"5.."}[5m]))
/
sum(rate(http_requests_total{route="/checkout"}[5m]))
- record: slo:checkout_errors:ratio_rate1h
expr: |
sum(rate(http_requests_total{route="/checkout", code=~"5.."}[1h]))
/
sum(rate(http_requests_total{route="/checkout"}[1h]))
# … the same for [30m], [6h] and [3d]
# 2. Alerts read those series. 0.001 = the error ratio a 99.9% SLO allows.
- name: checkout-slo-alerts
rules:
- alert: CheckoutBudgetBurnFast
expr: |
slo:checkout_errors:ratio_rate1h > (14.4 * 0.001)
and
slo:checkout_errors:ratio_rate5m > (14.4 * 0.001)
labels:
severity: page
annotations:
summary: "Checkout is burning its 30-day error budget 14x too fast"
runbook_url: "https://wiki.example.com/runbooks/checkout-slo"
# CheckoutBudgetBurnSlow (6× over 6h and 30m, page) and
# CheckoutBudgetBurnTicket (1× over 3d and 6h, ticket) look the same.The http_requests_total here is exactly the counter from §05. labels.severity is what your alert router (Alertmanager, PagerDuty, …) uses to decide between waking someone and filing a ticket.
Symptoms, not causes
Page on symptoms — things users feel: errors, slowness, checkouts not completing. Don't page on causes — CPU at 90%, a pod restarted, a disk 80% full — because:
- A cause often doesn't hurt anyone. CPU at 90% while latency is fine is a well-used server.
- You can't list every cause in advance. A symptom alert catches the failure you didn't predict.
- Causes are still worth watching — as dashboards and tickets, and as the first places to look once a symptom alert fires.
The exception: causes that will certainly become a user-facing outage before a human could react to the symptom. "Disk full in 4 hours at the current rate" or "TLS certificate expires in 7 days" deserve a ticket or a page.
Keeping on-call humane
On-call is sustainable only if pages are rare and meaningful. A few rules teams use:
- Every page must be actionable. If the response is "ack and go back to sleep", delete or downgrade the alert.
- Every alert links a Runbook: what it means, the dashboard to open, the first three things to check.
- Count pages. More than one or two per on-call shift on average means the alerts, not the people, need fixing.
- Review after incidents, without blame: what did we see, what was missing, which alert should have fired earlier?
Staff-level: debugging in production and running the pipeline
From a graph to the exact request: exemplars
Your latency graph shows a spike in the 2.5–5 s bucket. Which requests were those? An Exemplar answers it: when a histogram records a value, it can also keep the trace ID of one request that landed in that bucket. Dashboards draw exemplars as dots on the graph; clicking one opens that trace. Metric → trace → (via the trace ID on each log line) logs, in three clicks.
Prometheus supports exemplars in the OpenMetrics format (client_golang has ObserveWithExemplar), and OpenTelemetry SDKs attach them automatically when a span is active while you record a measurement. Your backend must store and show them; check before you rely on it.
When the trace says "this function is slow": profiling
A trace shows that render invoice took 800 ms but not which lines of it. That's a Profiler's job. Go's pprof can be exposed on a private port: import _ "net/http/pprof" (the _ means "import it only for its side effect" — it registers /debug/pprof/ handlers on the default mux) plus go http.ListenAndServe("localhost:6060", nil) in main. Then fetch a profile from a live server with go tool pprof http://host:6060/debug/pprof/profile?seconds=30; the result is usually read as a Flame graph. The GC topic walks through a real heap profile. Node has node --cpu-prof and the inspector.
Continuous profiling takes this further: an agent samples every server a few times per second, all the time, so you can ask "what was burning CPU on Tuesday at 14:05?" after the fact. The overhead is typically low single-digit percent — measure it on your workload.
Runtime metrics: is the runtime itself struggling?
Some slowness comes from the language runtime, not your code: garbage collection, too many goroutines, a blocked event loop. Both runtimes report on themselves:
import "runtime/metrics"
samples := []metrics.Sample{
{Name: "/sched/goroutines:goroutines"},
{Name: "/memory/classes/heap/objects:bytes"},
{Name: "/gc/cycles/total:gc-cycles"},
}
metrics.Read(samples)
for _, s := range samples {
fmt.Printf("%-40s %d\n", s.Name, s.Value.Uint64())
}
// /sched/goroutines:goroutines 501
// /memory/classes/heap/objects:bytes 266112
// /gc/cycles/total:gc-cycles 0(Real output on this machine; the Go program had started 500 sleeping goroutines.) The Node result is a lesson in itself: one 200 ms freeze is invisible in p99. The freeze swallowed about 20 of the 10 ms ticks, so the histogram held only about 80 samples, one of them huge. With fewer than 100 samples, p99 is effectively "the second-largest value", and the second-largest was a normal tick. Only max caught it. And the p50 of 10.1 ms isn't 10 ms of delay: the numbers include the 10 ms sampling interval itself, so subtract it mentally. A busy-looping or CPU-heavy request shows up as Event-loop delay; see Async/Await in production. In practice you don't call these by hand: Prometheus's Go collector and prom-client's collectDefaultMetrics() export them, and OTel has runtime instrumentation packages for both.
Dashboards that answer questions
A dashboard with 60 graphs answers nothing at 2 a.m. Build each one around a question, top to bottom:
- "Are users OK?" — SLO status and budget remaining; RED for the service (rate, errors, p50/p99).
- "Is it us or a dependency?" — RED for each downstream call (DB, payments, inventory).
- "Is something running out?" — USE for resources: CPU, memory, DB pool in use vs waiting, queue depth, GC / event-loop delay.
- "What changed?" — deploys and feature-flag flips drawn as vertical lines on every graph. A large share of incidents start with a change.
Cost: the bill is part of the design
Observability bills commonly surprise teams — it's not rare for them to rival the compute bill. The three cost drivers map to the three signals:
- Metrics: cardinality. One label like
user_id,url(with IDs in it) orerror_messagecan multiply series by millions (§02). Review new labels the way you review a database schema; many teams lint for them in CI. - Logs: volume. A DEBUG line in a hot loop at 5,000 requests/s is 430 million lines a day. Keep DEBUG off by default with a way to switch it on for one service or one user; sample chatty INFO lines (keep 1 in 100) but never sample errors; prefer one wide event per request over ten thin lines.
- Traces: how many you keep. Head-sample to cut the bulk; tail-sample in the Collector to keep every error and slow trace (§08).
Privacy: logs are a copy of your data
Every log line and span attribute is copied to a vendor, retained for weeks and read by many people. Data-protection laws (GDPR and similar) apply to it like to your database: a user's "delete my data" request covers their email sitting in your logs too. Defaults that save you: redaction at the type level (LogValuer, pino redact, §04); IDs instead of names and emails; and a scrubbing step in the Collector as a last safety net for Personal data and secrets like Authorization headers.
Libraries vs applications
If you write a library (a database driver, an SDK), depend only on the OpenTelemetry API, accept a logger (*slog.Logger) or use slog.Default(), and never configure exporters or global settings. The application owns those choices: which SDK, which exporter, which sampler, which log level. Because the API does nothing until an application installs an SDK, a library that's instrumented this way costs nothing for users who don't care.
The OpenTelemetry Collector
Rather than having every service send straight to a vendor, most setups run an OpenTelemetry Collector in between:
Apps send OTLP to a nearby Collector (often a Sidecar or one per machine), which batches, retries, scrubs PII, tail-samples and fans out to one or more backends. Switching vendors becomes a Collector config change instead of a redeploy of every service. Tail sampling needs all spans of a trace to reach the same Collector instance, which is why it's usually a second, central tier, routed by trace ID.
Observability-driven development
The habit that ties this together: when you write a feature, decide how you'll know it works in production — before you ship it. Which SLI does it affect? Which span and attributes will show its path? Which field will tell you which users hit the new code? Then, after deploying, actually go and look: does the new span appear, are the attributes filled in, did p99 move? Finding gaps on a calm Tuesday is much cheaper than at 2 a.m.
Pitfalls gallery
A user ID (or a raw URL) as a metric label
requests.WithLabelValues(userID) or route: req.url creates one series per user or per URL. Memory and bills explode, often days later when traffic grows. Fix: labels only from small fixed sets — use the route pattern (/orders/{id}; in Go 1.23+ r.Pattern gives you the matched mux pattern). Put IDs in logs and span attributes.
Graphing the average latency
The mean hides the slow tail and describes no real user (§06). Fix: histograms, and graph p50 and p99 (plus max while debugging).
Averaging percentiles across servers or time
avg(p99 of each pod) is not the service's p99. Fix: sum the histogram buckets first (sum by (le)), then compute the percentile once (§06).
Logging with the context left out
In Go, slog.Info(…) instead of slog.InfoContext(ctx, …) — or starting a span from context.Background() instead of the request's ctx — silently drops the request ID and breaks the trace into pieces. Fix: pass ctx everywhere; linters such as sloglint (in golangci-lint) can be configured to flag the context-less calls.
A pino mixin that returns your shared store object
We hit this while writing §04: with mixin: () => als.getStore(), pino merges each line's fields into the object you returned (its default merge is Object.assign(mixinObject, fields)). The path from the first line leaked into every later line of that request. Fix: return a copy — mixin: () => ({ ...als.getStore() }) — or store a child logger in AsyncLocalStorage as §04 does.
A header-dropping hop breaks every trace
A hand-rolled HTTP client, an old proxy or a message queue that doesn't copy traceparent splits each trace in two. Fix: use instrumented clients (otelhttp.NewTransport, auto-instrumentation), copy trace context into message headers, and check one end-to-end trace after every architecture change.
Units hidden in the numbers
slog's JSON handler writes a time.Duration as nanoseconds ("took":2300000000); OTel JS reports span duration in microseconds; Prometheus convention is seconds. Fix: put the unit in the name — took_ms, http_request_duration_seconds — and use base units (seconds, bytes) for metrics.
Decrementing a counter, or resetting it yourself
rate() treats any drop as a process restart, so a counter that goes down produces nonsense spikes. Fix: use a gauge for anything that goes down. Counters only ever Inc() / Add(positive).
Secrets and personal data in logs
logger.Info("request", "headers", r.Header) writes the Authorization header to your log vendor. logger.Info("user", "user", u) writes their email and address. Fix: LogValuer on sensitive types, pino redact, allow-lists of fields to log, and a scrubbing step in the Collector (§11).
Alerting on causes and raw thresholds
"CPU > 80%" and "error rate > 1% for 1 minute" page people for nothing at night and miss slow burns (§10). Fix: page on SLO burn rate with a long and a short window; send cause alerts to dashboards and tickets.
Forgetting to flush on shutdown
Batching exporters hold spans in memory. A process that exits (a deploy, a crash, a short CLI job) without tp.Shutdown(ctx) / provider.shutdown() loses the last few seconds of telemetry — often exactly the part about the crash. Fix: shut the provider down in your graceful-shutdown path, with a timeout.
Health checks and bots inside your SLI
Load-balancer health checks hit /healthz every few seconds and always succeed, so they pad your success rate and hide real failures. Fix: define "valid events" explicitly — real user routes, excluding health checks and known bots — and write that definition down next to the SLO.
Check yourself
Each question has one best answer. The explanation says which section to revisit.
1,000 requests: 990 take 50 ms and 10 take 5 s. Roughly what are the mean and the p50?
A counter has labels route (10 values), code (6 values) and region (3 values). How many time series can it create?
Pod A reports p99 = 120 ms, pod B reports p99 = 900 ms. What's the p99 of the whole service?
What is the parent of the charge card span?
ctx, root := tracer.Start(ctx, "checkout")
_, a := tracer.Start(ctx, "reserve stock")
a.End()
_, b := tracer.Start(ctx, "charge card")
b.End()
root.End()The handler from §04 is installed. Does this line include request_id?
func chargeCard(ctx context.Context, id int) {
slog.Info("charging card", "order_id", id)
}SLO: 99.9% over 30 days. Right now 0.6% of requests fail. What is the burn rate, and how long would the whole budget last at this pace?
Which of these should wake an engineer at 3 a.m.?
You keep 5% of traces with head sampling. Errors are rare (1 in 10,000 requests). What happens to traces of failed requests?
Cheat sheet
Which signal?
| Question | Signal |
|---|---|
| Is something wrong? How much? Since when? | Metrics (RED, SLO burn rate) |
| Where did the time go for this request? Which service? | Traces |
| Why exactly did this one fail? | Logs (filtered by request / trace ID) |
Logging
logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: slog.LevelInfo}))
logger.InfoContext(ctx, "order placed", "order_id", 1042, "took_ms", 38)
reqLog := logger.With("request_id", id) // fields on every line
func (c Card) LogValue() slog.Value { … } // redaction lives with the type- Constant message, details in fields. Units in field names.
- Request ID from middleware, carried by
ctx/ AsyncLocalStorage, sent on to other services. - Never log secrets or personal data; redact by type, scrub in the Collector.
Metrics
| Type | For | Read it as |
|---|---|---|
| Counter | things that happen | rate(x_total[5m]) per second |
| Gauge | current level | the value itself |
| Histogram | durations, sizes | histogram_quantile(0.99, sum by (le) (rate(x_bucket[5m]))) |
- RED for services: Rate, Errors, Duration. USE for resources: Utilization, Saturation, Errors.
- Labels only from small fixed sets. Series = product of label cardinalities.
- Graph p50 + p99, not the mean. Never average percentiles — merge buckets, then compute.
Tracing
ctx, span := tracer.Start(ctx, "charge card") // reassign ctx!
defer span.End()
span.SetAttributes(attribute.Int("order.id", id))
span.RecordError(err); span.SetStatus(codes.Error, "…")traceparent: 00-<32 hex trace id>-<16 hex parent span id>-<flags>;01= sampled.- Use instrumentation libraries (
otelhttp, auto-instrumentations-node); add manual spans for business steps. - Head sampling = cheap, random. Tail sampling = keep errors and slow traces; done in the Collector.
- Set
service.name. CallShutdownon exit.
SLOs and alerts
| SLO (30 days) | Budget |
|---|---|
| 99% | 7 h 12 min |
| 99.9% | 43 min |
| 99.99% | 4 min 19 s |
- SLI = good events ÷ valid events, from the user's point of view.
- Burn rate = error rate ÷ allowed error rate. Page at 14.4× over 1 h and 5 min, 6× over 6 h and 30 min; ticket at 1× over 3 days.
- Page on symptoms, not causes. Every page actionable, every alert has a runbook.