【Rust.Crate之tracing 诊断系统】
Rust.Crate之tracing 诊断系统
- 前言
- diagnostics system
- tracing
- 标签 #[tracing::instrument]
- 异步函数中span
- Instrument中的?
- tracing_subscriber
- tracing 的原生Subscribers
- 总结
前言
日志对于每一个开发者来说并不陌生,开发者通常希望在程序代码中的一些需要做记录的地方加上日志,亦或在调试期间加的打印,随着需求的展开和经验的不断丰富,单纯的日志往往无法让开发者第一时间定位到问题,一般的,日志记录都是文本格式,且针对特定的数据并没有一个舒适的格式便于人类阅读,即便有时间戳等的信息,没有上下文的记录,开发者依然需要还原现场才能够排查到具体的问题原因,这对于快速迭代的日常开发和服务器线上问题的解决并不友好。
diagnostics system
诊断系统是目前主流的信息记录手段,通常情况下,使用诊断信息可以做到log日志能够做的一切,并再此基础上,诊断系统可以记录程序运行期间的主要问题场景,从begining 到ending,整个时间跨度都可以记录下来,这对日常问题排查就很有友好了,加之诊断系统一般可轻松的将信息格式化的存储落盘,尤其是在服务器的请求响应模式下,每一条的请求都将格式化记录,这也适合第三方软件对日志关键内容的提取变得十分方便。
tracing
tracing 是Rust crate。
A scoped, structured logging and diagnostics system.
tracing是一个范围明确的结构化日志的诊断系统。
先来看一段代码:
use std::io;
use tracing::*;
use tracing_subscriber;
fn test_trace(n: i32) {
event!(Level::INFO, "something happened");
let span = span!(Level::TRACE, "my_span");
let _guard = span.enter();
trace!(answer = n, "trace1: test_trace");
event!(Level::INFO, "this is a test_trace ");
inner_trace();
}
fn inner_trace() {
trace!("trace2: inner_trace");
event!(Level::INFO, "this is a inner_trace ");
}
fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::TRACE)
.with_writer(io::stdout)
.init();
test_trace(33);
}
对上述代码进行分解:
let span = span!(Level::TRACE, "my_span");
let _guard = span.enter();
span指一个跨度,即在其enter的作用域内,在enter被析构前,所有的下游跨度都会被当作当前跨度的子跨度,编译器跟踪他的生命周期,在他离开作用域时候析构。
什么是他的下游跨度?
依上述代码中:
fn test_trace(n: i32) {
let span = span!(Level::TRACE, "my_span");
let _guard = span.enter();
trace!(answer = n, "trace1: test_trace");
inner_trace();//<--- 这就是子跨度,在输出的信息中也可以证实
}
程序运行输出的信息:
2024-11-08T07:00:41.891102Z TRACE my_span: log: trace1: test_trace answer=33
2024-11-08T07:00:41.891346Z TRACE my_span: log: trace2: inner_trace
标签 #[tracing::instrument]
此标签可以直接向函数添加跨度,在每次调用此函数时都会创建带有其名称的跨度,从而实现更好的追踪。
代码示例:
use std::io;
use tracing::*;
use tracing_subscriber;
#[tracing::instrument]
fn test_span() {
error!("error_my_instrument");
let _ = std::time::Duration::from_secs(1);
}
#[tracing::instrument]
fn test_span1() {
trace!("trace_my_instrument");
let _ = std::time::Duration::from_secs(1);
}
fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::TRACE)
.with_writer(io::stdout)
.init();
test_span();
test_span1();
}
程序输出:
2024-11-08T07:38:25.875136Z ERROR test_span: log: error_my_instrument
2024-11-08T07:38:25.875266Z TRACE test_span1: log: trace_my_instrument
异步函数中span
在异步程序中,异步函数都会返回一个Future,Future又会通过poll的不断轮询推进函数执行进度,具体的可参考
Rust异步编程
而在trcing crate中的Instrument(区别于macros),Instrument是一个用于扩展future的trait,它以span为参数,每当future被轮询的时候,都会enter当前跨度,每当当前future被挂起时,都会退出当前跨度,所以再此基础上可以一直追踪future。
代码示例:
use std::io;
use tracing::*;
use tracing_subscriber;
async fn test_span1() {
trace!("this is a tracing");
let _ = std::time::Duration::from_secs(1);
}
#[tokio::main]
async fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::TRACE)
.with_writer(io::stdout)
.init();
let span = info_span!("trace_my_instrument");
test_span1().instrument(span).await;
}
Instrument中的?
[?]就是使用Debug的简写,直接看代码:
use std::io;
use tracing::*;
use tracing_subscriber;
#[derive(Debug)]
struct MyStruct {
field: &'static str,
}
async fn test_span1() {
let my_struct = MyStruct {
field: "Hello world!",
};
event!(Level::TRACE, greeting = ?my_struct);
let _ = std::time::Duration::from_secs(1);
}
#[tokio::main]
async fn main() {
tracing_subscriber::fmt()
.with_max_level(Level::TRACE)
.with_writer(io::stdout)
.init();
let span = info_span!("trace_my_instrument");
test_span1().instrument(span).await;
}
tracing_subscriber
代码中的tracing_subscriber用于格式化信息输出,包括数据格式,时间格式,输出到哪里,设置tracing最大级别等等。 由此名称也可以推断,每次生成的tracing信息都由其收集。
tracing 的原生Subscribers
当Spans和Events发生时,它们会被Subscriber trait的实现记录或聚合。当事件发生以及输入或退出Span时,Subscriber 会收到通知。这些通知由以下Subscriber trait方法表示:
event, 当事件发生时触发
enter, 当进入跨度时触发
exit, 当推出跨度时触发
当我们需要高度定制化的Subscriber 时不如实现Subscriber trait来试试。
总结
至此,tracing 的基本使用方法和核心的几种方法就介绍完了,当然与之相连的还有很多crate,读者需要在需要时仔细阅读,多加练习。
开发者一般关注日志追踪的目的也时为了解决问题和提升系统,所以一般情况下错误处理和日志管理是一起讲的,thiserror , Anyhow
等都是很好的错误处理crate,错误处理在Rust中也犹如艺术一般。
“爬到山顶的最好方式就是不要去看远处的山顶,而是多注意脚下的路”