Lesson 93 of 94
Observability
Debugging tools (the previous lesson) answer questions about one process at one moment. Observability is what you build in advance, so that when something goes wrong across a fleet of services, the answer is already in your logs, metrics, and traces. It's also the difference between "the service is slow" and "requests to /orders for tenant 42 spend 800 ms waiting on the pricing service".
The Rust ecosystem has converged on a small set of libraries:
| Concern | Rust |
|---|---|
| Logging API | tracing (or log in older libraries) |
| Logging backend | tracing-subscriber (formatting, filtering, output) |
| Request context | spans with fields |
| Automatic instrumentation | #[instrument], tower-http layers (compile time) |
| Metrics | metrics crate + an exporter, or the OpenTelemetry metrics API |
| Distributed tracing | tracing-opentelemetry + opentelemetry-otlp |
| Health checks | a few routes you write |
Logging and Tracing in Essential Crates introduces the tracing API. This lesson goes further: designing telemetry for a production service.
Part 1: Structured logs and spans
1. Events with structured fields
A tracing event is a log line with typed fields. Fields are key-value pairs, not text interpolated into a message, so a log backend can index and query them (status >= 500 AND route = "/orders"). % records a field with Display, ? with Debug.
use tracing::{info, warn};
#[derive(Debug)]
enum Plan {
Free,
Pro,
}
fn main() {
tracing_subscriber::fmt().without_time().with_ansi(false).with_target(false).init();
let user_id = 42;
let plan = Plan::Pro;
let email = "ana@example.com";
info!(user_id, ?plan, "user logged in");
info!(user_id, plan = ?Plan::Free, %email, "downgraded");
warn!(user_id, attempts = 3, "password reset rate limit reached");
} INFO user logged in user_id=42 plan=Pro
INFO downgraded user_id=42 plan=Free email=ana@example.com
WARN password reset rate limit reached user_id=42 attempts=3without_time and with_ansi(false) are only there to make this output reproducible; a real service keeps timestamps. Prefer fields over formatting values into the message: info!(order_id, "order shipped") rather than info!("order {order_id} shipped").
2. Spans: context that every event inherits
A span represents a unit of work with a beginning and an end: a request, a job, a database transaction. Events inside a span automatically carry the span's fields. Spans are structured and nested, and they don't depend on thread-local state that breaks with async code.
use tracing::{info, info_span, warn};
fn charge_card(amount_cents: u64) -> bool {
info!(amount_cents, "charging card");
amount_cents < 10_000
}
fn handle_checkout(request_id: &str, user_id: u64, amount_cents: u64) {
let span = info_span!("checkout", request_id, user_id);
let _guard = span.enter();
info!("checkout started");
let payment = info_span!("payment", provider = "stripe");
let ok = payment.in_scope(|| charge_card(amount_cents));
if !ok {
warn!(amount_cents, "payment declined");
}
}
fn main() {
tracing_subscriber::fmt().without_time().with_ansi(false).with_target(false).init();
handle_checkout("req-7f3a", 42, 2_500);
handle_checkout("req-9c1d", 7, 25_000);
} INFO checkout{request_id="req-7f3a" user_id=42}: checkout started
INFO checkout{request_id="req-7f3a" user_id=42}:payment{provider="stripe"}: charging card amount_cents=2500
INFO checkout{request_id="req-9c1d" user_id=7}: checkout started
INFO checkout{request_id="req-9c1d" user_id=7}:payment{provider="stripe"}: charging card amount_cents=25000
WARN checkout{request_id="req-9c1d" user_id=7}: payment declined amount_cents=25000charge_card knows nothing about requests, yet its log line says which request and which user it belongs to. Spans also have durations, which is what makes them the basis of distributed tracing (Part 3).
3. #[instrument]: a span per function call
#[tracing::instrument] wraps a function in a span named after it, with its arguments as fields. Use skip for arguments that are large or sensitive, fields to add computed values, and err to record a returned error.
use tracing::{info, instrument};
#[derive(Debug)]
struct Db;
#[derive(Debug)]
struct Credentials {
user: String,
password: String,
}
#[instrument(skip(db, creds), fields(user = %creds.user))]
fn login(db: &Db, creds: &Credentials) -> Result<u64, String> {
let _ = db;
info!("checking password");
if creds.password.len() >= 8 { Ok(42) } else { Err("password too short".to_string()) }
}
#[instrument(err)]
fn load_profile(user_id: u64) -> Result<String, String> {
if user_id == 42 { Err(format!("profile {user_id} not found")) } else { Ok("profile".into()) }
}
fn main() {
tracing_subscriber::fmt().without_time().with_ansi(false).with_target(false).init();
let db = Db;
let creds = Credentials { user: "ana".into(), password: "correct horse".into() };
if let Ok(id) = login(&db, &creds) {
let _ = load_profile(id);
}
} INFO login{user=ana}: checking password
ERROR load_profile{user_id=42}: error=profile 42 not foundskip(creds) keeps the password out of the logs; only the user name is recorded through fields. Make skip a habit for anything holding secrets, tokens, or personal data. #[instrument(skip_all)] skips every argument, and ret records the return value.
4. Spans across .await: use .instrument(), not enter()
In async code, a task can be suspended at every .await, and another task then runs on the same thread. A span guard from span.enter() held across an .await stays "entered" on the thread while the task is suspended, so other tasks' events get attributed to the wrong request. #[instrument] on an async fn, or .instrument(span) on a future, enters and exits the span correctly on every poll.
use std::time::Duration;
use tracing::{Instrument, info, info_span};
async fn fetch_price(sku: &str) -> u64 {
tokio::time::sleep(Duration::from_millis(10)).await;
info!(sku, "price fetched");
499
}
#[tracing::instrument]
async fn handle(request_id: u32, sku: &'static str) -> u64 {
info!("start");
fetch_price(sku).await
}
#[tokio::main(flavor = "current_thread")]
async fn main() {
tracing_subscriber::fmt().without_time().with_ansi(false).with_target(false).init();
let a = tokio::spawn(handle(1, "apple"));
let b = tokio::spawn(handle(2, "pear"));
a.await.unwrap();
b.await.unwrap();
// For a future you didn't write, attach the span explicitly:
let job = async { info!("background job ran") };
job.instrument(info_span!("nightly_report", day = "2026-09-27")).await;
} INFO handle{request_id=1 sku="apple"}: start
INFO handle{request_id=2 sku="pear"}: start
INFO handle{request_id=1 sku="apple"}: price fetched sku="apple"
INFO handle{request_id=2 sku="pear"}: price fetched sku="pear"
INFO nightly_report{day="2026-09-27"}: background job ranThe two requests interleave on one thread, and every line still names the right request. The rule: never hold span.enter()'s guard across an .await; Clippy doesn't catch it, but code review should.
5. JSON logs for production
Humans read the compact format; log pipelines (Elasticsearch, Loki, Datadog, CloudWatch) want one JSON object per line. The same events, with the JSON formatter:
use tracing::{info, info_span, warn};
fn main() {
tracing_subscriber::fmt().json().without_time().with_target(false).with_current_span(true).with_span_list(false).init();
let span = info_span!("http_request", method = "POST", route = "/orders", request_id = "req-7f3a");
let _g = span.enter();
info!(order_id = 1001, items = 3, "order created");
warn!(latency_ms = 842, "slow request");
}{"level":"INFO","fields":{"message":"order created","order_id":1001,"items":3},"span":{"method":"POST","request_id":"req-7f3a","route":"/orders","name":"http_request"}}
{"level":"WARN","fields":{"message":"slow request","latency_ms":842},"span":{"method":"POST","request_id":"req-7f3a","route":"/orders","name":"http_request"}}Numbers stay numbers, so the log backend can compute percentiles of latency_ms directly. A common setup chooses the format from configuration: compact and colored for local development, JSON in containers.
6. Filtering with RUST_LOG
EnvFilter decides which events are recorded, per module and per level, with the same syntax as the RUST_LOG environment variable. Filtering is cheap: disabled events cost roughly one atomic load and a branch.
use tracing::{debug, info, trace};
use tracing_subscriber::EnvFilter;
// Targets default to the module path (`my_service::db`); they're set explicitly
// here so the example prints the same names wherever it's compiled.
mod db {
pub fn query() {
tracing::debug!(target: "app::db", "SELECT * FROM orders");
}
}
mod http {
pub fn request() {
tracing::debug!(target: "app::http", "GET /orders");
tracing::info!(target: "app::http", "200 OK");
}
}
fn main() {
// Usually: EnvFilter::from_default_env(), set with RUST_LOG=...
let filter = EnvFilter::new("info,app::db=debug");
tracing_subscriber::fmt().without_time().with_ansi(false).with_env_filter(filter).init();
info!(target: "app", "service started");
debug!(target: "app", "hidden: app is at info");
trace!(target: "app", "hidden too");
db::query();
http::request();
} INFO app: service started
DEBUG app::db: SELECT * FROM orders
INFO app::http: 200 OKUseful directives: RUST_LOG=info,my_service=debug,hyper=warn,sqlx=warn (noisy dependencies down, your code up), and span filters such as RUST_LOG=[checkout]=debug to see everything inside one kind of span. tracing_subscriber::reload lets you change the filter in a running service, for example from an admin endpoint, without a restart.
7. Recording fields that are known later
Some context is only known partway through a request: the authenticated user, the tenant, the result. Declare the field as Empty when creating the span, and record it later. Every event from then on carries it.
use tracing::{field, info, info_span};
fn authenticate(token: &str) -> Option<u64> {
token.strip_prefix("tok-").and_then(|id| id.parse().ok())
}
fn handle(token: &str) {
let span = info_span!("request", route = "/me", user_id = field::Empty, outcome = field::Empty);
let _g = span.enter();
info!("received");
match authenticate(token) {
Some(id) => {
span.record("user_id", id);
info!("authenticated");
span.record("outcome", "ok");
}
None => {
span.record("outcome", "unauthorized");
}
}
info!("done");
}
fn main() {
tracing_subscriber::fmt().without_time().with_ansi(false).with_target(false).init();
handle("tok-42");
handle("garbage");
} INFO request{route="/me"}: received
INFO request{route="/me" user_id=42}: authenticated
INFO request{route="/me" user_id=42 outcome="ok"}: done
INFO request{route="/me"}: received
INFO request{route="/me" outcome="unauthorized"}: done8. Layers: one event stream, many consumers
tracing-subscriber is built from layers stacked on a registry: one formats logs, one filters, one exports spans to OpenTelemetry, and you can write your own. A custom layer that counts events by level shows the mechanism, and is a simple way to turn "number of errors logged" into a metric:
use std::sync::atomic::{AtomicU64, Ordering};
use tracing::{Event, Level, Subscriber, error, info, warn};
use tracing_subscriber::layer::{Context, Layer};
use tracing_subscriber::prelude::*;
static WARNINGS: AtomicU64 = AtomicU64::new(0);
static ERRORS: AtomicU64 = AtomicU64::new(0);
struct CountingLayer;
impl<S: Subscriber> Layer<S> for CountingLayer {
fn on_event(&self, event: &Event<'_>, _ctx: Context<'_, S>) {
match *event.metadata().level() {
Level::ERROR => ERRORS.fetch_add(1, Ordering::Relaxed),
Level::WARN => WARNINGS.fetch_add(1, Ordering::Relaxed),
_ => 0,
};
}
}
fn main() {
tracing_subscriber::registry()
.with(tracing_subscriber::fmt::layer().without_time().with_ansi(false).with_target(false))
.with(CountingLayer)
.init();
info!("processing batch");
warn!(row = 17, "missing optional field");
error!(row = 42, "invalid date");
warn!(row = 99, "missing optional field");
println!("warnings: {}, errors: {}", WARNINGS.load(Ordering::Relaxed), ERRORS.load(Ordering::Relaxed));
} INFO processing batch
WARN missing optional field row=17
ERROR invalid date row=42
WARN missing optional field row=99
warnings: 2, errors: 1Layers are how Rust observability composes: the same info! calls feed the console, a JSON file, OpenTelemetry, and an error tracker (Sentry has a tracing integration), without the application code knowing about any of them.
Part 2: Metrics
9. Counters, gauges, and histograms with the metrics crate
Logs describe individual events; metrics are cheap aggregated numbers you can graph and alert on. The metrics crate is a facade (like tracing for metrics): code records values with macros, and an exporter chosen in main publishes them. Here the Prometheus exporter renders its text format:
use metrics::{counter, gauge, histogram};
use metrics_exporter_prometheus::{Matcher, PrometheusBuilder};
fn main() {
let handle = PrometheusBuilder::new()
.set_buckets_for_metric(Matcher::Full("http_request_duration_seconds".into()), &[0.01, 0.05, 0.1, 0.5])
.unwrap()
.install_recorder()
.unwrap();
for (route, status, ms) in [("/orders", 200, 12.0), ("/orders", 200, 30.0), ("/orders", 500, 250.0), ("/health", 200, 1.0)] {
counter!("http_requests_total", "route" => route, "status" => status.to_string()).increment(1);
histogram!("http_request_duration_seconds", "route" => route).record(ms / 1000.0);
}
gauge!("db_pool_connections_in_use").set(7.0);
// In a service, a GET /metrics route returns handle.render().
let text = handle.render();
let mut lines: Vec<&str> = text.lines().filter(|l| !l.is_empty() && !l.starts_with('#')).collect();
lines.sort(); // the exporter's order isn't stable; sorted for a reproducible listing
println!("{}", lines.join("\n"));
}db_pool_connections_in_use 7
http_request_duration_seconds_bucket{route="/health",le="+Inf"} 1
http_request_duration_seconds_bucket{route="/health",le="0.01"} 1
http_request_duration_seconds_bucket{route="/health",le="0.05"} 1
http_request_duration_seconds_bucket{route="/health",le="0.1"} 1
http_request_duration_seconds_bucket{route="/health",le="0.5"} 1
http_request_duration_seconds_bucket{route="/orders",le="+Inf"} 3
http_request_duration_seconds_bucket{route="/orders",le="0.01"} 0
http_request_duration_seconds_bucket{route="/orders",le="0.05"} 2
http_request_duration_seconds_bucket{route="/orders",le="0.1"} 2
http_request_duration_seconds_bucket{route="/orders",le="0.5"} 3
http_request_duration_seconds_count{route="/health"} 1
http_request_duration_seconds_count{route="/orders"} 3
http_request_duration_seconds_sum{route="/health"} 0.001
http_request_duration_seconds_sum{route="/orders"} 0.292
http_requests_total{route="/health",status="200"} 1
http_requests_total{route="/orders",status="200"} 2
http_requests_total{route="/orders",status="500"} 1| Type | Meaning | Examples |
|---|---|---|
| Counter | only goes up; graph its rate | requests, errors, bytes sent, retries |
| Gauge | a current value that goes up and down | pool connections in use, queue depth, cache size |
| Histogram | a distribution; gives percentiles | request latency, payload size, batch size |
Configure buckets for latency histograms, as above. Without them this exporter publishes a summary (precomputed quantiles per instance), which can't be aggregated across instances: the average of ten services' p99 is not the fleet's p99. With buckets, Prometheus computes percentiles across the whole fleet with histogram_quantile.
10. What to measure: RED, USE, and the runtime
| Method | For | Metrics |
|---|---|---|
| RED | request-driven services | Rate (requests/s), Errors (failed requests/s), Duration (latency histogram), per route |
| USE | resources (pools, queues, CPUs) | Utilization, Saturation (waiting work), Errors |
| Runtime | the Rust process | Tokio workers, alive tasks, global queue depth (Runtime & Executors), scheduling lag (Async Pitfalls), live heap bytes, RSS |
tower-http's trace layer and crates such as axum-prometheus record RED metrics for every route automatically. The runtime metrics have to be added explicitly.
11. Label cardinality: the metric that takes down your monitoring
Every distinct combination of label values is a separate time series. A label with unbounded values (user ids, request ids, full URLs, error messages) creates millions of series, which is expensive or fatal for Prometheus and costly in hosted systems.
use metrics::counter;
use metrics_exporter_prometheus::PrometheusBuilder;
fn route_template(path: &str) -> &'static str {
// Map concrete paths to their route pattern.
if path.starts_with("/users/") { "/users/{id}" } else if path == "/health" { "/health" } else { "other" }
}
fn main() {
let handle = PrometheusBuilder::new().install_recorder().unwrap();
let paths: Vec<String> = (0..1000).map(|i| format!("/users/{i}")).chain(["/health".to_string()]).collect();
for p in &paths {
counter!("bad_requests_total", "path" => p.clone()).increment(1); // one series per user!
counter!("good_requests_total", "route" => route_template(p)).increment(1); // two series
}
let text = handle.render();
let bad = text.lines().filter(|l| l.starts_with("bad_requests_total{")).count();
let good = text.lines().filter(|l| l.starts_with("good_requests_total{")).count();
println!("series with the raw path label: {bad}");
println!("series with the route label: {good}");
}series with the raw path label: 1001
series with the route label: 2Rules: labels only from small, fixed sets (route template, method, status class, region); ids and free text go into logs and traces, not metric labels.
Part 3: Distributed tracing with OpenTelemetry
12. Exporting spans to OpenTelemetry
In a system of many services, a single request crosses several processes. Distributed tracing stitches their spans into one trace, so you can see that a slow checkout spent most of its time in the pricing service's database query. OpenTelemetry (OTel) is the vendor-neutral standard; Jaeger, Tempo, Honeycomb, Datadog, and most other backends accept it.
With tracing-opentelemetry, every tracing span becomes an OTel span. The application code doesn't change; only the subscriber setup does:
[dependencies]
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter", "json"] }
opentelemetry = "0.33"
opentelemetry_sdk = { version = "0.33", features = ["rt-tokio"] }
opentelemetry-otlp = { version = "0.33", features = ["grpc-tonic"] }
tracing-opentelemetry = "0.34"use opentelemetry::trace::TracerProvider as _;
use opentelemetry_otlp::WithExportConfig;
use opentelemetry_sdk::{Resource, trace::SdkTracerProvider};
use tracing_subscriber::{EnvFilter, prelude::*};
fn init_telemetry() -> SdkTracerProvider {
let exporter = opentelemetry_otlp::SpanExporter::builder()
.with_tonic()
.with_endpoint("http://otel-collector:4317")
.build()
.expect("OTLP exporter");
let provider = SdkTracerProvider::builder()
.with_batch_exporter(exporter) // export in the background, in batches
.with_resource(Resource::builder().with_service_name("checkout").build())
.build();
tracing_subscriber::registry()
.with(EnvFilter::from_default_env())
.with(tracing_subscriber::fmt::layer().json())
.with(tracing_opentelemetry::layer().with_tracer(provider.tracer("checkout")))
.init();
provider
}
#[tokio::main]
async fn main() {
let provider = init_telemetry();
run_service().await;
provider.shutdown().expect("flush spans on exit"); // otherwise the last batch is lost
}With the stdout exporter instead of OTLP, one span from a checkout request looks like this (a real run; ids and times differ every time):
Span #0
Instrumentation Scope
Name : "checkout"
Name : handle_checkout
TraceId : 4bf92f3577b34da6a3ce929d0e0e4736
SpanId : ccf4c76517843421
TraceFlags : TraceFlags(1)
ParentSpanId : 00f067aa0ba902b7
Kind : Internal
Start time : 2026-09-27 23:00:49.473653
End time : 2026-09-27 23:00:49.473813
Status : Unset
Attributes:
-> code.file.path: String(Static("src/main.rs"))
-> code.line.number: I64(19)
-> thread.name: String(Owned("main"))
-> order_id: I64(42)
-> busy_ns: I64(90353)
-> idle_ns: I64(80835)Span fields (order_id) become attributes, and tracing-opentelemetry adds the source location and how long the span was busy versus idle (waiting at .awaits). Most teams send telemetry to a local OpenTelemetry Collector, which batches, samples, and forwards it, so services don't depend on the backend.
13. Propagating trace context between services
A trace spans services only if each outgoing request carries the trace id and the caller's span id, and each service continues from them. The W3C Trace Context standard puts both in a traceparent header: 00-<trace id>-<parent span id>-<flags>. The propagator extracts it from incoming headers and injects it into outgoing ones:
use opentelemetry::propagation::TextMapPropagator;
use opentelemetry::trace::TracerProvider as _;
use opentelemetry_sdk::propagation::TraceContextPropagator;
use opentelemetry_sdk::trace::SdkTracerProvider;
use std::collections::HashMap;
use tracing_opentelemetry::OpenTelemetrySpanExt;
use tracing_subscriber::prelude::*;
fn main() {
let provider = SdkTracerProvider::builder().build();
tracing_subscriber::registry().with(tracing_opentelemetry::layer().with_tracer(provider.tracer("checkout"))).init();
let propagator = TraceContextPropagator::new();
// 1. An incoming HTTP request from the API gateway:
let incoming = HashMap::from([("traceparent".to_string(), "00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01".to_string())]);
// 2. Continue that trace in this service's span.
let span = tracing::info_span!("handle_checkout", order_id = 42);
let _ = span.set_parent(propagator.extract(&incoming));
let _guard = span.enter();
// 3. An outgoing call to the pricing service carries the same trace id, with our span as parent.
let mut outgoing = HashMap::new();
propagator.inject_context(&tracing::Span::current().context(), &mut outgoing);
let header = &outgoing["traceparent"];
let parts: Vec<&str> = header.split('-').collect();
println!("incoming trace id: 4bf92f3577b34da6a3ce929d0e0e4736");
println!("outgoing trace id: {}", parts[1]);
println!("outgoing parent is a new span id: {}", parts[2] != "00f067aa0ba902b7" && parts[2].len() == 16);
println!("sampled flag kept: {}", parts[3] == "01");
}incoming trace id: 4bf92f3577b34da6a3ce929d0e0e4736
outgoing trace id: 4bf92f3577b34da6a3ce929d0e0e4736
outgoing parent is a new span id: true
sampled flag kept: trueIn a real service, HTTP middleware does steps 1–3: an axum/tower layer extracts traceparent for every request, and a reqwest middleware (reqwest-tracing) or a tonic interceptor injects it into outgoing calls. The trace id also belongs in your JSON logs, so a log line links to its trace.
14. Sampling
Recording every span of every request is expensive at high traffic. Traces are sampled: a decision at the start of a trace (keep 10%, keep all errors) that downstream services follow via the sampled flag in traceparent.
| Strategy | Where | Trade-off |
|---|---|---|
Parent-based ratio (Sampler::ParentBased(Box::new(Sampler::TraceIdRatioBased(0.1)))) |
in the service's SDK | cheap, consistent across services; may miss rare errors |
| Tail-based sampling | in the OTel Collector | decides after the trace finishes (keep slow and failed traces); needs Collector resources |
| Always on | development, low-traffic services | complete data, highest cost |
Logs and metrics aren't sampled this way, which is why the three signals complement each other: metrics for "how many", traces for "where did the time go" on a representative set, logs for the details of specific failures.
Part 4: Health and cost
15. Health, readiness, and a metrics endpoint
Orchestrators need two answers: is the process alive (liveness), and should it receive traffic (readiness)? They're different: a service that lost its database connection is alive but not ready. A metrics route belongs next to them. With axum, and tested without opening a socket:
use axum::{Router, extract::State, http::StatusCode, routing::get};
use std::sync::Arc;
use std::sync::atomic::{AtomicBool, Ordering};
use tower::ServiceExt;
#[derive(Clone)]
struct Health {
db_connected: Arc<AtomicBool>,
shutting_down: Arc<AtomicBool>,
}
async fn live() -> StatusCode {
StatusCode::OK // the process runs and the runtime responds
}
async fn ready(State(h): State<Health>) -> (StatusCode, &'static str) {
if h.shutting_down.load(Ordering::Relaxed) {
(StatusCode::SERVICE_UNAVAILABLE, "shutting down")
} else if !h.db_connected.load(Ordering::Relaxed) {
(StatusCode::SERVICE_UNAVAILABLE, "database unavailable")
} else {
(StatusCode::OK, "ready")
}
}
fn app(h: Health) -> Router {
Router::new().route("/livez", get(live)).route("/readyz", get(ready)).with_state(h)
}
async fn probe(router: &Router, path: &str) -> u16 {
let req = axum::http::Request::get(path).body(axum::body::Body::empty()).unwrap();
router.clone().oneshot(req).await.unwrap().status().as_u16()
}
#[tokio::main]
async fn main() {
let h = Health { db_connected: Arc::new(AtomicBool::new(true)), shutting_down: Arc::new(AtomicBool::new(false)) };
let router = app(h.clone());
println!("healthy: live {} ready {}", probe(&router, "/livez").await, probe(&router, "/readyz").await);
h.db_connected.store(false, Ordering::Relaxed);
println!("db down: live {} ready {}", probe(&router, "/livez").await, probe(&router, "/readyz").await);
h.db_connected.store(true, Ordering::Relaxed);
h.shutting_down.store(true, Ordering::Relaxed); // set on SIGTERM, before draining
println!("shutting down: live {} ready {}", probe(&router, "/livez").await, probe(&router, "/readyz").await);
}healthy: live 200 ready 200
db down: live 200 ready 503
shutting down: live 200 ready 503Keep liveness trivial: a liveness check that calls the database gets every instance restarted during a database outage, which makes it worse. Failing readiness during shutdown lets the load balancer stop sending traffic before the drain in Async Pitfalls completes.
16. The cost of telemetry
| Concern | Guidance |
|---|---|
| Disabled log levels | nearly free; don't wrap debug! in if checks |
| Formatting | happens only for enabled events, on the calling thread; keep hot-path events at debug/trace |
| Writing logs | stdout writes can block; use tracing_appender::non_blocking so a slow log pipe doesn't slow requests |
| Spans | creating a span costs little, but a span per item in a tight loop adds up; instrument operations, not iterations |
| Metrics | counters and histograms are atomic updates; label lookups cost more, so hold handles (let c = counter!(...)) in hot paths |
| OTel export | always use the batch exporter; flush on shutdown |
| Sensitive data | skip secrets in #[instrument]; never log tokens, passwords, or full request bodies |
use tracing::info;
fn main() {
// Logs go to a background thread; the guard flushes them when main ends.
let (writer, _guard) = tracing_appender::non_blocking(std::io::stdout());
tracing_subscriber::fmt().with_writer(writer).without_time().with_ansi(false).with_target(false).init();
for batch in 1..=3 {
info!(batch, "processed");
}
} INFO processed batch=1
INFO processed batch=2
INFO processed batch=3Dropping _guard too early (for example with let _ = ...) loses the last log lines at exit, the same way a missing provider.shutdown() loses the last spans.
Summary
- Use
tracingfor logs: structured fields, not formatted strings. Spans carry request context to every event inside them. #[instrument]creates spans from functions;skipsecrets. In async code use#[instrument]or.instrument(), never anenter()guard across.await.- Emit JSON in production, filter with
RUST_LOG/EnvFilter, and record late-known fields withfield::Emptyandrecord. - Layers let one event stream feed logs, metrics, OpenTelemetry, and error trackers.
- Metrics: counters, gauges, and bucketed histograms through the
metricsfacade; RED for services, USE for resources, plus Tokio runtime metrics. Keep label values bounded. - Distributed tracing:
tracing-opentelemetryexports spans over OTLP; propagatetraceparenton every hop; sample deliberately; flush on shutdown. - Separate liveness from readiness, fail readiness during shutdown, and keep telemetry off the hot path's critical costs.
Next: Architecting Rust Services: structuring a larger service and leading a Rust team.
