Rust 日誌系統實踐總結

文檔列表見：Rust 移動端跨平臺複雜圖形渲染項目開發系列總結（目錄）

（上次更新：2018-12-20 新增【日誌顏色】）基於log、env_logger、fern等的使用總結，詳細配置建議參考官方說明。

給工程添加第三方日誌庫依賴

給Cargo.toml文件加上以下配置，log基本爲Rust項目日誌需求的標配庫，env_logger提供了具體實現，相似策略模式：log定義操做，env_logger實現具體行爲，很方便切換另外一個實現了log所定義接口的庫，好比daboross/fern。

[dependencies]
log = "0.4.0"
env_logger = "0.6.0"
複製代碼

env_log配置

下面描述咱們項目對env_log所做的配置。問題：修改format致使終端執行時日誌無顏色。

配置輸出時間爲本地時間

env_logger默認用0時區，而北京是東8區，每第二天志輸出都少8小時，時間沒對上不方便分析日誌。0時區舉個例子：

INFO 2018-11-18T02:00:08Z: webgpu-native::registry: env_logger initialized.
複製代碼

下面給出env_logger輸出本地時間的示例代碼，參考了DCjanus/nabu，他用flexi_logger，略調整便可用於env_logger。加上更多自定義信息的關鍵是修改writeln! 宏。

#[macro_use]
extern crate log;
extern crate chrono;
extern crate env_logger;

fn init_log() {
    use chrono::Local;
    use std::io::Write;

    let env = env_logger::Env::default().filter_or(env_logger::DEFAULT_FILTER_ENV, "trace");
    env_logger::Builder::from_env(env)
        .format(|buf, record| {
            writeln!(
                buf,
                "{} {} [{}] {}",
                Local::now().format("%Y-%m-%d %H:%M:%S"),
                record.level(),
                record.module_path().unwrap_or("<unnamed>"),
                &record.args()
            )
        })
        .init();

    info!("env_logger initialized.");
}
複製代碼

以上代碼需在fn main()開始或lazy_static開始，不然剛開始部分日誌不受新配置影響。 放在lazy_static的日誌配置須要手動 激活，好比

// 定義
lazy_static! {
    pub(crate) static ref HUB: Hub = {
        init_log();
        Hub::default()
    };
}
// 在某個入口函數中先訪問HUB，「強迫」它執行lazy_static代碼塊
fn entry_point() {
    &*HUB; // 「強迫」執行lazy_static代碼塊
    
    HUB.some_method(); // 裏面的info!()等可正常輸出到文件或控制檯
}
複製代碼

以東8區爲例，執行顯示：

// 修改前
[2018-11-18T02:00:08Z INFO  webgpu-native::registry] env_logger initialized.
// 修改後
2018-11-18 09:27:43 INFO [webgpu-native::registry] env_logger initialized.
複製代碼

日誌添加行號

writeln!(
    buf,
    "{} {} [{}:{}] {}",
    Local::now().format("%Y-%m-%d %H:%M:%S"),
    record.level(),
    record.module_path().unwrap_or("<unnamed>"),
    record.line().unwrap_or(0),
    &record.args()
)
複製代碼

執行顯示：

2018-11-18 10:38:41 INFO [webgpu-native::registry:87] env_logger initialized.
複製代碼

日誌添加文件名

writeln!(
    buf,
    "{} {} [{}:{}:{}] {}",
    Local::now().format("%Y-%m-%d %H:%M:%S"),
    record.level(),
    record.module_path().unwrap_or("<unnamed>"),
    record.line().unwrap_or(0),
    &record.args()
)
複製代碼

執行顯示：

2018-11-18 10:38:48 INFO [webgpu-native::registry:webgpu-native/src/registry.rs:87] env_logger initialized.
複製代碼

日誌級別左/右對齊

1. 左對齊

   writeln!(
       buf,
       "{:<5} {} [{}:{}] {}",
       record.level(),
       // same as previous content
   )
   複製代碼

2. 右對齊

   writeln!(
       buf,
       "{:>5} {} [{}:{}] {}",
       record.level(),
       // same as previous content
   )
   複製代碼

參考：What is the easiest way to pad a string with 0 to the left?

日誌顏色

不修改format，env_logger默認用不一樣顏色標識level日誌。前面的修改致使這一特性「失效」，看着不直觀，固然CLion等能夠用Grep Console插件給日誌上色，若是是Terminal中執行，那還得咱們修改format加上顏色才行。如下內容參考env_logger-0.6.0/src/fmt/mod.rs的DefaultFormatter源碼，感謝 @齒輪哥 指導。

use std::io::Write;
    let env = env_logger::Env::default().filter_or(env_logger::DEFAULT_FILTER_ENV, "trace");
    let mut builder = env_logger::Builder::from_env(env);
    println!("builder = {:?}", builder);
    builder
        .format(|buf, record| {
            let level = { buf.default_styled_level(record.level()) };
            write!(buf, "{}", format_args!("{:>5}", level));
            writeln!(buf, " {}", &record.args())
        })
        .init();
複製代碼

過濾日誌級別

env_logger::Env::default().filter_or(env_logger::DEFAULT_FILTER_ENV, "trace");
複製代碼

filter_or()可配置以下內置值過濾不一樣級別的日誌，其實咱們也可自行添加filter tag：

• "trace"
• "info"
• "debug"
• "warn"
• "error"

也能夠在程序執行時傳遞命令行參數進行過濾：

$ RUST_LOG=info ./main
[2018-11-03T06:09:06Z INFO  default] starting up
複製代碼

組合過濾條件

添加depX=Y，可同時過濾多個條件、以其中級別最高的爲準，低於最高級都無法經過，好比下面將顯示級別高於info、也高於debug級別的日誌 = 要高於info級別，乾脆設置成info就好了，真是畫蛇添足。

RUST_LOG=info,dep1=debug ./main
複製代碼

動態過濾信息

在複雜項目中每每存在多個模塊，做爲其中一個模塊的開發者，爲了定位本身負責模塊的問題，過濾掉其餘模塊的日誌是很常見的需求，因爲總體項目一般使用同一個日誌庫，逐行註釋其餘模塊的日誌輸出顯然是不可理的行爲。另外，雖然控制檯能夠作過濾處理，多條件的過濾規則編寫起來也有難度，並且可能日誌查看系統不支持這種操做。其實，咱們能夠給前面一直在修改的format()加上過濾邏輯，好比：

format(|buf, record| {
    // special format for debug messages coming from our own crate.
    if record.level() > log::LevelFilter::Info && record.target() == "my_module" {
        write!(...)
    } else if /* some condition */ {
        write!(...)
    } else if /* some condition 2*/ {
        write!(...)
    } else {
        write!(...)
    }
}
複製代碼

過濾邏輯的實現可參考fern/cmd-program.rs。

fern，env_logger的另外一個選擇

daboross/fern

Simple, efficient logging for Rust

fern配置起來更直觀（所下所示），目前我還沒測試它與env_logger的性能差別。

// Configure logger at runtime
fern::Dispatch::new()
    // Perform allocation-free log formatting
    .format(|out, message, record| {
        out.finish(format_args!(
            "{}[{}][{}] {}",
            chrono::Local::now().format("[%Y-%m-%d][%H:%M:%S]"),
            record.target(),
            record.level(),
            message
        ))
    })
    // Add blanket level filter -
    .level(log::LevelFilter::Debug)
    // - and per-module overrides
    .level_for("hyper", log::LevelFilter::Info)
    // Output to stdout, files, and other Dispatch configurations
    .chain(std::io::stdout())
    .chain(fern::log_file("output.log")?)
    // Apply globally
    .apply()?;

// and log using log crate macros!
info!("helllo, world!");
複製代碼

提升日誌性能

todo