Mục lục
Mục Tiêu Bài Học
Sau bài học, bạn sẽ:
- Hiểu crate
tracingvs cratelogtrong Rust ecosystem — structured logging native vs string-based message. - Setup
tracing_subscribervới 2 format multi-env: pretty cho dev + JSON cho production. - Áp
tower-http::TraceLayerwire vào router stack Shop API. - Customize trace span với
request_idcorrelation (B39 lock continued) inject từX-Request-Idheader. - Implement log level by status MANDATORY: 2xx/3xx → INFO, 4xx → WARN, 5xx → ERROR thay default TraceLayer cố định.
- JSON log format cho production stack log aggregator (Loki / Grafana / Elasticsearch / Datadog).
- Multi-env config: pretty + debug Local, JSON + info Staging/Production qua
RUST_LOGEnvFilter. - PII sanitize MANDATORY (OWASP A09 Logging Failures) — mask phone / card last 4 + skip password.
tracing Vs log Crate
Rust có 2 crate logging chính, lựa chọn ảnh hưởng đến mọi quyết định observability tương lai. Shop API lock tracing từ B10 và B80 deep dive lý do.
Crate log (legacy, từ Rust 1.0):
- Macro
info!(),warn!(),error!()đơn giản — chỉ message string. - String-based formatting
info!("user {} logged in", id)— log line là plain text. - KHÔNG structured: không có key-value field, log aggregator phải regex parse — fragile khi format đổi.
- KHÔNG context propagation: không có "span" lifecycle scope, log nested call mất ngữ cảnh.
- Backend qua trait
Log— implementation phổ biếnenv_logger,simplelog. - Phù hợp CLI tool nhỏ, script đơn giản.
Crate tracing (modern, tokio ecosystem, recommended):
- Macro
tracing::info!(user_id = %id, action = "login", "user logged in")— structured native, key=value field tách khỏi message. - Span: track lifecycle scope (request, transaction, background job) — nested call tự inherit field span cha.
- Event: emit log point trong span (info!/warn!/error!/debug!/trace!).
- Subscriber: process log (format + filter + output) — pluggable qua
tracing-subscriber. - Async-aware: span tự attach Future qua
.instrument(); tokio task switch không mất ngữ cảnh. - Output đa dạng: pretty colored cho dev, JSON cho production, OpenTelemetry export cho distributed tracing.
Decision lock Shop API: tracing (modern, structured, async-aware) — quyết định từ B10 với tracing = "0.1" + tracing-subscriber = "0.3" trong [workspace.dependencies]. B80 extend feature flag để bật JSON output + EnvFilter.
Workspace dep update shop/Cargo.toml:
[workspace.dependencies]
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter", "json", "fmt"] }
Feature lock:
env-filter:EnvFilterparseRUST_LOGenv per-module level (vdinfo,shop_api=debug,sqlx=warn).json:fmt::layer().json()output JSON Lines cho log aggregator parse native.fmt:fmt::layer().pretty()output colored multi-line cho dev terminal.
tracing_subscriber Setup Multi-Env
Refactor crates/shop-api/src/main.rs thay tracing_subscriber::fmt::init() basic bằng fn init_tracing(env: Environment) branch theo môi trường (B56 Environment enum lock continued).
// File: crates/shop-api/src/main.rs (refactor B80)
use tracing_subscriber::{fmt, prelude::*, EnvFilter};
use shop_api::config::Environment;
fn init_tracing(env: Environment) {
// EnvFilter parse RUST_LOG; fallback per-env default.
let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| match env {
Environment::Local => {
EnvFilter::new("info,shop_api=debug,sqlx=warn,tower_http=debug")
}
Environment::Staging | Environment::Production => {
EnvFilter::new("warn,shop_api=info,sqlx=warn,tower_http=info")
}
});
match env {
Environment::Local => {
// Pretty format dev — colored multi-line, dễ đọc terminal.
tracing_subscriber::registry()
.with(env_filter)
.with(fmt::layer().pretty())
.init();
}
Environment::Staging | Environment::Production => {
// JSON format production — log aggregator parse native.
tracing_subscriber::registry()
.with(env_filter)
.with(
fmt::layer()
.json()
.with_target(true) // module path field "target"
.with_current_span(true) // span hiện tại embed JSON
.with_span_list(false), // span list parent omit (giảm noise)
)
.init();
}
}
}
#[tokio::main]
async fn main() -> anyhow::Result<()> {
dotenvy::dotenv().ok();
let config = shop_api::config::AppConfig::from_env()?;
init_tracing(config.environment);
tracing::info!(
env = ?config.environment,
version = env!("CARGO_PKG_VERSION"),
"starting shop-api"
);
// ... build pool + router + axum::serve (giữ nguyên B57)
Ok(())
}
Pretty format Local — output 1 event:
2026-06-16T10:00:00.123456Z INFO shop_api: starting shop-api
env: Local
version: "0.1.0"
at crates/shop-api/src/main.rs:42
JSON format Production — cùng event:
{"timestamp":"2026-06-16T10:00:00.123456Z","level":"INFO","target":"shop_api","fields":{"message":"starting shop-api","env":"Production","version":"0.1.0"}}
EnvFilter pattern lock qua biến môi trường RUST_LOG:
RUST_LOG=debug— toàn bộ crate level DEBUG.RUST_LOG=info,shop_api=debug— global INFO, crateshop_apiDEBUG.RUST_LOG=info,shop_api=debug,sqlx=warn— thêm cratesqlxchỉ WARN (giảm noise query log).RUST_LOG=info,shop_api[create_order]=debug— chỉ span namecreate_ordertrong crateshop_apiDEBUG.- Khi env var không set → fallback theo môi trường (Local debug, Production info).
Lock decision Shop API:
- Local: pretty +
info,shop_api=debug,sqlx=warn,tower_http=debug— đủ chi tiết debug + ẩn query noise. - Staging: JSON +
warn,shop_api=info,sqlx=warn,tower_http=info— log aggregator + info app code. - Production: JSON +
warn,shop_api=info,sqlx=warn,tower_http=info— same Staging, separate dashboard.
tower-http TraceLayer Setup
tower-http::TraceLayer là middleware tower wrap mỗi HTTP request trong 1 span riêng — mọi log event trong handler/service nested tự inherit span đó kèm method/uri. Default API setup:
use tower_http::trace::{TraceLayer, DefaultOnRequest, DefaultOnResponse, DefaultOnFailure};
use tower_http::LatencyUnit;
use tracing::Level;
// Default TraceLayer — span "request" với method + uri auto.
let trace_layer = TraceLayer::new_for_http()
.on_request(DefaultOnRequest::new().level(Level::INFO))
.on_response(
DefaultOnResponse::new()
.level(Level::INFO)
.latency_unit(LatencyUnit::Millis),
)
.on_failure(DefaultOnFailure::new().level(Level::ERROR));
Default span tạo ra mỗi request:
INFO request{method=POST uri=/api/v1/orders version=HTTP/1.1}: started processing request
INFO request{method=POST uri=/api/v1/orders version=HTTP/1.1}: finished processing request latency=125 ms status=201
Default đủ tốt cho prototype nhưng thiếu 3 điểm Shop API cần:
- KHÔNG có
request_id: correlation cross-service vô dụng — load balancer route 5 instance, log Loki query{request_id="abc-123"}không thấy gì. - Log level cố định:
DefaultOnResponseINFO mọi status — 5xx error rớt vào INFO bucket bị alert filter bỏ qua. - KHÔNG redact sensitive header:
Authorization: Bearer ...hoặcCookie: session=...log raw → leak credentials.
B80 customize tất cả 3 điểm qua make_span_with + closure custom on_request / on_response / on_failure.
Wire layer vào router stack (preview, deep ở Bước 5):
use crate::middleware::trace_layer::custom_trace_layer;
Router::new()
// ... routes
// OUTERMOST 2 — trace layer wrap mọi request, span "request" với request_id field.
.layer(custom_trace_layer())
// OUTERMOST 1 — global RequestBodyLimitLayer 100MB cap (B79 lock continued)
.layer(RequestBodyLimitLayer::new(GLOBAL_BODY_LIMIT))
Lưu ý ordering: trace_layer đặt INNER hơn RequestBodyLimitLayer để 413 reject KHÔNG được log như request bình thường (raw bytes reject sớm trước khi trace span tạo). Pattern lock B76 continued.
Customize Span — request_id Correlation
NEW crates/shop-api/src/middleware/trace_layer.rs — file riêng theo pattern lock B76 (1 file/layer):
// File: crates/shop-api/src/middleware/trace_layer.rs
use axum::body::Body;
use axum::http::{Request, Response};
use std::time::Duration;
use tower_http::classify::ServerErrorsFailureClass;
use tower_http::trace::{MakeSpan, OnFailure, OnRequest, OnResponse, TraceLayer};
use tracing::{Level, Span};
use shop_common::headers::X_REQUEST_ID;
/// Build trace layer Shop API với 4 customize:
/// 1. make_span_with — inject request_id từ X-Request-Id header (B39 continued).
/// 2. on_request — log "started processing" mỗi request.
/// 3. on_response — log "finished processing" với level by status (2xx INFO / 4xx WARN / 5xx ERROR).
/// 4. on_failure — log error chi tiết khi service trả error.
pub fn custom_trace_layer() -> TraceLayer<
tower_http::classify::SharedClassifier<tower_http::classify::ServerErrorsAsFailures>,
ShopMakeSpan,
ShopOnRequest,
ShopOnResponse,
(),
(),
ShopOnFailure,
> {
TraceLayer::new_for_http()
.make_span_with(ShopMakeSpan)
.on_request(ShopOnRequest)
.on_response(ShopOnResponse)
.on_failure(ShopOnFailure)
}
#[derive(Clone)]
pub struct ShopMakeSpan;
impl<B> MakeSpan<B> for ShopMakeSpan {
fn make_span(&mut self, request: &Request<B>) -> Span {
let request_id = request
.headers()
.get(X_REQUEST_ID)
.and_then(|v| v.to_str().ok())
.unwrap_or("-");
tracing::info_span!(
"request",
method = %request.method(),
uri = %request.uri(),
version = ?request.version(),
request_id = %request_id,
)
}
}
ShopOnRequest log entry mỗi request — mức INFO mặc định:
#[derive(Clone)]
pub struct ShopOnRequest;
impl<B> OnRequest<B> for ShopOnRequest {
fn on_request(&mut self, _request: &Request<B>, _span: &Span) {
tracing::info!("started processing request");
}
}
ShopOnResponse — log level by status MANDATORY, lock pattern vĩnh viễn:
#[derive(Clone)]
pub struct ShopOnResponse;
impl<B> OnResponse<B> for ShopOnResponse {
fn on_response(self, response: &Response<B>, latency: Duration, _span: &Span) {
let status = response.status();
let latency_ms = latency.as_millis() as u64;
// Log level by status — MANDATORY Shop API lock.
if status.is_server_error() {
// 5xx — ERROR, alert pipeline kích hoạt.
tracing::error!(
status = status.as_u16(),
latency_ms,
"finished processing request"
);
} else if status.is_client_error() {
// 4xx — WARN, monitor nhưng không alert.
tracing::warn!(
status = status.as_u16(),
latency_ms,
"finished processing request"
);
} else {
// 2xx/3xx — INFO, normal traffic.
tracing::info!(
status = status.as_u16(),
latency_ms,
"finished processing request"
);
}
}
}
ShopOnFailure — log error khi service trả lỗi internal (panic, timeout, IO error trước khi response build xong):
#[derive(Clone)]
pub struct ShopOnFailure;
impl OnFailure<ServerErrorsFailureClass> for ShopOnFailure {
fn on_failure(
&mut self,
failure: ServerErrorsFailureClass,
latency: Duration,
_span: &Span,
) {
tracing::error!(
error = ?failure,
latency_ms = latency.as_millis() as u64,
"request failed"
);
}
}
Update crates/shop-api/src/middleware/mod.rs re-export:
// File: crates/shop-api/src/middleware/mod.rs
pub mod cors;
pub mod enrich_error;
pub mod idempotency;
pub mod rate_limit;
pub mod request_id;
pub mod security_headers;
pub mod trace_layer; // NEW B80
pub use trace_layer::custom_trace_layer;
Lock pattern Shop API:
- Span name:
"request"(1 span per HTTP request). - Field span:
method+uri+version+request_id(KHÔNG body để tránh leak PII). on_request: log "started processing request" INFO.on_response: log "finished processing request" với 3 level rẽ nhánh theo status.on_failure: log error chi tiết khi service trả failure class.
Lock log level by status MANDATORY:
- 2xx/3xx → INFO — normal traffic, retained 7 ngày, không alert.
- 4xx → WARN — client error, retained 14 ngày, monitor dashboard nhưng không page on-call.
- 5xx → ERROR — server error, retained 30 ngày, alert pipeline trigger PagerDuty / Slack.
Module-Level Log Trong Handler
Handler dùng macro tracing::info! với field key=value — log event tự inherit span của TraceLayer (đã set method/uri/request_id) qua context propagation tokio task-local. Pattern lock cho mọi handler Shop API:
// File: crates/shop-api/src/routes/orders.rs (preview B66)
use axum::Extension;
use shop_common::dto::order::{CreateOrderDto, OrderResponseDto};
use shop_common::error::AppError;
use crate::extractors::ValidatedJson;
use crate::middleware::request_id::RequestId;
use crate::responses::Created;
use crate::state::AppState;
use axum::extract::State;
pub async fn create_order(
State(state): State<AppState>,
Extension(_req_id): Extension<RequestId>,
ValidatedJson(dto): ValidatedJson<CreateOrderDto>,
) -> Result<Created<OrderResponseDto>, AppError> {
// Log entry handler — input field summary, KHÔNG full body.
tracing::info!(
user_id = 1, // TODO: từ CurrentUser extractor B116
item_count = dto.items.len(),
payment_type = ?dto.payment.payment_type,
"create order request"
);
// ... business logic gọi service layer
let order = state
.order_service
.create_order(1, dto.items, &dto.payment)
.await?;
// Log success — kết quả + ID, KHÔNG raw DTO.
tracing::info!(
order_id = order.id,
total = %order.total,
"order created successfully"
);
Ok(Created {
location: format!("/api/v1/orders/{}", order.id),
data: OrderResponseDto::from(order),
})
}
Output Local pretty — log 3 event nested trong span request:
2026-06-16T10:00:00.100Z INFO request{method=POST uri=/api/v1/orders version=HTTP/1.1 request_id=abc-123}: started processing request
2026-06-16T10:00:00.105Z INFO request{method=POST uri=/api/v1/orders version=HTTP/1.1 request_id=abc-123}: shop_api::routes::orders: create order request user_id=1 item_count=2 payment_type=Cod
2026-06-16T10:00:00.245Z INFO request{method=POST uri=/api/v1/orders version=HTTP/1.1 request_id=abc-123}: shop_api::routes::orders: order created successfully order_id=42 total=1500000
2026-06-16T10:00:00.250Z INFO request{method=POST uri=/api/v1/orders version=HTTP/1.1 request_id=abc-123}: finished processing request status=201 latency_ms=150
Output Production JSON — handler event auto kèm span context:
{"timestamp":"2026-06-16T10:00:00.105Z","level":"INFO","target":"shop_api::routes::orders","fields":{"message":"create order request","user_id":1,"item_count":2,"payment_type":"Cod"},"span":{"name":"request","method":"POST","uri":"/api/v1/orders","version":"HTTP/1.1","request_id":"abc-123"}}
Lock pattern handler log Shop API:
- Entry handler: 1 event
"<action> request"với input field summary (count, type, ID — KHÔNG full DTO). - Success: 1 event
"<action> successfully"với kết quả ID + tổng giá trị. - Error: không cần log thủ công —
AppError::IntoResponseB16/B48 lock đã log chi tiết qua?bubble.on_responsetrả 4xx/5xx tự log level tương ứng. - Span nested auto inherit: handler
info!()không cần repeatrequest_id— tracing-subscriber tự gắn vào output.
Số event log per request typical: 3 (entry + success + finished) cho happy path; 2 (entry + finished với WARN/ERROR) cho error path.
PII Sanitize Trong Log
OWASP Top 10 2021 mục A09 Security Logging and Monitoring Failures nêu rõ: log raw PII (Personally Identifiable Information) = vi phạm GDPR (EU), CCPA (California), Nghị định 13/2023 (Việt Nam) — phạt tới 4% doanh thu toàn cầu.
Pattern lock Shop API B80 vĩnh viễn — danh sách trường KHÔNG được log raw:
- Password / password_hash: KHÔNG bao giờ log dưới bất kỳ dạng nào.
- Card number: mask
****-****-****-4242(PCI DSS yêu cầu mask, chỉ giữ last 4). - CVV / PIN / OTP: KHÔNG log.
- Phone full: mask
***1234(chỉ giữ last 4). - Email full: pattern lock mask
u***@example.comhoặc logemail_hashSHA-256. - National ID / SSN: mask last 4 hoặc skip.
- JWT / session token: log
jticlaim (token ID) thay full token. - API key / secret: KHÔNG log, sanitize header
Authorizationtrước khi log header map.
Helper mask_phone pattern lock — reuse cho mọi sensitive field:
// File: crates/shop-common/src/sanitize.rs (NEW B80 preview, fully implement G15)
/// Mask phone giữ last 4 ký tự: "0912345678" → "***5678".
pub fn mask_phone(phone: &str) -> String {
if phone.len() <= 4 {
return "****".into();
}
format!("***{}", &phone[phone.len() - 4..])
}
/// Mask card giữ last 4: "4242424242424242" → "****-****-****-4242".
pub fn mask_card(card: &str) -> String {
if card.len() < 4 {
return "****".into();
}
format!("****-****-****-{}", &card[card.len() - 4..])
}
/// Mask email giữ char đầu + domain: "[email protected]" → "u***@example.com".
pub fn mask_email(email: &str) -> String {
match email.split_once('@') {
Some((local, domain)) if local.len() >= 1 => {
format!("{}***@{}", &local[..1], domain)
}
_ => "***@***".into(),
}
}
Apply trong handler:
use shop_common::sanitize::{mask_email, mask_phone};
// ✅ ĐÚNG — mask trước khi log.
tracing::info!(
user_id = user.id,
email = %mask_email(&user.email),
phone = %mask_phone(user.phone.as_str()),
"user registered"
);
// ❌ SAI — log raw PII, vi phạm OWASP A09.
// tracing::info!(email = %user.email, phone = %user.phone, "user registered");
// ❌ SAI — log password dù đã hash.
// tracing::info!(password_hash = %user.password_hash, "...");
Sanitize header sensitive — Shop API TraceLayer KHÔNG log toàn bộ HeaderMap (chỉ method/uri/version) nên tránh được leak Authorization / Cookie tự nhiên. Khi cần log header debug (vd middleware custom), pattern lock skip 4 header:
const SENSITIVE_HEADERS: &[&str] = &[
"authorization",
"cookie",
"set-cookie",
"x-api-key",
];
fn sanitize_headers(headers: &http::HeaderMap) -> Vec<(String, String)> {
headers
.iter()
.map(|(name, value)| {
let key = name.as_str().to_ascii_lowercase();
let val = if SENSITIVE_HEADERS.contains(&key.as_str()) {
"[REDACTED]".to_string()
} else {
value.to_str().unwrap_or("[non-utf8]").to_string()
};
(key, val)
})
.collect()
}
OWASP A09 reference: OWASP Top 10 2021 — A09. Lock pattern Shop API: KHÔNG bao giờ log raw PII; mọi field nhạy cảm phải qua helper mask_*.
Verify Log Output + Multi-Env Test
Khởi động Shop API Local pretty format:
APP_ENV=local RUST_LOG=info,shop_api=debug cargo run -p shop-api
# > 2026-06-16T10:00:00.000Z INFO shop_api: starting shop-api env=Local version="0.1.0"
# > 2026-06-16T10:00:00.050Z INFO shop_api: shop-api listening addr=0.0.0.0:3000
Test 1 — 2xx INFO normal traffic:
curl -i http://localhost:3000/api/v1/products
# > HTTP/1.1 200 OK
# > ...
# Server log:
# INFO request{method=GET uri=/api/v1/products version=HTTP/1.1 request_id=abc-123}: started processing request
# INFO request{...}: shop_api::routes::products: list products request page=1 per_page=20
# INFO request{...}: shop_api::routes::products: list products successfully total=42
# INFO request{...}: finished processing request status=200 latency_ms=18
Test 2 — 4xx WARN client error:
curl -i -X POST http://localhost:3000/api/v1/products \
-H 'Content-Type: application/json' \
-d '{"name":""}'
# > HTTP/1.1 422 Unprocessable Entity
# > {"error":"validation failed","code":"VALIDATION_FAILED",...}
# Server log:
# INFO request{method=POST uri=/api/v1/products request_id=def-456}: started processing request
# WARN request{...}: finished processing request status=422 latency_ms=8
Test 3 — 5xx ERROR server failure:
# Simulate DB down (stop postgres container).
docker stop shop-postgres
curl -i http://localhost:3000/api/v1/products
# > HTTP/1.1 500 Internal Server Error
# > {"error":"internal error","code":"INTERNAL",...}
# Server log:
# INFO request{method=GET uri=/api/v1/products request_id=ghi-789}: started processing request
# ERROR request{...}: shop_common::error: database error: connection refused
# ERROR request{...}: finished processing request status=500 latency_ms=5012
Test 4 — Production JSON format:
APP_ENV=production RUST_LOG=warn,shop_api=info cargo run -p shop-api 2>&1 | head -5
# Output (JSON Lines):
{"timestamp":"2026-06-16T10:00:00.000Z","level":"INFO","target":"shop_api","fields":{"message":"starting shop-api","env":"Production","version":"0.1.0"}}
{"timestamp":"2026-06-16T10:00:00.050Z","level":"INFO","target":"shop_api","fields":{"message":"shop-api listening","addr":"0.0.0.0:3000"}}
{"timestamp":"2026-06-16T10:00:05.123Z","level":"INFO","target":"tower_http::trace::on_request","fields":{"message":"started processing request"},"span":{"name":"request","method":"GET","uri":"/api/v1/products","version":"HTTP/1.1","request_id":"abc-123"}}
{"timestamp":"2026-06-16T10:00:05.141Z","level":"INFO","target":"tower_http::trace::on_response","fields":{"message":"finished processing request","status":200,"latency_ms":18},"span":{"name":"request","method":"GET","uri":"/api/v1/products","version":"HTTP/1.1","request_id":"abc-123"}}
Verify log aggregator integration:
- Loki + Grafana: scrape stdout container qua Promtail; query LogQL
{app="shop-api"} | json | request_id="abc-123"trace 1 request cross-instance. - Elasticsearch: Filebeat ship JSON lines; Kibana visualize
level:ERROR AND status:>=500. - Datadog: agent auto-detect JSON format;
service:shop-api status:errortrigger monitor. - Honeycomb:
trace.trace_idauto-correlate khi G15 wire OpenTelemetry.
Span nested verify: query Loki {request_id="abc-123"} trả 3 event (entry handler + finished + nested debug) — đủ context debug 1 request mà không cần cross-reference.
Tổng Kết
- Crate
tracingmodern structured logging — field key=value + span lifecycle, replacelogcrate string-based. tracing-subscriber2 format multi-env: pretty cho Local dev colored multi-line, JSON cho Staging/Production log aggregator parse native.EnvFiltercontrol level per-module quaRUST_LOG— pattern lockinfo,shop_api=debug,sqlx=warn,tower_http=debugLocal;warn,shop_api=infoProduction.tower-http::TraceLayerwrap mọi request — auto span generate với method/uri/version.make_span_withcustomize: injectrequest_idtừX-Request-Idheader (B39 continued) — correlation cross-service MANDATORY.on_request/on_response/on_failureba lifecycle hook custom — full control log point per request.- Log level by status MANDATORY: 2xx/3xx INFO (normal), 4xx WARN (client error monitor), 5xx ERROR (server error alert pipeline).
- Handler log pattern: entry event (input field summary) + success (result + ID) + error (delegate
AppError::IntoResponseB16/B48). - Span nested auto inherit: handler
tracing::info!()tự kèmrequest_idspan TraceLayer — không cần repeat field. - PII sanitize MANDATORY: mask phone / card / email part, skip password / CVV / OTP / JWT / API key.
- OWASP A09 prevention: KHÔNG bao giờ log raw PII — vi phạm GDPR / CCPA / Nghị định 13.
- Helper
mask_phone/mask_card/mask_emailpattern lock reuse cho mọi sensitive field — fileshop-common::sanitize. - Multi-env config: pretty + debug Local, JSON + info Staging/Production qua
fn init_tracing(env: Environment)match branch. - Log aggregator support: Loki / Grafana / Elasticsearch / Datadog / Honeycomb parse JSON Lines native — không cần regex parse fragile.
- File path lock: NEW
crates/shop-api/src/middleware/trace_layer.rs; extendcrates/shop-api/src/main.rs::init_tracing; re-exportmiddleware/mod.rs. - Middleware stack giờ 8 layer (7 cũ B79 + trace_layer mới B80).
- Foundation cho B81 (metrics Prometheus middleware refactor B57), G15 OpenTelemetry distributed tracing cross-service.
Bài Tập Củng Cố
Tự trả lời, đáp án ở cuối:
tracingvslogcrate — phân biệt structured logging vs string-based. Pros/cons mỗi crate? Tại sao Shop API locktracingtừ B10?tracing_subscriber::EnvFilter+RUST_LOG— patterninfo,shop_api=debug,sqlx=warn. Cho ví dụ filter per-module scenario thực tế debug 1 endpoint mà không bị noise sqlx query.make_span_withcustomize TraceLayer — tại sao MANDATORY injectrequest_id? B39 correlation pattern hoạt động ra sao cross-service?- Log level by status — 4xx WARN vs 5xx ERROR. Cho ví dụ scenario log filter
level>=ERRORcho alert pipeline; tại sao 4xx KHÔNG nên ERROR? - PII sanitize log — OWASP A09. Cho ví dụ scenario raw log password / phone → exploit GDPR violation; pattern
mask_*helper lock Shop API.
Đáp án
tracingvslogcrate: Cratelog(legacy từ Rust 1.0) — macroinfo!("user {} logged in", id)string-based interpolation tại compile time → log line plain text dạng"INFO user 42 logged in". Pros: đơn giản học 5 phút, API stable 10 năm, dep nhẹ, phù hợp CLI tool/script không cần observability. Cons: KHÔNG structured (log aggregator phải regex parse fragile khi format đổi vd thêm field giữa câu), KHÔNG span context (log nested call mất ngữ cảnh — handler gọi service A gọi service B, log của B không biết thuộc request nào), KHÔNG async-aware (tokio task switch mất TLS context), backend dynamic dispatch overhead khi log volume cao. Cratetracing(modern, tokio ecosystem 2019+) — macrotracing::info!(user_id = %id, action = "login", "user logged in")field key=value tách khỏi message → output structured JSON{"level":"INFO","msg":"user logged in","user_id":42,"action":"login"}. Pros: structured native (log aggregator parse JSON 1 lệnh không regex), span lifecycle scope cho request/transaction/job — nested call tự inherit field cha qua tokio task-local storage, async-aware (.instrument()attach Future tracking cross await point), pluggable subscriber (pretty dev, JSON prod, OTel export distributed tracing G15, custom subscriber for sampling/aggregation), Level enum 5 mức (TRACE/DEBUG/INFO/WARN/ERROR) per-module filter qua EnvFilter. Cons: API học 1-2 ngày (span/event/subscriber concept), dep nặng hơn (tracing-subscriber+ feature flag), overhead nhỉnh hơnlog~5% benchmark (negligible production). Tại sao Shop API locktracingtừ B10: (a) production web API MUST structured log cho log aggregator parse (Loki/ES/Datadog),logstring-based fragile khi schema log đổi; (b) request scope span foundation cho B39 request_id correlation cross-service; (c) tokio ecosystem alignment — sqlx/axum/tower-http/tonic đều tracing native, dùnglogphải bridge quatracing-logdouble overhead; (d) future-proof G15 OpenTelemetry export — tracing cótracing-opentelemetrybridge sẵn,logkhông có path; (e) async-aware MANDATORY khi handler gọi 5-10 service await point —logmất ngữ cảnh ở mỗi await. Lock B10 vĩnh viễn: workspace deptracing = "0.1"+tracing-subscriber = "0.3"; KHÔNG dùnglogtrực tiếp; nếu dep transitively dùnglog(vdhyper) thì bridge quatracing-log::LogTracer::init()route log event qua tracing subscriber.EnvFilter+RUST_LOGper-module pattern:EnvFilterparse string format"<level>,<target>=<level>,..."— global level mặc định + override per-crate/module/span. Cú pháp:info,shop_api=debug,sqlx=warn= global INFO, crateshop_apiDEBUG, cratesqlxWARN. Granularity sâu hơn:shop_api::routes::orders=tracechỉ moduleorders.rsTRACE;shop_api[create_order]=debugchỉ span namecreate_orderDEBUG. Scenario thực tế debug 1 endpoint: dev đang điều tra bugPOST /api/v1/orderstrả 422 mà DTO valid; cần xem chi tiết deserialize step + validate step nhưng KHÔNG muốn 1000 dòng sqlx query log noise mỗi request. SetRUST_LOG=info,shop_api::routes::orders=trace,shop_api::extractors=trace,sqlx=warn,tower_http=info→ output: chỉ 2 module liên quan TRACE (route orders + extractors), sqlx WARN (chỉ slow query / error), tower_http INFO (trace layer entry/exit). Filter granularity giúp signal-to-noise ratio cao 100x so vớiRUST_LOG=traceflat. Pattern lock Shop API: Local defaultinfo,shop_api=debug,sqlx=warn,tower_http=debug— đủ debug app code + ẩn query verbose; Production defaultwarn,shop_api=info,sqlx=warn,tower_http=info— giảm log volume tiết kiệm storage aggregator (1 request = 4 event INFO thay 20 event DEBUG); incident on-call temporary setRUST_LOG=info,shop_api=debugqua env var không cần redeploy. Hot-reload: B80 implement initial config; G15 deploy thêmtracing-subscriber::reload::Layer+ admin endpointPATCH /admin/log-levelđổi level runtime không restart instance — pattern Netflix/Spotify production. EnvFilter directive precedence: directive cụ thể hơn thắng —shop_api::routes::orders=traceoverrideshop_api=debugoverrideinfoglobal. Test directive:EnvFilter::try_new(directive).is_ok()validate trước khi apply tránh typo silent break log.make_span_withcustomize TraceLayer + request_id MANDATORY: defaultTraceLayer::new_for_http()tạo span"request"với 3 field automethod/uri/version— đủ minimal cho 1-instance dev nhưng production multi-instance 10+ pod sau load balancer thì 1 request rớt vào 1 pod random, log Loki query{app="shop-api"} method="POST" uri="/api/v1/orders"trả về hàng nghìn match cùng giờ — không thể isolate 1 request bug user báo. Patternrequest_idcorrelation B39 lock: middlewarerequest_id_middleware(B39) đọc headerX-Request-Idclient gửi hoặc generate UUID v4 mới nếu absent → inject vàoExtension<RequestId>+ set response headerX-Request-Idecho về client. Client log error kèmX-Request-Idtừ response header → support engineer query log aggregator{request_id="abc-123-def"}trả CHÍNH XÁC log của 1 request đó cross-instance.make_span_withtrong B80 implementShopMakeSpanđọcrequest.headers().get(X_REQUEST_ID)trước khi handler chạy (middlewarerequest_idđã set header trước layer trace nhờ ordering INNER hơn) → inject fieldrequest_id = %request_idvào spaninfo_span!("request", ..., request_id = %request_id)→ mọi event nested trong handler (info!/warn!/error!) tự inherit field qua span context propagation. Cross-service correlation: Shop API gọi service Stripe / S3 / Redis pubsub → forward headerX-Request-Idqua reqwest client; service downstream log cùngrequest_id→ query Loki across service trả full distributed trace 1 lệnh. Foundation OpenTelemetry G15:request_id=trace_idOTel standard; B80 inject manual qua header, G15 wiretracing-opentelemetryauto-propagate quatraceparentW3C header thayX-Request-Idcustom. Nếu KHÔNG có request_id: debug 1 user complain "order create fail 30 phút trước" — engineer query log không có anchor, scan thủ công 50K event cùng timeframe, tốn 30-60 phút thay 30 giây với request_id. Pattern industry: AWS X-Ray, GCP Trace, Honeycomb đều require trace_id MANDATORY mọi event. Lock Shop API B39 + B80: mọi log event MUST có request_id field; missing = bug middleware ordering.- Log level by status — 4xx WARN vs 5xx ERROR: 4xx Client Error (400/401/403/404/409/422/429) = lỗi client (bad input, missing auth, conflict business rule) — KHÔNG phải lỗi server, NGƯỜI DÙNG hoặc client SDK gửi sai. Volume cao bình thường: 5-15% traffic 422 validation fail từ form người dùng nhập sai, 1-3% 401 token expire chờ refresh, 0.5% 404 link cũ bookmark. Log INFO sẽ chìm trong noise traffic 2xx; log ERROR sẽ trigger PagerDuty page on-call mỗi 5 phút 24/7 (alert fatigue → engineer disable alert hoặc nghỉ việc). Lock WARN: 4xx event vẫn vào log aggregator để dashboard monitor trend (vd spike 401 = JWT key rotation lỗi, spike 422 = bug client SDK release mới), retain 14 ngày, KHÔNG page on-call. 5xx Server Error (500/502/503/504) = lỗi server thực sự (DB down, panic Rust, timeout upstream, OOM) — RARE bình thường < 0.1% traffic; mọi 5xx MUST investigate. Lock ERROR: trigger alert pipeline (PagerDuty/OpsGenie/Slack) ngay khi rate > 0.5% sustained 5 phút; retain 30 ngày cho post-mortem; engineer on-call page 2 AM nếu cần. Scenario alert pipeline: Grafana alert rule
sum(rate({app="shop-api"} | json | level="ERROR" | status>=500 [5m])) by (status) > 0.1= nếu > 0.1 event ERROR/sec sustained 5 min → trigger PagerDuty severity P2;status=500+error="connection pool exhausted"trigger runbook auto-restart pool. Tại sao 4xx KHÔNG ERROR: (a) volume — 100 req/s × 10% 4xx = 10 event/s ERROR fake → alert pipeline overload, on-call burnout; (b) signal — 4xx là expected behavior contract API design (validation fail = expected khi user input sai), KHÔNG phải bug; (c) liability — 4xx do client gửi sai, KHÔNG phải bug Shop API → log WARN đủ trace mà không page; (d) cost — Datadog/ES storage tính theo level ERROR cao gấp 5x INFO/WARN, log 4xx ERROR tăng bill 5x không lợi ích. Edge case 4xx → ERROR upgrade: 429 spike đột biến (DDoS) trigger ERROR temporary + alert; 401 spike đột biến (auth service down) trigger ERROR. Pattern lock Shop API B80: mặc định 4xx WARN; G19 thêm rate-based alert escalate WARN → ERROR khi anomaly detect. - PII sanitize log + OWASP A09: A09 Security Logging and Monitoring Failures = 1 trong Top 10 web security risk 2021 OWASP; bao gồm 2 mặt: (1) KHÔNG đủ log (security event không track → forensic incident không truy được); (2) log SAI cách (PII raw → vi phạm privacy law + data breach exposed). Mặt 2 là focus B80. Scenario raw log password exploit: dev junior log
tracing::info!(email = %dto.email, password = %dto.password, "login attempt")debug auth flow — code merge production; mọi login event ghi password plaintext vào log aggregator (Datadog retain 30 ngày, 100M event); 6 tháng sau employee bị social-engineered cung cấp Datadog credential cho attacker; attacker query{app="shop-api"} | json | password!=""trả 100M password user kèm email → mass account takeover; Shop bị GDPR phạt 4% revenue (€20M cho công ty €500M), CCPA class action lawsuit $750/user × 100M = $75B liability, reputation damage permanent. Scenario raw log phone full: logphone = %user.phone"0912345678" +address = %user.address"123 Nguyễn Trãi Hà Nội" → log aggregator search bằng phone trả full profile user + order history + payment history → SIM swap attack (đổi SIM nhà mạng giả mạo ID) + stalking + phishing target. Patternmask_*helper lock B80: filecrates/shop-common/src/sanitize.rschứa 3 function:mask_phone(s)giữ last 4 → "***5678",mask_card(s)giữ last 4 → "****-****-****-4242" (PCI DSS yêu cầu),mask_email(s)giữ char đầu + domain → "u***@example.com". Helper pattern:if s.len() <= 4 return "****"defensive nhỏ;format!("***{}", &s[s.len()-4..])last 4 char. Pattern lock Shop API vĩnh viễn: (a) KHÔNG bao giờ log raw password / password_hash / CVV / PIN / OTP / JWT raw / API key / secret — strict skip; (b) phone / card / national ID mask last 4; (c) email mask local part trừ char đầu; (d) full name mask first name + last name initial "Nguyễn V*** A***"; (e) address mask street + giữ city — "*** Hà Nội"; (f) IP address mask last octet "192.168.1.***"; (g) DOB mask day + month "1990-**-**"; (h) sensitive headerAuthorization/Cookie/X-API-Keyredact "[REDACTED]" trước khi log header map. Enforce: code review checklist + clippy lint customshop_clippy::raw_pii_in_loggrep regextracing::(info|warn|error|debug)!.*(password|phone|email|card)warn dev; G19 thêm Vector/Fluent Bit redaction layer drop-in defense in depth: stream log qua sidecar regex replace"password":"[^"]+"→"password":"[REDACTED]"trước khi ship aggregator (nếu dev quên mask trong code thì sidecar catch). Lock B80 + G19: 2 layer defense (app-level mask + infra-level redaction). Compliance: GDPR Article 32 (data protection by design), PCI DSS Requirement 3 (cardholder data protection), HIPAA §164.312 (audit log encryption), Nghị định 13/2023 Điều 7 (bảo vệ dữ liệu cá nhân).
Bài Tiếp Theo
Bài 81: Metrics Prometheus Middleware Sâu — refactor /metrics endpoint B57 với crate metrics + metrics-exporter-prometheus, expose 4 metric type (counter / gauge / histogram / summary), HTTP request metrics middleware track request_count + response_time_histogram + error_rate per route, Prometheus scrape config + Grafana dashboard preview.
