11 KiB
classDiagram
class LogLevel {
<<enumeration>>
DEBUG
INFO
WARNING
ERROR
FATAL
}
class LogRecord {
+DateTime timestamp
+LogLevel level
+String message
+String target
}
class LogOutput {
<<interface>>
+write(record: LogRecord) Future
}
class ConsoleOutput {
+write(record: LogRecord)
}
class PostgresOutput {
-PgPool pool
+new(pool: PgPool)
+write(record: LogRecord)
}
class FileOutput {
-File file
+write(record: LogRecord)
}
class LoggerConfig {
+LogLevel min_level
+Vec~Box~LogOutput~~ outputs
}
class Logger {
-Sender~LogRecord~ tx
-LogLevel min_level
+init(config: LoggerConfig) Arc~Logger~
+log(level, message, target)
-run_background_task(rx, outputs)
}
%% Relationships
LogOutput <|.. ConsoleOutput : Implements
LogOutput <|.. PostgresOutput : Implements
LogOutput <|.. FileOutput : Implements
Logger ..> LogRecord : Creates
Logger o-- LoggerConfig : Uses
LoggerConfig o-- LogOutput : Aggregates (0..*)
LogRecord -- LogLevel : Has
classDiagram
%% 接口定义:强调 Send + Sync 约束
class LogOutput {
<<interface>>
<<Send + Sync>>
+write(record: LogRecord) Future
}
%% 具体实现
class PostgresOutput {
-PgPool pool
+write(record)
}
class ConsoleOutput {
+write(record)
}
%% 业务线程持有的 Logger (Producer)
class Logger {
<<Thread-Safe>>
<<Shared via Arc>>
-mpsc::Sender~LogRecord~ tx
-LogLevel min_level
+log(level, msg)
}
%% 后台异步任务 (Consumer)
class BackgroundWorker {
<<Active Object>>
<<Running in tokio::spawn>>
-mpsc::Receiver~LogRecord~ rx
-Vec~Box~LogOutput~~ outputs
+run()
}
%% 数据包
class LogRecord {
<<Immutable>>
+timestamp
+level
+message
}
%% 关系描述
LogOutput <|.. PostgresOutput
LogOutput <|.. ConsoleOutput
%% 关键的线程安全机制:MPSC Channel
Logger "1" o-- "1" `mpsc::Sender` : Owns
BackgroundWorker "1" o-- "1" `mpsc::Receiver` : Owns
%% 逻辑流
ClientThread ..> Logger : 1. Calls log() (Non-blocking)
Logger ..> `mpsc::Sender` : 2. Sends Record
`mpsc::Sender` ..> `mpsc::Receiver` : 3. Channel Transfer (Thread-Safe)
`mpsc::Receiver` ..> BackgroundWorker : 4. Receives Record
BackgroundWorker --> LogOutput : 5. Serialized Writes
rust_logger/
├── Cargo.toml
├── src/
│ ├── lib.rs # 库入口,定义宏
│ ├── model.rs # 定义 LogLevel, LogRecord
│ ├── outputs/ # 输出模块
│ │ ├── mod.rs # Trait 定义
│ │ ├── console.rs # 控制台输出实现
│ │ ├── file.rs # 文件输出实现
│ │ └── postgres.rs # 数据库输出实现
│ ├── core.rs # Logger 核心逻辑 (Channel, Spawn)
│ └── cleaner.rs # 清理输出协程
为了展示 TraceID 的真正威力,我们将模拟一个 高并发的 Web 服务场景。
在这个场景中,如果不使用 TraceID,多个用户的日志会像“洗牌”一样混在一起,根本无法区分谁是谁。使用了 TraceID 后,我们就能像“抓线头”一样把一次请求的完整路径提出来。
第一步:准备工作 (不可跳过)
因为我们在 LogRecord 中增加了 trace_id,你必须更新数据库表结构,否则程序运行会报错。
请在 PostgreSQL 中执行:
-- 1. 增加字段
ALTER TABLE app_logs ADD COLUMN trace_id VARCHAR(64);
-- 2. 建立索引 (查询全靠它)
CREATE INDEX idx_logs_trace_id ON app_logs(trace_id);
第二步:编写业务代码 (order-service/src/main.rs)
我们需要引入 uuid 来生成唯一的 ID。
Cargo.toml:
[dependencies]
# ... 其他依赖
uuid = { version = "1.0", features = ["v4"] }
main.rs: 在这个例子中,我们模拟两个并发请求同时进入系统。
use rust_logger::{
context::with_trace_id, // 核心:上下文管理器
log_info, log_error, set_global_logger,
Logger, LoggerConfig, LogLevel, LogCleaner,
outputs::{ConsoleOutput, PostgresOutput, FileOutput}
};
use sqlx::postgres::PgPoolOptions;
use std::time::Duration;
use uuid::Uuid;
use std::sync::Arc;
#[tokio::main]
async fn main() -> anyhow::Result<()> {
// 1. 初始化 DB
let db_url = std::env::var("DATABASE_URL").expect("DATABASE_URL must be set");
let pool = PgPoolOptions::new().connect(&db_url).await?;
// 2. 初始化 Logger (同时输出到 Console, DB, File)
let file_output = FileOutput::new("logs", "order-service").await?;
let config = LoggerConfig {
min_level: LogLevel::INFO,
outputs: vec![
Box::new(ConsoleOutput),
Box::new(PostgresOutput::new(pool.clone())), // DB
Box::new(file_output), // File
],
};
set_global_logger(Logger::init("order-service", config));
// 3. 启动清理任务 (可选)
LogCleaner::new(7).with_db_cleanup(pool.clone()).start();
println!(">>> 服务启动,开始模拟并发请求...\n");
// 4. 模拟并发:同时处理两个用户的下单请求
// 场景:
// - 用户 A (Alice) 下单成功
// - 用户 B (Bob) 下单失败
let request_a = tokio::spawn(mock_http_handler("Alice", "ITEM-001", true));
let request_b = tokio::spawn(mock_http_handler("Bob", "ITEM-999", false)); // 模拟库存不足
// 等待请求处理完成
let _ = tokio::join!(request_a, request_b);
// 等待日志写入完毕
tokio::time::sleep(Duration::from_secs(1)).await;
println!("\n>>> 模拟结束。请查看数据库或文件日志。");
Ok(())
}
// 模拟 HTTP 请求入口 (Middleware 层)
async fn mock_http_handler(user: &str, item_id: &str, is_success: bool) {
// 1. 生成 TraceID (通常从 HTTP Header "X-Trace-ID" 获取,没有则生成)
let trace_id = Uuid::new_v4().to_string();
// 2. 【关键】使用 with_trace_id 包裹整个业务逻辑
// 只要在这个闭包里,无论调用多深层的函数,log_info! 都会自动带上 ID
with_trace_id(trace_id.clone(), async move {
log_info!("收到下单请求: User={}, Item={}", user, item_id);
// 进入业务逻辑层
process_order(user, item_id, is_success).await;
log_info!("请求处理完毕,返回响应给 {}", user);
}).await;
}
// 模拟业务逻辑层 (Service 层)
async fn process_order(user: &str, item_id: &str, simulate_success: bool) {
log_info!("正在检查库存: {}", item_id);
tokio::time::sleep(Duration::from_millis(50)).await; // 模拟耗时
if simulate_success {
log_info!("库存充足,开始扣款...");
payment_service(user, 100).await;
log_info!("下单成功!订单号: ORDER-{}", Uuid::new_v4());
} else {
log_error!("库存不足!商品 {} 缺货", item_id);
log_info!("订单已取消");
}
}
// 模拟底层服务 (DAO/RPC 层)
async fn payment_service(user: &str, amount: i32) {
// 注意:这里我们没有传 trace_id 参数,但 log_info 依然能获取到它!
log_info!("扣款成功: User={}, Amount=${}", user, amount);
}
第三步:运行结果与证明
运行代码后,我们来看看 为什么 TraceID 是分布式的救命稻草。
1. 如果没有 TraceID (灾难现场)
在控制台或文件中,由于是异步并发,日志会是时间交错的。你看到的可能是这样:
2026-01-22 10:00:01 [INFO] 收到下单请求: User=Alice
2026-01-22 10:00:01 [INFO] 收到下单请求: User=Bob <-- 乱入
2026-01-22 10:00:02 [INFO] 正在检查库存: ITEM-001
2026-01-22 10:00:02 [INFO] 正在检查库存: ITEM-999 <-- 分不清谁是谁了
2026-01-22 10:00:03 [ERROR] 库存不足!
2026-01-22 10:00:03 [INFO] 库存充足,开始扣款... <-- 谁库存充足?谁不足?
2026-01-22 10:00:04 [INFO] 扣款成功
问题:当 Bob 投诉说“我下单失败了”,你看着日志里的“扣款成功”会陷入沉思:到底扣没扣 Bob 的钱?
2. 使用 TraceID 后 (真相大白)
现在查看生成的文件日志 logs/order-service-YYYY-MM-DD.log,或者查看数据库。
实际输出:
[INFO] [550e8400-e29b...] - 收到下单请求: User=Alice
[INFO] [a1b2c3d4-ffff...] - 收到下单请求: User=Bob
[INFO] [550e8400-e29b...] - 正在检查库存: ITEM-001
[INFO] [a1b2c3d4-ffff...] - 正在检查库存: ITEM-999
[ERROR] [a1b2c3d4-ffff...] - 库存不足!商品 ITEM-999 缺货
[INFO] [a1b2c3d4-ffff...] - 订单已取消
[INFO] [550e8400-e29b...] - 库存充足,开始扣款...
[INFO] [550e8400-e29b...] - 扣款成功: User=Alice, Amount=$100
虽然行还是交错的,但我们可以清楚地看到 ID a1b2c3d4... (Bob) 对应的是 ERROR,而 ID 550e8400... (Alice) 对应的是 扣款成功。
第四步:如何追查问题 (Audit)
当生产环境出现问题时,正确的排查姿势如下:
场景:客服转来一个工单,用户 Bob 说 10:00 左右下单失败了。
1. 模糊搜索定位 TraceID
你不知道 TraceID,但知道时间和用户。
使用 grep 或 SQL:
-- 查找 Bob 在那个时间点的第一条日志,为了拿 TraceID
SELECT trace_id, message, created_at
FROM app_logs
WHERE message LIKE '%Bob%'
AND created_at BETWEEN '2026-01-22 10:00:00' AND '2026-01-22 10:05:00'
LIMIT 1;
结果:拿到 TraceID = a1b2c3d4-ffff...
2. 全链路还原 (The Magic Query) 拿着这个 ID,查询该请求的一生。
SELECT created_at, log_level, module, message
FROM app_logs
WHERE trace_id = 'a1b2c3d4-ffff-...'
ORDER BY created_at ASC;
还原出的故事:
10:00:01[INFO] 收到请求 (module:mock_http_handler)10:00:02[INFO] 检查库存 ITEM-999 (module:process_order)10:00:03[ERROR] 库存不足! (module:process_order) <--- 找到原因了!10:00:03[INFO] 订单取消
结论:你可以自信地回复工单:“经排查,用户下单失败是因为商品 ITEM-999 此时没有库存了,系统正确拦截,未扣款。”
总结 TraceID 的三大好处
- 解耦并发:在高并发系统中(每秒几千个请求),TraceID 是唯一能把属于同一个请求的日志“聚合”在一起的键。
- 跨越边界:虽然本例只演示了一个服务,但 TraceID 通常会通过 HTTP Header 传给下游服务(Payment Service, Stock Service)。这样你在 Kibana/Grafana 里搜一个 TraceID,能看到跨越 5 个微服务的完整调用链。
- 无侵入开发:你的开发人员不需要在写
payment_service时手动传递trace_id参数,他们只需要写log_info!,库会自动完成剩下的工作。