Distributed Tracing for a Go Service: One Request, One Thread You Can Pull

A friend pings you: "hey, that payment felt slow just now." You open the logs. What you get is a hundred requests worth of lines, all interleaved, all from the same few seconds. You can see that something took a while, but you can't tell which lines belong to that one payment, or whether the time went to Postgres, to the domain logic, or to the network in between. You are staring at a haystack and someone is describing one specific piece of straw.

That is the exact pain distributed tracing solves. A trace ties every step of one request together under a single id, so you can pull that one thread out of the pile and see the whole thing: where it went, how long each hop took, and where it stalled. This week I wired it into go-ledger, and the goal was concrete: post one transaction, and get back one trace that runs from the HTTP handler, through the domain service, down to every SQL query, all linked. This is post 8 of 12.

What "one trace" actually looks like

Say you post the dinner-repayment transaction from Week 1: move 600 taka from my wallet to my friend's. That single API call touches four layers. Tracing records each layer as a span (a timed unit of work with a name), and nests the child spans inside their parent. Lined up on a timeline, one post looks like this:

POST /v1/transactions                                    [============] 14.2ms
  └─ ledger.PostTransaction           [==========]   11.8ms
       ├─ BEGIN (serializable)        [=]            0.9ms
       ├─ INSERT transaction          [==]           2.1ms
       ├─ INSERT postings (x2)        [===]          3.4ms
       ├─ INSERT idempotency_key      [=]            1.2ms
       ├─ INSERT audit_log            [==]           1.9ms
       └─ COMMIT                      [==]           1.8ms

Now the "it felt slow" conversation is a five-second look instead of a guessing game. If the COMMIT span is fat, you have write contention. If an INSERT is fat, maybe an index is missing. If the gap between the HTTP span and the first SQL span is fat, the time went somewhere in your own code, not the database. The shape of the waterfall tells you where to look before you have read a single line of code.

The tool that produces this is OpenTelemetry (OTel): a vendor-neutral standard for traces, metrics, and logs, with a Go SDK. You instrument your code once against the standard, and you can send the data to whatever backend you like. Locally I send it to Jaeger, which draws exactly the waterfall above in a browser. Remotely I send it to Honeycomb's free tier. The app code does not change between the two; only an environment variable does.

Instrument the edges, then the middle

Most of the tracing you want comes from the boundaries, and the boundaries already have libraries. I wrapped the HTTP router with otelhttp and added otelgrpc to the gRPC server (Week 7 left a clean seam for exactly this), so every inbound request opens a span automatically. For the database, otelpgx plugs into the pgx connection pool as a query tracer and emits one span per SQL statement, which is where those INSERT and COMMIT rows in the waterfall come from.

That covers the top and the bottom. The one span I wrote by hand is the middle one, ledger.PostTransaction, because that is my domain's unit of meaning and no library knows it exists:

ctx, span := s.tracer.Start(ctx, "ledger.PostTransaction",
    oteltrace.WithAttributes(
        attribute.String("tenant_id", tenantID),
        attribute.Int("transaction.posting_count", len(t.Postings)),
        attribute.Bool("idempotency.present", idem != nil),
    ),
)
defer span.End()

The ctx that comes back carries the span, and because every layer already passes context.Context down the call chain, the SQL spans that happen later automatically nest under this one. That is the whole magic of context propagation: you thread one value through, and the tree assembles itself.

The part I'm quietly proud of: what is not in that span

Look again at those attributes. Tenant id, a count, a boolean. No amount. No account balance. No account id as a value. That restraint is deliberate.

Honeycomb is a US company's servers. The moment I ship a span there, I have handed a third party whatever I put in it. For a payment system, "600 taka from account A to account B" is exactly the kind of data you do not casually export to someone else's cloud because a default made it easy. So the rule I baked in, and wrote into the architecture decision record, is simple: identifiers and counts, never money. otelpgx is configured to leave query arguments off, so the actual values bound into a SQL statement never leave the process either. You can trace the shape of the work without leaking the contents.

This is the kind of thing that is trivial to get right when you decide it on purpose in week 8, and quietly awful to discover in an incident review two years later.

The two decisions I went back and forth on

Should everything go through OpenTelemetry? OTel does metrics too, not just traces. The tidy-looking move is to route all my metrics through it and have one instrumentation API. I didn't. I already had four hand-built Prometheus metrics from earlier weeks, including the transaction-latency histogram that any alert I ever write will be based on. The OTel Prometheus exporter renames things: it appends unit suffixes and adds its own labels. Renaming a metric is how you silently break an alert and only find out when the thing it was supposed to page you about happens in silence.

So I split it. The four existing metrics stay exactly as they are, same names. The new "how many requests, how many errors, how fast" numbers for HTTP and gRPC (the classic Rate-Errors-Duration trio) come from the OTel side and get merged into the same /metrics endpoint. Two styles living together on purpose beats one clean style that breaks my alerting. Boring and stable won.

What happens when tracing isn't configured? My first instinct was: if there's no endpoint set, just print spans to stdout so you can still see them. I talked myself out of it. On the server, stdout is where my structured logs go. Dumping a flood of span JSON into that same stream, silently, because someone forgot to set a variable, is a great way to make a misconfiguration invisible. So the behavior is: an endpoint set means export to it; the explicit OTEL_TRACES_EXPORTER=console means print to stdout for local eyeballing; and nothing set means tracing is off with one clear warning line at startup. A missing config should be loud and boring, not a silent surprise.

The thing that makes logs and traces click together

Here is the payoff for the "which lines belong to my payment" problem I opened with. Every span has a trace_id. If I stamp that same id onto every log line emitted during the request, then finding a slow trace in Jaeger and finding its logs become the same lookup.

I did this with a tiny wrapper around Go's slog handler. On every log record, it checks the context for an active span and, if there is one, adds the trace and span ids:

func (h traceHandler) Handle(ctx context.Context, rec slog.Record) error {
    if sc := trace.SpanContextFromContext(ctx); sc.IsValid() {
        rec.AddAttrs(
            slog.String("trace_id", sc.TraceID().String()),
            slog.String("span_id", sc.SpanID().String()),
            slog.Bool("sampled", sc.IsSampled()),
        )
    }
    return h.inner.Handle(ctx, rec)
}

A dozen lines, no new dependency, and now a log line looks like {"msg":"transaction posted","trace_id":"a1b2...","tenant_id":"..."}. Copy the trace_id, paste it into Jaeger, and you are looking at the exact waterfall for that exact request. Logs tell you what happened; the trace tells you where the time went; the shared id is the bridge.

One boring-on-purpose detail: don't trace everything

There is a demo seeder in go-ledger that resets and repopulates the sample data every few hours, writing a few hundred transactions each time. If I trace all of that at full volume, plus a span for every single SQL query, I will happily burn through Honeycomb's free tier on data nobody will ever look at. So sampling is configurable through the standard OTel environment variables (in production I send a quarter of traces, not all of them), and the health-check and metrics endpoints are excluded from tracing entirely. Otherwise ninety percent of your "traces" are just a load balancer asking if you're alive. Keep the signal, drop the noise.

Where this leaves the ledger

One transaction post now produces one trace across HTTP, the domain, and SQL, and its log lines carry the same id. It runs to Jaeger with make jaeger and a single environment variable, and to Honeycomb by changing that variable and adding an API key. No money leaves the process. The existing metrics and their future alerts are untouched.

The repo is open source at github.com/sohag-pro/go-ledger, and the full reasoning for the hybrid metrics, the loud no-op, and the no-money-in-spans rule lives in ADR-010. Next week: testing for real. Unit, integration, load, and pointing enough concurrency at the ledger to try to make it lie about someone's balance.