navree
Documentation

Distributed tracing

Follow one request through every service with OpenTelemetry: spans for HTTP, outgoing calls, queries, jobs, cache and mail, W3C trace context across every hop, OTLP export, trace ids in your logs, and Lighthouse.

On this page

Introduction

Featureobserve In one binary, the request log line and its request id tell you what a request did. Across services, one click in the web app becomes an HTTP request to crm-api, a deals.move message to the deals service, a few queries, a deal.won event to two more services, and a queued mail. A trace ties them together: each step is a span with a start, a duration, attributes and a parent, and the spans of one click form one tree.

Navree records traces with OpenTelemetry, the open standard for them:

  • every request, outgoing call, query, job, scheduled task, cache call and mail is a span, named and labeled with OpenTelemetry's conventions; messages, gRPC calls and GraphQL operations are spans too, with their packages;
  • the trace context travels with every hop: HTTP calls in and out, queued jobs, and messages and gRPC calls with their packages;
  • spans go to any OpenTelemetry backend over OTLP;
  • log lines written inside a request or job carry its trace id;
  • Lighthouse links each issue to the trace where it happened.

Propagation is always on, so trace ids appear in your logs and in the headers your app sends from the first request. Spans are built only when something reads them: the OTLP export, the stdout exporter, or SpanRecorder in a test. An app that exports nothing pays for a trace id per request and nothing else.

Text

Spans are made from Navree's telemetry events: when a request is answered, a query runs or a job attempt ends, ObserveModule turns the event into a span of the request's or job's trace.

Exporting traces

Tracing is part of ObserveModule, in the observe.tracing section. OTLP export needs the facade's otel feature. It is opt-in, not in full, because it adds the OpenTelemetry SDK, tonic and prost:

Cargo.toml

otel turns on observe and adds the exporter; the default features stay on.

Then point the section at an OTLP endpoint, usually an OpenTelemetry Collector:

config/app.toml

That's all a service needs. Its spans carry service.name from micro.service (or app.name), are batched in the background and sent over OTLP/gRPC. Without the otel feature, an endpoint in the configuration fails the boot with a message that names the feature, and one from OTEL_EXPORTER_OTLP_ENDPOINT is ignored with a warning.

KeyDefaultMeaning
observe.tracing.enabledtrueStart traces and propagate trace context. false turns both off.
observe.tracing.endpointnoneThe OTLP endpoint, http:// or https://. Without one, nothing is exported.
observe.tracing.protocolgrpcgrpc (port 4317) or http (OTLP/HTTP with protobuf, port 4318). For http, /v1/traces is added to an endpoint without a path.
observe.tracing.headers{}Headers sent with every export, such as a vendor's API key.
observe.tracing.service_namemicro.service, then app.name, then the binary's nameThe service.name of every span.
observe.tracing.resource{}Extra resource attributes, such as { "deployment.environment" = "production" }.
observe.tracing.sample_ratio1.0The share of new traces recorded, from 0 to 1. See sampling.
observe.tracing.trust_incomingtrueContinue traces from incoming traceparent headers. See public edges.
observe.tracing.stdoutfalseAlso print finished spans to stdout, one JSON object per line, for development. Works without the otel feature.
observe.tracing.timeout_ms10000The time limit of one export.
observe.tracing.max_queue_size2048Spans waiting for export; when full, new spans are dropped.
observe.tracing.trace_urlnoneYour backend's trace page, with {trace_id}, for links to traces.

An invalid value fails the boot with a message that names the key: a sample_ratio outside 0 to 1, a timeout_ms or max_queue_size of 0, an endpoint that isn't an http:// or https:// URL.

As environment variables: APP_OBSERVE__TRACING__ENDPOINT=http://otel-collector:4317, APP_OBSERVE__TRACING__SAMPLE_RATIO=0.2. Navree also reads OpenTelemetry's standard variables for any setting the observe.tracing section doesn't set: OTEL_EXPORTER_OTLP_ENDPOINT, OTEL_EXPORTER_OTLP_PROTOCOL (grpc or http/protobuf), OTEL_EXPORTER_OTLP_HEADERS and OTEL_RESOURCE_ATTRIBUTES (key=value,key=value), OTEL_SERVICE_NAME and OTEL_TRACES_SAMPLER_ARG.

In code, inject Arc<TracingOptions> (from navree::observe): ObserveModule provides the section as it was read, with the variables applied and the service name resolved.

Locally

Run a backend that accepts OTLP, such as Jaeger's all-in-one image, and point every service at it:

Shell
.env

Click through the web app, then open http://localhost:16686 and pick crm-api: each request is a trace, with the spans of every service it reached.

Without a backend, set observe.tracing.stdout = true and read the spans in the terminal:

One span, formatted

What is traced

Navree names spans and sets attributes the way OpenTelemetry's semantic conventions say, so backends recognize HTTP, database, messaging and RPC spans and draw them accordingly.

WhatSpan nameKindMain attributes
An HTTP requestGET /api/v1/deals/{id} (method and route template)serverhttp.request.method, http.route, http.response.status_code, url.path, client.address, navree.request_id, enduser.id, navree.workspace_id
An outgoing HTTP call (HttpClient)GETclienthttp.request.method, server.address, url.full (no query string), http.response.status_code, http.request.resend_count
A database querySELECT dealsclientdb.system.name, db.operation.name, db.collection.name, db.query.text
A job runjob contacts.exportconsumernavree.queue, navree.job_id, navree.attempt
A scheduled task runtask prune-sessionsinternalnavree.task
A cache callcache get, cache put, cache forgetinternalnavree.cache.store, navree.cache.hit
A mail sentmail sendclientnavree.mail.transport
A message sentsend deals.moveclientmessaging.system, messaging.destination.name, messaging.message.id, navree.service
A message handledprocess deals.moveserverthe same, plus navree.reply_status
An event publishedpublish deal.wonproducermessaging.system, messaging.destination.name, messaging.message.id
An event handledprocess deal.wonconsumerthe same, plus messaging.consumer.group.name, navree.attempt
A gRPC call servedcrm.deals.v1.Deals/GetDealserverrpc.system, rpc.service, rpc.method, rpc.grpc.status_code
A gRPC call madecrm.deals.v1.Deals/GetDealclientthe same
A GraphQL operationquery DealBoard, mutation MoveDealinternalgraphql.operation.type, graphql.operation.name

The first seven come with the core modules; the messaging, gRPC and GraphQL spans come with microservices, gRPC and GraphQL.

  • A request's span covers the whole request. Queries, outgoing calls, cache calls and mail sent while it runs are its children; so are its log lines, through their trace id.
  • An outgoing call is one span for all its attempts: http.request.resend_count says how many retries it took.
  • A job attempt is one span. The queries and calls of the handler are its children, and the job itself is a child of the span that dispatched it (see context propagation).
  • Each scheduled task run starts a new trace.
  • Notifications, exceptions and log lines are telemetry events but not spans.

Some rules hold for every span:

  • No values from your data. db.query.text is the statement with its placeholders, never the bound parameters (a literal you write into the SQL yourself stays in it); URLs lose their query string and credentials; payloads, bodies and headers are never recorded.
  • Errors mark the span. A 5xx response, a failed outgoing call (a 5xx, or no response), a failed job attempt, a failed scheduled task or a failed query sets the span's status to error, with the error's message. A 4xx is a client's mistake, not the server's: an HTTP server span keeps status unset for it, as the conventions say.

Context propagation

Navree uses W3C Trace Context (traceparent and tracestate) on every hop, so spans from different services join the same trace, whatever language a service is written in:

HopCarried inThe span on the other side is
HTTP into a Navree apprequest headersa child of the caller's span
HttpClient out of a Navree apprequest headers, added by Navreea child of the GET client span
Queued jobs, queued listeners, queued mailthe job's row (jobs.trace_parent)job is a child of the span that dispatched it
ServiceClient::sendmessage headersprocess is a child of send
ServiceClient::emit and forwarded eventsmessage headers (and the outbox row)each service's process is a child of publish
gRPC, both wayscall metadataa child of the caller's span
GraphQL subscriptionsthe WebSocket's connection_initeach event's span links to the subscription
  • Incoming HTTP. navree-http reads traceparent and tracestate on every request. A valid header continues the caller's trace with a new span; a missing or malformed one starts a new trace. The observe.tracing keys enabled, trust_incoming and sample_ratio apply even without ObserveModule.
  • Outgoing HTTP. Inside a request or job, every HttpClient request carries a traceparent for a new client span of the current trace, and the current tracestate. A request that sets its own traceparent header keeps it.
  • Queued jobs. A job dispatched inside a request or job records that span's traceparent with the job (the jobs.trace_parent column, added by the queue's migrations). Each attempt continues that trace, whatever trust_incoming says, since the value came from your own app. Queued listeners and queued mail are jobs, so they follow. Jobs dispatched outside a request or job, and failed jobs retried with navree queue:retry, start a new trace.

An event published through the outbox keeps the context of the code that emitted it: the outbox stores it with the row, so the publish span sits under the request that changed the deal even when a relay on another instance sent it.

Browsers can join too. The app's CORS settings allow the traceparent and tracestate request headers, so a front end instrumented with OpenTelemetry's web SDK starts the trace at the click, and the backend's spans continue it.

Public edges

By default an incoming traceparent is trusted: the request's spans join the caller's trace, and the caller's sampling decision holds. That's right between your own services and for your own front end. On an API that strangers call, a client could pick trace ids or force sampling on. Set observe.tracing.trust_incoming = false on the edge service: each request then starts a new trace, sampled by your own sample_ratio, whose span keeps a link to the client's span so you can still follow it.

Your own code in a trace

Everything your handlers and jobs do through Navree is already in the trace: their queries, outgoing calls, cache calls, mail and the jobs they dispatch. Spans you open yourself with the tracing crate stay in your logs, where each line carries the trace id; they are not exported as spans.

To show users a reference they can quote to support, read the current trace id:

Rust

It is None outside a request, job or scheduled task run, and when tracing is off. The same value is navree::telemetry::current_trace_id(); TelemetryContext::current() (in navree::telemetry) gives the whole context: the request or job id, the trace, the user and the workspace.

Work you spawn onto another task leaves the request's context behind, since it is a task-local value. Wrap the future to keep it:

Rust

Sampling

Recording every trace is right in development and for most apps. At high volume, record a share of them with observe.tracing.sample_ratio:

  • the decision is made when a trace starts, from its trace id, so every service makes the same decision for the same trace;
  • a request that arrives with a trusted traceparent follows the caller's decision, and a queued job follows the request that dispatched it, so traces are never cut in half;
  • unsampled requests still get a trace id: it is in the logs and propagated to the next service, but none of their spans are built or exported.

A ratio below 1.0 drops error traces too, since nobody knows at the start that a request will fail. To keep every trace with an error and a share of the rest, keep sample_ratio = 1.0 and let an OpenTelemetry Collector make the decision at the end of each trace (tail sampling).

Logs and traces

Every log line written inside a request or job carries the trace id and the id of the request's or job's span. In the JSON format, they sit next to the request id:

One line, formatted

Search your logs for a trace id to get the lines of every service that took part, or start from the logs and open the trace. To pass the request id on as well, add .with_request_id(&request_id) to an HttpClient request: it sends X-Request-Id, and the other Navree service uses it as its own request id. In development, Logbook shows the same ids on its entries.

Lighthouse

Lighthouse stores the trace id with every exception, slow request, slow query and failed job it groups into an issue. Tell it where your traces live:

TOML

Each occurrence of an issue then links to its trace. Your own pages can build the same link: tracing_options.trace_link(&trace_id) on the injected TracingOptions returns trace_url with the id filled in, or None when trace_url isn't set.

In production

  • Export to a Collector, as an agent on each host or a gateway for the cluster, rather than straight to a vendor. The Collector batches, retries, samples by tail, and lets you change backends without redeploying services.
  • Export never slows requests. Spans are queued and sent in the background, in batches of up to 512 every two seconds. When the queue is full (max_queue_size), new spans are dropped and counted in the navree_tracing_spans_dropped_total metric on /metrics. A failed or timed-out export is logged as a warning under the navree::tracing target.
  • Shutdown flushes. On Ctrl-C or SIGTERM, Navree exports what's left in the queue before the app stops.
  • Resource attributes identify each process: service.name, service.instance.id (unique per process), service.version (the app.version setting, when you set it), plus observe.tracing.resource.
  • TLS to an https:// endpoint uses rustls with the ring provider, as the rest of Navree does.

Testing

SpanRecorder (from navree::observe::testing) collects finished spans in memory. Add its module to the app, then assert on the tree. This test sends a request with a traceparent to a route that calls another service through a faked HttpClient:

tests/tracing.rs

spans.all() returns every finished span, spans.find(name) the first with that name (and fails the test with the names it has when there is none), spans.find_all(name) every one, and spans.clear() forgets them. Each RecordedSpan has its name, kind (SpanKind), trace_id, span_id, parent_span_id, start, end, status (SpanStatus::Unset or SpanStatus::Error { message }), attributes (JSON values by name) and links. The recorder sees the spans of sampled traces whether or not an endpoint is configured, so tests never export anything.

To assert on the events themselves (requests, queries, jobs, mail), use TelemetryRecorder.