【跟小嘉学 Rust 编程】三十一、Rust的日志与追踪

系列文章目录

文章目录

系列文章目录
@[TOC](文章目录)

前言
一、日志详解
1.1、日志级别
1.2、输出位置
1.3、日志的查看
1.4、日志采集

二、日志门面(logging facade)
2.1、日志门面介绍
2.1、Log 特征
2.2、日志宏
2.3、日志输出
2.3.1、env_logger
2.3.2、实现 log 特征

三、追踪(tracing)
3.1、追踪(tracing)
3.2、使用
3.2.1、添加依赖
3.2.1、使用

3.3、异步编程中使用
3.4、tracing的核心概念
3.4.1、span
3.4.2、event
3.4.3、collector

3.5、tracing-subscriber
3.6、#[instrument]

前言

本章节讲解日志与监控，系统的可观测性(Observability) 通常由三个维度：日志(Logging)、指标(Metric)和追踪(Tracing)。

日志：离散的错误信息和状态信息
指标：记录和呈现可聚合的数据
追踪：单个请求的一系列事件；

主要教材参考《The Rust Programming Language》
主要教材参考《Rust For Rustaceans》
主要教材参考《The Rustonomicon》
主要教材参考《Rust 高级编程》
主要教材参考《Cargo 指南》
主要教材参考《Rust 异步编程》

一、日志详解

1.1、日志级别

日志级别是对基本的“滚动文本”式日志记录的一个重要补充。每条日志消息都回基于其重要性或严重程度分配到一个日志级别。

Fatal：程序发生致命错误，此类错误往往来自于程序逻辑的严重异常，例如无法分配足够的硬盘空间、内存不足等，建议立即退出或重启程序
Error：错误，一般指的是程序级别的错误或严重的业务错误，但是这种错误并不会影响程序的运行。
Warn：警告，说明这条记录需要注意，但是不确定是否发生了错误，因粗需要相关的开发人员来辨别。
Info：信息，此类往往用于记录程序的运行信息，例如用户操作或状态的变化；
Debug：调试信息，是给开发者用的，应用了解程序当前的详细运行状况，例如请求信息追踪等；

1.2、输出位置

一般而言，日志可以输出的两个地方：终端控制台(标准输出/标准错误)和文件。

如果没有日志持久化的需求，你只是为了调试程序，建议输出到控制台即可。悄悄的说一句，我们还可以为不同的级别设定不同的输出位置，例如 Debug 日志输出到控制台，既方便开发查看，但又不会占用硬盘，而 Info 和 Warning 日志可以输出到文件 info.log 中，至于 Error、Fatal 则可以输出到 error.log 中。

1.3、日志的查看

可以使用 tail、cat、grep等命令
打开文件搜索
在可视化界面，配合日志采集工具到 ElasticSearch 或其他搜索平台，然后通过 kibana、grafana 等进行搜索查看。

1.4、日志采集

我们可以使用日志采集工具去控制台等标准输出读取日志数据，然后将读取到的数据发送给到日志存储平台(ElasticSearch).

目前常用的日志采集工具有：filebeat、vector等，他们都是以 agent 的形式运行在你的应用程序旁边；

二、日志门面(logging facade)

2.1、日志门面介绍

就如同 slf4j 是 Java 的日志门面库，log 也是 Rust 的日志门面库，目前由官方积极维护。

cargo add log

既然是门面，log 自然定义了一套统一的日志特征和API，将日志的操作进行了抽象定义。

2.1、Log 特征

pub trait Log: Sync + Send {
    fn enabled(&self, metadata: &Metadata<'_>) -> bool;
    fn log(&self, record: &Record<'_>);
    fn flush(&self);
}

enabled：用于判断某条带有元数据的日志是否能被记录，它对于 log_enabled！宏特别有用
log：回记录 record 所代表的日志
flush：回将缓存中的日志刷到输出中，例如标准输出或文件；

2.2、日志宏

log 为我们不同的日志级别提供了不同的日志宏

use log::{info, trace, warn};

pub fn shave_the_yak(yak: &mut Yak) {
    trace!("Commencing yak shaving");

    loop {
        match find_a_razor() {
            Ok(razor) => {
                info!("Razor located: {}", razor);
                yak.shave(razor);
                break;
            }
            Err(err) => {
                warn!("Unable to locate a razor: {}, retrying", err);
            }
        }
    }
}

2.3、日志输出

log 仅仅是日志门面库，不具备完整的日志库功能。如果你是 rust 库的开发者，只要在库中使用门面库即可，具体的日志库交由用户选择和绑定

2.3.1、env_logger

1、添加依赖

cargo add env_logger

2、使用

use log::{debug, error, log_enabled, info, Level};

fn main() {
    // 注意，env_logger 必须尽可能早的初始化
    env_logger::init();

    debug!("this is a debug {}", "message");
    error!("this is printed by default");

    if log_enabled!(Level::Info) {
        let x = 3 * 4; // expensive computation
        info!("the answer was: {}", x);
    }
}

此时i可以通过环境变量(RUST_LOG)设置日志级别

默认情况下，env_logger 会输出到标错误，如果你要输出到标准输出，可以使用 builder 来改变日志对象(target);

2.3.2、实现 log 特征

use log::{Record, Level, Metadata};
struct SimpleLogger;
impl log::Log for SimpleLogger {
    fn enabled(&self, metadata: &Metadata) -> bool {
        metadata.level() <= Level::Info
    }
    fn log(&self, record: &Record) {
        if self.enabled(record.metadata()) {
            println!("{} - {}", record.level(), record.args());
        }
    }
    fn flush(&self) {}
}

三、追踪(tracing)

3.1、追踪(tracing)

随着微服务的流行，现在一个产品有多个系统组成是非常常见的，这种情况下，一条用户请求可能会横跨几个甚至几十个服务。此时再用传统的日志方式去跟踪这条用户请求就变得较为困难，这就是分布式追踪在现代化监控系统中这么炽手可热的原因。

关于分布式追踪，在后面的监控章节进行详细介绍，大家只要知道：分布式追踪的核心就是在请求的开始生成一个 trace_id，然后将该 trace_id 一直往后透穿，请求经过的每个服务都会使用该 trace_id 记录相关信息，最终将整个请求形成一个完整的链路予以记录下来。

那么后面当要查询这次请求的相关信息时，只要使用 trace_id 就可以获取整个请求链路的所有信息了，非常简单好用。看到这里，相信大家也明白为什么这个库的名称叫 tracing 了吧？

至于为何把它归到日志库的范畴呢？因为 tracing 支持 log 门面库的 API，因此，它既可以作为分布式追踪的 SDK 来使用，也可以作为日志库来使用。

在分布式追踪中，trace_id 都是由 SDK 自动生成和往后透穿，对于用户的使用来说是完全透明的。如果你要手动用日志的方式来实现请求链路的追踪，那么就必须考虑 trace_id 的手动生成、透传，以及不同语言之间的协议规范等问题

3.2、使用

3.2.1、添加依赖

cargo add tracing

3.2.1、使用

use log;
use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt};

fn main() {
    // 只有注册 subscriber 后， 才能在控制台上看到日志输出
    tracing_subscriber::registry()
        .with(fmt::layer())
        .init();
    
    // 调用 `log` 包的 `info!`
    log::info!("Hello world");
    
    let foo = 42;
    // 调用 `tracing` 包的 `info!`
    tracing::info!(foo, "Hello from tracing");
}

tracing 在 API上使用了 log 的规范。

3.3、异步编程中使用

在异步编程中，异步任务的执行没有确定的顺序，那么输出的日志将没有确定的日志并混在一起，无法按照我们想要的逻辑顺序串联起来。

归根到底，在于日志只能针对某个时间点进行记录，缺乏上下文信息，而线程间的执行顺序又是不确定的，因此日志就有些无能为力。而 tracing 为了解决这个问题，引入了 span 的概念( 这个概念也来自于分布式追踪 )，一个 span 代表了一个时间段，拥有开始和结束时间，在此期间的所有类型数据、结构化数据、文本数据都可以记录其中。

大家发现了吗？ span 是可以拥有上下文信息的，这样就能帮我们把信息按照所需的逻辑性串联起来了。

3.4、tracing的核心概念

3.4.1、span

相比起日志只能记录在某个时间点发生的事件，span 最大的意义就在于它可以记录一个过程，也就是在某一段时间内发生的事件流。既然是记录时间段，那自然有开始和结束:

use tracing::{span, Level};
fn main() {
    let span = span!(Level::TRACE, "my_span");

    // `enter` 返回一个 RAII ，当其被 drop 时，将自动结束该 span
    let enter = span.enter();
    // 这里开始进入 `my_span` 的上下文
    // 下面执行一些任务，并记录一些信息到 `my_span` 中
    // ...
} // 这里 enter 将被 drop，`my_span` 也随之结束

3.4.2、event

Event 代表了某个时间点发生的事件，这方面它跟日志类似，但是不同的是，Event 还可以产生在 span 的上下文中。

use tracing::{event, span, Level};
use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt};

fn main() {
    tracing_subscriber::registry().with(fmt::layer()).init();
    // 在 span 的上下文之外记录一次 event 事件
    event!(Level::INFO, "something happened");

    let span = span!(Level::INFO, "my_span");
    let _guard = span.enter();

    // 在 "my_span" 的上下文中记录一次 event
    event!(Level::DEBUG, "something happened inside my_span");
}

虽然 event 在哪里都可以使用，但是最好只在 span 的上下文中使用：用于代表一个时间点发生的事件，例如记录 HTTP 请求返回的状态码，从队列中获取一个对象，等等。

3.4.3、collector

当 Span 或 Event 发生时，它们会被实现了 Collect 特征的收集器所记录或聚合。这个过程是通过通知的方式实现的：当 Event 发生或者 Span 开始/结束时，会调用 Collect 特征的相应方法通知 Collector。

3.5、tracing-subscriber

只有使用了 tracing-subscriber 日志才会输出到控制台

cargo add tracing-subscriber

3.6、#[instrument]

如果想要将某个函数的整个函数体都设置为 span 的范围，最简单的方法就是为函数标记上 #[instrument]，此时 tracing 会自动为函数创建一个 span，span 名跟函数名相同，在输出的信息中还会自动带上函数参数。

use tracing::{info, instrument};
use tracing_subscriber::{fmt, layer::SubscriberExt, util::SubscriberInitExt};

#[instrument]
fn foo(ans: i32) {
    info!("in foo");
}

fn main() {
    tracing_subscriber::registry().with(fmt::layer()).init();
    foo(42);
}

对于没有内置 tracing 支持或者无法使用 #instrument 的函数，例如外部库的函数，我们可以使用 Span 结构体的 in_scope 方法，它可以将同步代码包裹在一个 span 中