// 心智模型对比：log crate 与 tracing 的差别在哪 // 老办法：把上下文拼进字符串，然后想按 user_id 过滤日志 —— 做不到 // log::info!("用户 {} 下单成功，订单 {}", user_id, order_id); // tracing 的写法：上下文是字段，而不是字符串的一部分 use tracing::{info, instrument, warn}; #[instrument(skip(db), fields(user_id = %user_id))] async fn create_order(user_id: i64, db: &sqlx::PgPool) -> anyhow::Result<i64> { // 这个 event 会自动带上 user_id 字段（因为它在当前 span 上） // 也不会打印 db 参数（被 skip 掉了） info!("开始创建订单"); let id: i64 = sqlx::query_scalar("INSERT INTO orders(user_id) VALUES($1) RETURNING id") .bind(user_id).fetch_one(db).await?; // 结构化字段用 key = value 的形式，值是"字段"而不是字符串片段 info!(order_id = id, "订单创建成功"); Ok(id) } // 好处一：日志可以按字段查询 —— 在 Loki/ES 里搜 user_id=42 就能捞出这个用户的所有操作 // 好处二：span 会变成一个"上下文容器"，函数内部所有日志自动继承 user_id // 好处三：同一份 span 可以同时导出成 trace（给 Jaeger）和日志（给 stdout）

[dependencies] tracing = "0.1" # json feature 让日志以 JSON 行输出，便于 Loki/ES 采集 tracing-subscriber = { version = "0.3", features = ["env-filter", "json", "fmt"] } tracing-opentelemetry = "0.29" opentelemetry = "0.29" opentelemetry_sdk = { version = "0.29", features = ["rt-tokio"] } opentelemetry-otlp = { version = "0.29", features = ["grpc-tonic"] } # 提醒：opentelemetry 系列 crate 的 API 在 0.2x 小版本之间会有调整， # 升级时请以该版本 docs.rs 上的示例为准；但 tracing 那侧的用法是稳定的

use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter}; pub fn init_tracing(json: bool) { // EnvFilter 从 RUST_LOG 读取；解析失败时给一个安全的默认值 // 默认值建议"全局 info，本 crate debug"，避免第三方库刷屏 let filter = EnvFilter::try_from_default_env() .unwrap_or_else(|_| EnvFilter::new("info,my_crate=debug,sqlx=warn,hyper=warn")); if json { // 生产：一行一个 JSON 对象，字段独立可查询 let layer = fmt::layer() .json() // 把 span 的字段也打进每条日志，否则 JSON 日志里看不到 user_id .with_current_span(true) // 同时带上父 span 的字段（嵌套场景必需） .with_span_list(true) // 时间戳统一成 RFC3339，跨时区对齐时不会抓瞎 .with_timer(fmt::time::UtcTime::rfc_3339()); tracing_subscriber::registry().with(filter).with(layer).init(); } else { // 开发：带颜色和缩进的层叠展示，看 span 嵌套关系最直观 let layer = fmt::layer().with_target(true).with_level(true).pretty(); tracing_subscriber::registry().with(filter).with(layer).init(); } } // main.rs 最开头就调用，别等连接数据库之后再初始化（会丢掉启动期的日志） // init_tracing(std::env::var("LOG_JSON").is_ok());

# 只调本项目的某个模块，其余保持 warn（线上临时排障最常用） RUST_LOG=warn,my_crate::api::orders=debug ./order-api # 全局 debug，但把最吵的几个库压到 error RUST_LOG=debug,sqlx=error,hyper=error,reqwest=error ./order-api # 打开 SQLx 的语句日志（能看到实际执行的 SQL 与绑定参数，排查慢查询利器） RUST_LOG=info,sqlx::query=debug ./order-api # 拿到一个 trace 的全部细节（配合 trace_id 过滤，见下一节） RUST_LOG=info ./order-api 2>&1 | jq 'select(.trace_id=="4bf92f3577b34da6a3ce929d0e0e4736")'

use tracing::{instrument, Span}; // 危险：默认会把 req 和 db 都记进 span 字段 // req 是一个几百字段的结构体，db 是连接池（Debug 输出巨大） // 结果：每条日志都要格式化一遍这些对象，CPU 白烧，日志里全是噪音 #[instrument] async fn bad_handler(req: CreateOrderReq, db: &sqlx::PgPool) { /* ... */ } // 正确：skip 掉不该记录的值，只挑真正有用的字段 #[instrument( // name 控制 span 名字（默认是函数名），跨 crate 排查时统一命名很有用 name = "http.create_order", // skip 大对象：连接池、请求体、大数组、任何 Debug 输出很长的东西 skip(db, req), // fields 精确说明要记哪些字段；% 是 Display，? 是 Debug fields(user_id = %user_id, item_count = req.items.len()), // level 指定 span 级别，配合 EnvFilter 可以整体关掉这类 span level = "info", // ret 记录返回值（要 Debug）；err 记录错误（要 Display） err, )] async fn create_order( user_id: i64, req: CreateOrderReq, db: &sqlx::PgPool, ) -> anyhow::Result<i64> { /* ... */ } // 不想用宏时，手动写 span（更灵活，适合"只想包一段代码"的场景） let span = tracing::info_span!("db.query", sql = %sql_preview, rows = tracing::field::Empty); let _guard = span.enter(); // 同步代码用 enter() // 异步代码里【不要】跨 .await 持有 _guard，见下面的坑

// 调用链：handle_request -> create_order -> reserve_stock -> db.query // 每一层的日志都会带上自己这一层以及所有祖先 span 的字段 #[instrument(name = "http.request", skip(state), fields(trace_id = %trace_id))] async fn handle_request(state: axum::extract::State<AppState>, trace_id: String) { // 这里 info! 会带上 trace_id tracing::info!("收到请求"); create_order(42).await; // 子 span 自动挂在当前 span 下面 } #[instrument(name = "order.create")] async fn create_order(user_id: i64) { // 这行日志同时带 user_id（本层）与 trace_id（祖先层） tracing::info!("创建订单"); reserve_stock(user_id).await; } // 把 span 句柄"塞"进异步任务：spawn 出来的任务不会继承父 span，必须手动带 let span = tracing::Span::current(); // 拿到当前 span tokio::spawn(async move { // enter / in_scope / instrument 三选一，异步任务里推荐 instrument let _enter = span.enter(); do_background_work().await; }); // 更好的写法：让 future 自己带着 span 上下文（不会因为跨 await 而丢失） // tokio::spawn(do_background_work().instrument(tracing::Span::current()));

use axum::{extract::Request, middleware::Next, response::Response}; use tracing::info_span; use tracing_opentelemetry::OpenTelemetrySpanExt; /// 从入站请求头提取 trace 上下文，创建 root span，并把 trace_id 暴露出来 pub async fn trace_middleware(mut req: Request, next: Next) -> Response { // 1) 优先用上游传来的 traceparent（W3C 标准头），没有就生成一个新的 let trace_id = req .headers() .get("traceparent") .and_then(|v| v.to_str().ok()) // traceparent 格式：00-<trace_id>-<span_id>-01，第 2 段就是 trace_id .and_then(|v| v.split('-').nth(1).map(|s| s.to_string())) .unwrap_or_else(|| uuid::Uuid::new_v4().simple().to_string()); // 2) 建 root span，把 HTTP 元信息与 trace_id 都放进字段 let span = info_span!( "http.request", // otel.name / otel.kind 是两个约定字段，OTel 后端会读它们 otel.name = %format!("{} {}", req.method(), req.uri().path()), http.method = %req.method(), http.route = %req.uri().path(), // trace_id 是自定义字段，可以按它直接过滤日志 trace_id = %trace_id, // 生产里通常交给 OTel propagator 生成/续接，这里手写是为了讲清原理 user_agent = %req.headers().get("user-agent").and_then(|v| v.to_str().ok()).unwrap_or("-"), ); // 3) 用 instrument 把 span 挂到请求处理链上（不要用 enter） use tracing::Instrument; let resp = next.run(req).instrument(span).await; // 4) 把状态码补进 span：span 已经结束就不能再写字段，所以用事件补 tracing::info!(status = resp.status().as_u16(), "请求处理完成"); resp } // 装配：middleware::from_fn 包在最外层，保证连 404 也进 trace let app = axum::Router::new() .route("/api/orders", axum::routing::post(create_order)) .layer(axum::middleware::from_fn(trace_middleware));

use tracing_opentelemetry::OpenTelemetrySpanExt; pub async fn call_inventory(http: &reqwest::Client, sku: &str) -> anyhow::Result<Stock> { // 从当前 span 里取出 OTel 上下文，注入到 HTTP 头 let cx = tracing::Span::current().context(); let mut headers = reqwest::header::HeaderMap::new(); opentelemetry::global::get_text_map_propagator(|p| { // 全局 propagator 默认是 W3C TraceContext，会写出 traceparent 头 p.inject_context(&cx, &mut HeaderInjector(&mut headers)); }); // 给这次出站调用建一个子 span，Jaeger 里就能看到"HTTP 调用"这一段耗时 let span = tracing::info_span!("http.client", peer = "inventory", endpoint = %"/stock"); let resp = http .get(format!("{}/stock?sku={sku}", INVENTORY_URL)) .headers(headers) .send() .instrument(span) .await? .error_for_status()?; Ok(resp.json().await?) } // 一个最小的 HeaderInjector：把 OTel 的 Injector trait 适配到 reqwest 的 HeaderMap struct HeaderInjector<'a>(&'a mut reqwest::header::HeaderMap); impl<'a> opentelemetry::propagation::Injector for HeaderInjector<'a> { fn set(&mut self, key: &str, value: String) { if let Ok(v) = reqwest::header::HeaderValue::from_str(&value) { if let Ok(name) = reqwest::header::HeaderName::from_bytes(key.as_bytes()) { // SAFETY 说明：这里不是 unsafe，只是借用检查的常规处理 self.0.insert(name, v); } } } }

use opentelemetry::{trace::TracerProvider as _, KeyValue}; use opentelemetry_otlp::WithExportConfig; use opentelemetry_sdk::{trace::SdkTracerProvider, Resource}; use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, EnvFilter}; pub fn init_telemetry(service_name: &'static str, otlp_endpoint: &str) -> anyhow::Result<SdkTracerProvider> { // 1) 建 exporter：批量发送到 OTLP gRPC 端点（Jaeger 默认 4317） let exporter = opentelemetry_otlp::SpanExporter::builder() .with_tonic() .with_endpoint(otlp_endpoint) // 如 http://tempo:4317 .with_timeout(std::time::Duration::from_secs(5)) .build()?; // 2) Resource 描述"这条 trace 来自哪个服务、哪个版本、哪个实例" // 没有它，Jaeger 里全是 "unknown_service"，多服务时无法区分 let resource = Resource::builder() .with_service_name(service_name) .with_attributes([ KeyValue::new("service.version", env!("CARGO_PKG_VERSION")), KeyValue::new("deployment.environment", std::env::var("ENV").unwrap_or_else(|_| "dev".into())), KeyValue::new("service.instance.id", uuid::Uuid::new_v4().to_string()), ]) .build(); // 3) Provider：批量导出 + 采样策略 let provider = SdkTracerProvider::builder() // batch 会攒一批再发，比 simple（每条都发）高效得多； // 但进程退出前必须 shutdown()，否则缓冲区里的 span 全丢 .with_batch_exporter(exporter) .with_resource(resource) // 采样：高 QPS 服务不可能 100% 上报，通常 10%~20% 或按错误优先采样 .with_sampler(opentelemetry_sdk::trace::Sampler::ParentBased(Box::new( opentelemetry_sdk::trace::Sampler::TraceIdRatioBased(0.1), ))) .build(); // 4) 把 OTel layer 叠加到 tracing subscriber 上 // 注意顺序：fmt 放前面（日志优先输出），otel 放后面 let tracer = provider.tracer(service_name); tracing_subscriber::registry() .with(EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info,my_crate=debug"))) .with(tracing_subscriber::fmt::layer().json().with_current_span(true)) .with(tracing_opentelemetry::layer().with_tracer(tracer)) .init(); // 设置全局 propagator：跨服务传递用 W3C TraceContext 标准 opentelemetry::global::set_text_map_propagator( opentelemetry_sdk::propagation::TraceContextPropagator::new(), ); Ok(provider) }

# docker-compose.yml services: jaeger: image: jaegertracing/all-in-one:latest ports: - "16686:16686" # UI - "4317:4317" # OTLP gRPC - "4318:4318" # OTLP HTTP # 启动应用并指向 Jaeger OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317 ./order-api # 打开 http://localhost:16686 就能按 service 名搜 trace # 用环境变量切换后端（代码不用改，这是 OTLP 标准化的价值） # Tempo： OTEL_EXPORTER_OTLP_ENDPOINT=http://tempo:4317 # Datadog： OTEL_EXPORTER_OTLP_ENDPOINT=http://datadog-agent:4317

// 方案 A：metrics crate + Prometheus exporter（轻量、生态广、和 tracing 解耦） use metrics::{counter, gauge, histogram}; fn record_http(route: &str, status: u16, elapsed: std::time::Duration) { // 维度尽量少：route + status 就够了，加上 user_id 会让时间序列爆炸 counter!("http_requests_total", "route" => route.to_string(), "status" => status.to_string()).increment(1); histogram!("http_request_duration_seconds", "route" => route.to_string()).record(elapsed.as_secs_f64()); } // 初始化：把 Prometheus recorder 装成全局，然后暴露 /metrics 端点 // use metrics_exporter_prometheus::PrometheusBuilder; // let handle = PrometheusBuilder::new().install_recorder()?; // .route("/metrics", get(move || async move { handle.render() })) // 方案 B：OTel metrics —— 和 trace 共用一套 SDK 与导出通道 // let meter = provider.meter("order-api"); // let counter = meter.u64_counter("http_requests_total").build(); // counter.add(1, &[KeyValue::new("route", route.to_string())]);

use axum::{extract::State, http::StatusCode, Json}; /// 存活探针：只回答"进程还活着吗"，【不要】检查下游依赖 // 如果这里查数据库，数据库抖一下 K8s 就会杀掉所有 Pod，雪崩 async fn healthz() -> StatusCode { StatusCode::OK } /// 就绪探针：回答"现在能接流量吗"，【要】检查关键依赖，但必须带超时 async fn readyz(State(state): State<AppState>) -> (StatusCode, Json<serde_json::Value>) { // 关键：给依赖检查加超时，否则依赖卡住会让探针也卡住 → 被判定不健康 let db_ok = tokio::time::timeout( std::time::Duration::from_millis(500), sqlx::query_scalar::<i32>("SELECT 1").fetch_one(&state.db), ) .await .map(|r| r.is_ok()) .unwrap_or(false); let redis_ok = tokio::time::timeout( std::time::Duration::from_millis(300), redis::cmd("PING").query_async::<String>(&mut state.redis.clone()), ) .await .map(|r| r.is_ok()) .unwrap_or(false); let status = if db_ok && redis_ok { StatusCode::OK } else { StatusCode::SERVICE_UNAVAILABLE }; (status, Json(serde_json::json!({ "db": db_ok, "redis": redis_ok }))) }

use opentelemetry_sdk::trace::SdkTracerProvider; /// 等一个"该下班了"的信号：Ctrl+C 或 SIGTERM（K8s 滚动更新发的是 SIGTERM） async fn shutdown_signal() { let ctrl_c = async { tokio::signal::ctrl_c().await.expect("注册 Ctrl+C 失败"); tracing::info!("收到 Ctrl+C"); }; // K8s 删除 Pod / docker stop 发的是 SIGTERM，必须单独处理 let terminate = async { tokio::signal::unix::signal(tokio::signal::unix::SignalKind::terminate()) .expect("注册 SIGTERM 失败") .recv() .await; tracing::info!("收到 SIGTERM"); }; tokio::select! { _ = ctrl_c => {}, _ = terminate => {}, } } pub async fn serve(app: axum::Router, addr: std::net::SocketAddr) -> anyhow::Result<()> { let provider: SdkTracerProvider = init_telemetry("order-api", &otlp_endpoint())?; let listener = tokio::net::TcpListener::bind(addr).await?; tracing::info!(%addr, "服务已启动"); // with_graceful_shutdown：收到信号后不再接受新连接，并等待在途请求跑完 axum::serve(listener, app) .with_graceful_shutdown(shutdown_signal()) .await?; // 关键一步：把缓冲区里的 span 和 metric 冲出去 // 忘了这行，最后 5 秒的 trace 全部丢失 —— 而"正在关停时的异常"恰恰最值得看 provider.shutdown()?; tracing::info!("已优雅退出"); Ok(()) } // K8s 侧要配合的配置（这段是 deployment.yaml，不是 Rust 代码） // terminationGracePeriodSeconds: 30 # 给在途请求留足时间，要大于最长请求耗时 // preStop: ["/bin/sh", "-c", "sleep 5"] # 等 Service 从 Endpoints 摘掉再开始停 // 顺序很重要：先摘流量、再发 SIGTERM，否则新请求会打到正在关闭的 Pod 上