Rust中使用tracing写入日志文件为空问题求助

问题描述 #

使用tracing库将日志写入文件时，程序运行期间日志文件已创建，但程序结束后文件内容为空。相关代码及依赖配置如下：

初始化tracing的代码 #

pub fn tracing_init() {
    let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"));
    // 输出到控制台中
    let formatting_layer = fmt::layer().pretty().with_writer(std::io::stderr);
    let log_file_name = Local::now().format("%Y-%m-%d").to_string() + ".log";
    // 输出到文件中
    let file_appender = rolling::daily("logs", log_file_name);
    let (non_blocking_appender, _guard) = non_blocking(file_appender);
    let file_layer = fmt::layer()
        .with_ansi(false)
        .with_writer(non_blocking_appender);

    // 注册
    Registry::default()
        .with(env_filter)
        // ErrorLayer 可以让 color-eyre 获取到 span 的信息
        .with(ErrorLayer::default())
        .with(formatting_layer)
        .with(file_layer)
        .init();

    // 安装 color-eyre 的 panic 处理句柄
    color_eyre::install().expect("color_eyre install fail");

}

main函数代码 #

fn main() {
    tracing_init();
    event!(Level::DEBUG, "aaa:{}", "myu");
    info!("info");
    debug!("debug");
    error!("error");
    warn!("warn");
    tracing::info!("this is tracing info");
    thread::sleep(time::Duration::from_secs(10));
    event!(Level::INFO, "aaa:{}", "myu1");
    info!("info1");
    debug!("debug1");
    error!("error1");
    warn!("warn1");
    tracing::info!("this is tracing info1");
}

Cargo.toml依赖配置 #

[dependencies]
tracing = "0.1.37"
tracing-subscriber = { version = "0.3.16", features = ["env-filter", "std"] }
tracing-appender="0.2.2"
tracing-error="0.2.0"
color-eyre="0.6.2"

chrono = "0.4"

问题原因 #

tracing_appender::non_blocking返回的WorkerGuard（代码中的_guard）负责在销毁时强制刷新后台线程的日志缓冲区，并等待所有未写入的日志完成写入。当前代码中_guard是tracing_init函数的局部变量，函数执行完毕后_guard被立即销毁，此时后台线程还未将缓冲区中的日志写入文件就被终止，导致文件内容为空。

修复方案 #

延长WorkerGuard的生命周期，使其与程序生命周期一致。具体做法是让tracing_init返回WorkerGuard，在main函数中持有该实例直到程序结束。

修改后的tracing_init函数 #

use tracing_appender::non_blocking::WorkerGuard;

pub fn tracing_init() -> WorkerGuard {
    let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"));
    // 输出到控制台中
    let formatting_layer = fmt::layer().pretty().with_writer(std::io::stderr);
    let log_file_name = Local::now().format("%Y-%m-%d").to_string() + ".log";
    // 输出到文件中
    let file_appender = rolling::daily("logs", log_file_name);
    let (non_blocking_appender, guard) = non_blocking(file_appender);
    let file_layer = fmt::layer()
        .with_ansi(false)
        .with_writer(non_blocking_appender);

    // 注册
    Registry::default()
        .with(env_filter)
        // ErrorLayer 可以让 color-eyre 获取到 span 的信息
        .with(ErrorLayer::default())
        .with(formatting_layer)
        .with(file_layer)
        .init();

    // 安装 color-eyre 的 panic 处理句柄
    color_eyre::install().expect("color_eyre install fail");

    guard
}

修改后的main函数 #

fn main() {
    let _guard = tracing_init(); // 持有guard实例直到程序结束
    event!(Level::DEBUG, "aaa:{}", "myu");
    info!("info");
    debug!("debug");
    error!("error");
    warn!("warn");
    tracing::info!("this is tracing info");
    thread::sleep(time::Duration::from_secs(10));
    event!(Level::INFO, "aaa:{}", "myu1");
    info!("info1");
    debug!("debug1");
    error!("error1");
    warn!("warn1");
    tracing::info!("this is tracing info1");
}

额外说明 #

当前代码中EnvFilter设置为info级别，因此debug!宏输出的日志会被过滤，不会出现在文件和控制台中。如果需要输出debug级别日志，可以将EnvFilter::new("info")改为EnvFilter::new("debug")，或者通过设置RUST_LOG=debug环境变量来调整日志级别。

内容的提问来源于stack exchange，提问作者yan shen