1. 业务逻辑中的异步日志
在应用的初期版本,所有日志可能都是通过 tracing
输出到外部文件的,这是非常正常的情况;等到开始进行可观测能力建设后,就需要引入一些日志中间件,比如将一些重要日志输出到 SLS 。这些逻辑往往会穿插在我们业务函数中,于是就引出一个基本的原则:日志无论如何不能阻塞业务本身。(对于日志之外的非业务逻辑,其实也是一样的)
从反面例子开始说起:
假设我们最初有这样的一个业务函数:
async fn business() {
// ...
do_some_biz();
let log = generate_important_log();
tracing::info!("[biz] {log}");
do_other_biz();
// ...
}
这个版本没有任何问题。现在,我们需要接入某些高大上的日志中间件,这里为了简化,假设日志投递方式是一个 http 接口,那么最容易想到(也是最糟糕)的写法就是直接把 tracing
这行换掉:
async fn business() {
// ...
do_some_biz();
let log = generate_important_log();
let response = reqwest::Client::new()
.post("https://naive-logger.com/api/push")
.body(log.to_string())
.send()
.await?;
do_other_biz();
// ...
}
显而易见,我们的第二段业务逻辑 do_other_biz
需要等待日志投递完成。如果日志服务出现问题而导致请求超时,那么在这期间业务就会被阻塞住。
修复这个问题的思路,无非就是让业务与日志逻辑分隔开来,或者让所有日志相关的逻辑等到业务彻底完成以后再进行处理。实际写法里,使用分隔方案的场景是比较多的。
那么,似乎简单地把日志逻辑 spawn
出去即可?比如下面这样:
async fn business() {
// ...
do_some_biz();
let log = generate_important_log();
tokio::spawn(async {
let response = reqwest::Client::new()
.post("https://naive-logger.com/api/push")
.body(log.to_string())
.send()
.await;
});
do_other_biz();
// ...
}
这个改动表面上看起来能解决业务被阻塞的问题。但是实际上,这种写法也是不合理的:对于业务流量很大的场景,如果日志投递模块超时,则会出现大量的 tokio 异步任务累积,最终还是有可能打垮我们的服务。
对于类似的场景,最佳的解决方案是,一旦引入了这种服务,我们端侧的日志模块就必须改成基于有限长度队列的的生产者-消费者模式。现成的方案是基于 tokio::sync::mpsc::channel
进行开发,这个 channel 有着确定长度的消息缓冲区。与之对应的不限长度 channel 则是 tokio::sync::mpsc::unbounded_channel
。此外,当队列满导致日志无法正常投递时,可以在错误处理中增加落盘的逻辑。