logクレートが提供する柔軟性の仕組みを探る

2023-06-02 :: #Rust  #Logging 
> 目次

Rust でアプリケーションを作成する際に tracing クレートを利用する場合も多くありますが、プロジェクトの初期段階や簡単な POC であればよりシンプルな log クレートを利用する選択肢もあるかと思います。

本記事では log クレートの仕組みを追っていきながら、実装を提供している simple_logger クレートがどのように機能しているのか理解を深めていきます。

[dependencies]
log = "0.4.18"
simple_logger = "4.1.0"

log クレートを利用した Rust での logging

log クレートは、それ自体はロギングの実装を提供しておらず、Rust で標準的なロギングを行うための API となるトレイトを提供しています。そのため log クレートを利用してロギングを行う際には、実際の実装を提供するクレートと組み合わせる必要があります。

以下は実装を提供しているクレートの一部です。

環境変数を利用して設定を行うことが可能な env_logger では、以下のようなコードを記述するだけでログを出力することが可能です。

fn main() {
    env_logger::init();

    log::info!("hello");
}

後は環境変数を指定して実行するとログが出力されていることが確認できます。

$ RUST_LOG=info cargo run
...
[2023-05-27T09:50:55Z INFO  log] hello

これだけだと内部でどのような処理を実現しているのかを推察することが難しいため、公式ドキュメントに記載されている自作ロガーのコードも確認します。

自作ロガーの実装を確認する

公式ドキュメントのサンプルでは Log トレイトの実装として以下がが提供されています。

struct SimpleLogger;

impl log::Log for SimpleLogger {
    fn enabled(&self, metadata: &log::Metadata) -> bool {
        println!("{:?}", metadata);
        metadata.level() <= Level::Info
    }

    fn log(&self, record: &log::Record) {
        println!("{:?}", record);
        if self.enabled(record.metadata()) {
            println!("{} - {}", record.level(), record.args());
        }
    }

    fn flush(&self) {}
}

そしてこの実装を呼び出す時には以下のように set_logger 関数を呼び出してグローバルに適用するロガーを登録し、ログレベルを設定して出力されるログを制御するようにしています。

// SimpleLoggerはフィールドを持たないユニット構造体である
// 型の名前自体が唯一の値となるため、単に SimpleLogger と記述すればインスタンスを作成できる
// フィールドを有する場合には、そのフィールドを初期化する必要がある
static LOGGER: SimpleLogger = SimpleLogger;

fn main() {
    log::set_logger(&LOGGER).unwrap();
    log::set_max_level(LevelFilter::Info);

    log::trace!("trace");
    log::debug!("debug");
    log::info!("info");
    log::warn!("warn");
    log::error!("error");
}

この場合であれば最大のログレベルに Info を設定しているため、debug! マクロや trace! マクロはメッセージを出力されないようになっています。

これからは log クレートが提供している下記の機能の詳細を見ていきます。

Log トレイト

ログの実装を行うためには log クレートが提供している Log トレイトを実装することで、各マクロを実行したときのログ出力の挙動を制御する必要があります。

Log トレイトは以下のように定義されています。

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

Log trait | log crate

この定義を 1 つ 1 つ見ていきます。

pub trait Log: Sync + Send

まずは Log トレイトのトレイト境界に設定されているマーカートレイトである Send トレイトと Sync トレイトを振り返ります。

Log トレイトを実装する全ての型は、スレッド間で安全に転送でき、スレッド間で安全に参照を共有することを保証する必要があります。

例えばマルチスレッドでリクエストを処理するような Web サーバーの利用を考えると、各スレッドからは Log トレイトを実装したオブジェクトにアクセスできる必要があります。 Sync トレイトが実装されていれば、複数のスレッドから同時に安全にアクセスできることが保証されます。

実際には Send トレイトと Send トレイトから構成される型は自動的にこれらのトレイトを実装するので、手動で実装する必要はありません。

fn enabled(&self, metadata: &Metadata<'_>) -> bool;

このメソッドを実行することで、以下の構造体で定義されているメタデータを含むログメッセージを記録するかどうかを判定します。

#[derive(Clone, Eq, PartialEq, Ord, PartialOrd, Hash, Debug)]
pub struct Metadata<'a> {
    level: Level,
    target: &'a str,
}

level にはそれぞれログ出力時に呼び出したマクロに対するログレベルが設定されており、この値とグローバルに設定されたログレベルなどの比較を行い、ログを出力するのかどうかを判定することが可能です。

impl Log {
  fn enabled(&self, metadata: &log::Metadata) -> bool {
      // 必ずInfoレベル以上のログを出力しないように設定している
      // 基本的にはグローバルで設定したものをキャプチャしてフィルタリングを行う
      metadata.level() <= Level::Info
  }
}

target にはマクロを呼び出す際にオプションとして設定することが可能であり、例えばライブラリやアプリケーションの名前を設定することで、ログメッセージがどのモジュールから生成されたものを追跡できるようになっています。

例えば以下のようにエラーメッセージを出力すると、

log::error!(target: "Global", "error");

この場合は設定したログレベルとターゲット情報をもとに Metadata が生成されていることがわかります。

Metadata { level: Error, target: "Global" }

まとめるとこのメソッドは、ログ出力時に呼び出したマクロのログレベルをキャプチャして、条件に基づいてログを出力するかどうかを決めることが可能なメソッドです。

またこのメソッドを呼び出すことが可能な log_enabled! マクロも用意されており、ログ出力時に重い計算が必要になる箇所ではこのマクロを利用することで出力する必要のない処理は実行しないように制御することが可能です。

if log_enabled!(log::Level::Debug) {
    log::info!("{}", expensive_call());
}

fn log(&self, record: &log::Record)

このメソッドを実行することでログメッセージのフォーマットなどを制御することが可能であり、 enabled メソッドを呼び出してログの出力可否を細かく制御することも可能です。

fn log(&self, record: &log::Record) {
    if self.enabled(record.metadata()) {
        println!("{} - {}", record.level(), record.args());
    }
}

このメソッドは、各マクロを呼び出した時に以下で定義されている Record を受け取り、ログマクロが実行されたときの情報を抽出します。

#[derive(Clone, Debug)]
pub struct Record<'a> {
    metadata: Metadata<'a>,
    args: fmt::Arguments<'a>,
    module_path: Option<MaybeStaticStr<'a>>,
    file: Option<MaybeStaticStr<'a>>,
    line: Option<u32>,
    #[cfg(feature = "kv_unstable")]
    key_values: KeyValues<'a>,
}

ログマクロを実行したときに内部でこのレコードが生成され、指定したメッセージやマクロを呼び出した行数、実行したときのファイル名などが格納されています。

例えば以下のようにエラーメッセージを出力すると、

log::error!(target: "Global", "error");

このときメタデータが格納されたレコードが生成され、Rust の標準ライブラリから提供されている line! マクロや file! マクロを呼び出した値で初期化を行っています。(今回は検証のために作成したリポジトリ内で examples ディレクトリを作成して処理を実行させています。 )

Record {
  metadata: Metadata { level: Error, target: "Global" },
  args: "error",
  module_path: Some(Static("log")),
  file: Some(Static("examples/log/main.rs")),
  line: Some(31)
}

macros | log crate

他のクレートではこのメソッドの中でタイムスタンプなどのフォーマットを行なっています。

fn flush(&self);

標準出力にメッセージを出すだけの場合にはあまり使うことはないかもしれませんが、ログメッセージをファイルに出力したりする場合など利用します。

例えば std::io::Write トレイトでも flush メソッドは提供されており、以下のようにファイルを生成して書き込む内容を指定した後で、 flush を呼び出すことでバッファに書き込まれた内容をファイルに反映しています。

fn main() -> std::io::Result<()> {
    let mut buffer = BufWriter::new(File::create("foo.txt")?);

    buffer.write_all(b"some bytes")?;
    buffer.flush()?;
    Ok(())
}

Log トレイトに限らず、 flush メソッドは上記のように、パフォーマンス向上のためにデータをメモリ上に保存して、一定の条件や任意のタイミングで永続的なストレージに書き出す時などで利用されています。

他のクレートを例にとると、 fern クレートでは、出力先に応じてそれぞれ対応する flush メソッドを呼び出すことで、ファイルやチャンネルに対してメッセージを書き出す挙動を制御しています。

https://github.com/daboross/fern/blob/4f45ef9aac6c4d5929f100f756b5f4fea92794a6/src/log_impl.rs#L378-L407

各種関数

fn set_logger(logger: &'static dyn Log) -> Result<(), SetLoggerError>

このメソッドを利用することで、アプリケーション内でグローバルに宣言されているロガーを設定することができ、このメソッドを呼び出して初めてログの出力が可能となります。

set_logger | log crate

このメソッドを呼び出さない場合には、マクロを実行した時には NopLogger という空の実装が用意されているメソッドが実行されます。

処理の流れとしてはまず info! マクロを呼び出した時に、内部では __private_api_log 関数を呼び出しており、この中の logger 関数内部でロガーの初期化が実行されたかどうかを判定しています。

// 各種ログマクロを実行した時に呼び出されている関数
pub fn __private_api_log(
    args: fmt::Arguments,
    level: Level,
    &(target, module_path, file, line): &(&str, &'static str, &'static str, u32),
    kvs: Option<&[(&str, &str)]>,
) {
    if kvs.is_some() {
        panic!(
            "key-value support is experimental and must be enabled using the `kv_unstable` feature"
        )
    }

    // この logger 関数内部でどのログ実装を使用するのかを判断する
    logger().log(
        // Record に関しては Builder パターンを使用してオブジェクトの生成を行っている
        &Record::builder()
            .args(args)
            .level(level)
            .target(target)
            .module_path_static(Some(module_path))
            .file_static(Some(file))
            .line(Some(line))
            .build(),
    );
}

https://github.com/rust-lang/log/blob/f4c21c1b2dc958799eb6b3e8e713d1133862238a/src/lib.rs#L1468-L1490

実際に logger 関数の内容を確認すると以下のように AtomicUsize で管理している状態を取得し、初期化されたかどうかを判定させた後に実際に利用するロガーの判断を行なっています。

// ロガーの設定状態を管理する変数
static STATE: AtomicUsize = AtomicUsize::new(0); // 初期値は UNINITIALIZED
const UNINITIALIZED: usize = 0;
const INITIALIZING: usize = 1;
const INITIALIZED: usize = 2;

// グローバルに宣言されたロガーへのポイントを保持する
// AtomicUsizeで宣言された STATE により初期化されたかどうかを判定している
// NopLoggerは何もプロパティが設定されていないため、そのまま型を指定してグローバルに宣言することが可能である
static mut LOGGER: &dyn Log = &NopLogger;

// ...

pub fn logger() -> &'static dyn Log {
    // ロガーを初期化していない場合はデフォルトの実装として NopLogger が採用される
    if STATE.load(Ordering::SeqCst) != INITIALIZED {
        static NOP: NopLogger = NopLogger;
        &NOP
    } else {
        unsafe { LOGGER }
    }
}

https://github.com/rust-lang/log/blob/f4c21c1b2dc958799eb6b3e8e713d1133862238a/src/lib.rs#LL1348C1-L1350C2

AtomicUsize はマルチスレッド環境でのデータ一貫性を担保するために設計された型であり、複数のスレッドからでも値を安全に操作することが可能です。

AtomicUsize | std crate

ログ出力を行う際はマルチスレッド環境からでもロガーを呼び出す可能性はあるため、アトミックな操作でロガーが初期化されたかどうかを判定することで、どのログを利用するかの判断を安全に行っています。

(ただ、正直なところアトミック操作やメモリ順序への理解度は怪しいので「Rust Atomics and Locks」を読みたい。)

ここで AtomicUsize を初期化状態の管理で使用しているのは、ロガーの定義が static なライフタイムを有している可変参照として定義されているからです。

可変参照であるためそのまま利用してしまうと、複数のスレッドからロガーの初期化が呼び出されてしまった場合、 LOGGER に対して同時アクセスを行いデータ競合が発生してしまう可能性があります。そのため AtomicUsize を利用して初期化が一度だけ安全に行われることを保証するためにこのような設計になっているのだと推察しています。

次に set_logger メソッドが内部でどのように初期化を行っているのかを確認します。

// この関数でグローバルに宣言されたロガーを受け取って、static mutな変数を変更する
pub fn set_logger(logger: &'static dyn Log) -> Result<(), SetLoggerError> {
    set_logger_inner(|| logger)
}

// この内部でロガーを変更するが、AtomicUsizeを利用することで安全に上書きするようにしている
fn set_logger_inner<F>(make_logger: F) -> Result<(), SetLoggerError>
where
    F: FnOnce() -> &'static dyn Log,
{
    let old_state = match STATE.compare_exchange(
        UNINITIALIZED, // 現在の値が第1引数と等しい場合に
        INITIALIZING,  // 現在の値を第2引数で指定した値に交換する
        Ordering::SeqCst,
        Ordering::SeqCst,
    ) {
        Ok(s) | Err(s) => s,
    };
    match old_state {
        UNINITIALIZED => {
            unsafe {
                LOGGER = make_logger();
            }
            STATE.store(INITIALIZED, Ordering::SeqCst);
            Ok(())
        }
        INITIALIZING => {
            while STATE.load(Ordering::SeqCst) == INITIALIZING {
                // TODO: replace with `hint::spin_loop` once MSRV is 1.49.0.
                #[allow(deprecated)]
                std::sync::atomic::spin_loop_hint();
            }
            Err(SetLoggerError(()))
        }
        _ => Err(SetLoggerError(())),
    }
}

https://github.com/rust-lang/log/blob/304eef7d30526575155efbdf1056f92c5920238c/src/lib.rs#L1352-L1382

AtomicUsize が提供する compare_exchange は、現在の値と第 1 引数で指定された値と比較して、同じ値の場合には第 2 引数で指定した値に置き換えます。そして、関数の返り値に置き換え前の現在の値を返却します。

この状態の変更に関しては Ordering::SeqCst が指定されているため、必ず 1 度に 1 つのスレッドのみがアトミックに状態を INITIALIZING という初期化中であることを示す状態に変更することになります。

もしもあるスレッドがログ設定を行なっている間に、他のスレッドがログ設定の関数を呼び出した場合には old_stateINITIALIZING が返却され、後続の処理でスピンループを行うことでそのスレッドでの初期化設定が完了するまで待機し、そのあとでエラーを返却しています。

このような初期化処理を実現することで、グローバルにロガー設定が 1 度のみしか呼出されないことを保証しています。

fn set_max_level(level: LevelFilter)

info! マクロを呼び出せば、自動的にログレベル Info が設定された Metadata がログレコードに付与された状態になりますが、これだけだと全てのログメッセージが表示されてしまいます。

そこで log クレートは set_max_level というログの出力を調整するための関数を用意しています。

// ログレベルに関してもグローバルなアトミックの設定を有している
static MAX_LOG_LEVEL_FILTER: AtomicUsize = AtomicUsize::new(0);

// ...

pub fn set_max_level(level: LevelFilter) {
    MAX_LOG_LEVEL_FILTER.store(level as usize, Ordering::Relaxed);
}

https://github.com/rust-lang/log/blob/304eef7d30526575155efbdf1056f92c5920238c/src/lib.rs#LL1220C1-L1222C2

ここで Ordering::Relaxed を設定して制約を緩めている背景は以下の ISSUE で言及されている通り、現在設定されている最大のログレベルを取得する箇所が Ordering::Relaxed を設定しているためです。

Confusing memory orderings for MAX_LOG_LEVEL_FILTER

他のライブラリでは、このメソッドは Log トレイトの実装を行なったロガーの初期化を行うメソッドの内部で利用されていることが多い印象です。

例えば simple_logger の場合であれば、以下のようなロガーを生成する処理の中でログレベルを設定し、そのメソッド内部で set_max_level を呼び出すようにしており、 log クレートが提供するAPIの抽象化を行なっています。

simple_logger::init_with_level(log::Level::Warn).unwrap();

ここで設定したログレベルを、どのように管理して、ログの出力判断を行う enabled でどのように使用しているのかは、それぞれライブラリの実装によって異なっています。

fn set_boxed_logger(logger: Box<dyn Log>) -> Result<(), SetLoggerError>

set_logger 関数では &'static dyn Log 型を引数に取る都合上、 Log トレイトを実装したロガーは、プログラムの実行全体にわたって有効なものでないといけません。

そのため公式ドキュメントのサンプルでは、初期化を行う際に static でロガーを宣言するようにしていました。

struct SimpleLogger;
impl log::Log for SimpleLogger {
    // ...
}

static LOGGER: SimpleLogger = SimpleLogger;

fn main() {
    log::set_logger(&LOGGER).unwrap();
}

このように記述できるのは SimpleLogger がフィールドを持たないユニット構造体であり、その型の名前自体が唯一の値となるため SimpleLogger とだけ定義すればインスタンスを作成できるからです。

しかし、他のライブラリのようにロガーに対して各種設定を制御するためにフィールドを追加すると、他の方法でロガーを初期化して static な参照を取得する必要があります。

そのような場合に利用できるのは set_boxed_logger 関数です。

set_boxed_logger | log crate

これは内部的には set_logger 関数と同様に set_logger_inner 関数を呼び出しているだけですが、関数の引数と指定しているクロージャーの処理が異なっています。

pub fn set_boxed_logger(logger: Box<dyn Log>) -> Result<(), SetLoggerError> {
    set_logger_inner(|| Box::leak(logger))
}

ここで使用している Box::leak メソッドは、Box を使用してヒープ上に確保されたメモリを、明示的にリークさせることでそのメモリをプログラム終了時まで保持させることのできるメソッドです。

Box::leak

このメソッドを実行することで logger をプログラム終了までヒープ上に保持させるようにし、その結果このメソッドから返却されるものは &'static mut Log の参照となり、エラーが発生することなくコンパイルすることが可能です。

この set_boxed_logger を利用することで、 static な値で初期化することなく、以下のように特定のスコープ内で生成されたロガーをグローバルな変数として登録することができます。

// simple_loggerの例
fn main() {
    // Box::leakを活用することで関数内で生成したロガーを static に登録できる
    SimpleLogger::new().init().unwrap();

    log::warn!("This is an example message.");
}

fn set_max_level(level: LevelFilter)

log クレートではグローバルに最大のログレベルを設定することのできる関数 set_max_logger が提供されている。

set_max_logger | log crate

この関数を通して設定されたログレベルを info! などの各種マクロを実行した際に参照し、ログ出力を行うかどうかを判断しています。

// log!(target: "my_target", Level::Info, "a {} event", "log");
(target: $target:expr, $lvl:expr, $($arg:tt)+) => ({
    let lvl = $lvl;
    // ここでコンパイル時に設定したログレベルと、関数を通して設定したログレベルを参照し
    // 対象するログメッセージのログレベルとの比較を行い出力判断を行なっている
    if lvl <= $crate::STATIC_MAX_LEVEL && lvl <= $crate::max_level() {
        $crate::__private_api_log(
            __log_format_args!($($arg)+),
            lvl,
            &($target, __log_module_path!(), __log_file!(), __log_line!()),
            $crate::__private_api::Option::None,
        );
    }
});

https://github.com/rust-lang/log/blob/304eef7d30526575155efbdf1056f92c5920238c/src/macros.rs#L45-L56

この処理の中では以下の 2 つのログレベルを参照している。

log クレートでは、ログレベルとして以下の Enum を定義しており、各マクロに対応するログレベルと、全てのログを出力しないレベルに設定された Off のログレベルが定義されており、この Off ログレベルが初期値として設定されています。

static MAX_LOG_LEVEL_FILTER: AtomicUsize = AtomicUsize::new(0);

pub enum LevelFilter {
    /// A level lower than all log levels.
    Off,
    /// Corresponds to the `Error` log level.
    Error,
    /// Corresponds to the `Warn` log level.
    Warn,
    /// Corresponds to the `Info` log level.
    Info,
    /// Corresponds to the `Debug` log level.
    Debug,
    /// Corresponds to the `Trace` log level.
    Trace,
}

LevelFilter | log crate

つまり関数を使用してこのログレベルを変更しなければ、デフォルトでは全てのログ出力は抑制されてしまいます。

最大のログレベルを調整するための関数は以下のように定義されています。

// https://github.com/rust-lang/log/blob/304eef7d30526575155efbdf1056f92c5920238c/src/lib.rs#LL1265C1-L1273C2
pub fn max_level() -> LevelFilter {
    unsafe { mem::transmute(MAX_LOG_LEVEL_FILTER.load(Ordering::Relaxed)) }
}

// https://github.com/rust-lang/log/blob/304eef7d30526575155efbdf1056f92c5920238c/src/lib.rs#LL1220C1-L1222C2
pub fn set_max_level(level: LevelFilter) {
    MAX_LOG_LEVEL_FILTER.store(level as usize, Ordering::Relaxed);
}

std::mem::transmute は非常に危険な関数ではあるが、ある型から別の型へのビット単位の移動行うため、引数で指定した値から返り値で指定した型に対してビットをコピーします。

log クレートの場合ではマルチスレッドでログレベルの変更を管理するために AtomicUsize を利用しているため、ログレベルを定義している LevelFilterusize で型が異なっています。関数のインターフェースレベルでは LevelFilter を表に出しているため、 LevelFilter をアトミックに更新するための裏技的なやり方です。

match 式などを利用してより安全に型変換を行う方法もありますが、どの値にも該当しない exhaustive patterns をどのように取り扱うのか、であったり単純なビット移動である transmute の方がパフォーマンスが良い、という理由で現状のコードになっている可能性はあります。

トランスミュート transmute

log トレイトの実装を提供しているクレート

ここからはクレートがどのように Log トレイを実装しているのかを見ていきます。

よく利用されているであろうクレートは、例えば以下のようなものだと思いますが、今回は simple_logger を対象にします。

simple_logger

初期化用の関数

simple_logger はロガーの設定や出力メッセージがとてもシンプルで使いやすいクレートであり、本体のコードも lib.rs のみで構成されているため Log トレイトの実装例確認の最初の一歩に適しています。

公式から提供されている Getting Started なコードを確認すると、提供されているメソッドの中で、今まで説明してきた set_boxed_logger によるグローバルなロガーの宣言や set_max_level での最大ログレベルの設定を行なっていることが想像できます。

use simple_logger::SimpleLogger;

fn main() {
    SimpleLogger::new().init().unwrap();

    log::warn!("This is an example message.");
}

これで以下のようにログメッセージが表示されます。

2023-05-30T11:49:38.789Z WARN  [simple] This is an example message.

このクレートでは関連関数を使用していることからわかるように SimpleLogger のインスタンス生成と設定適用の関数をそれぞれ役割に分けて分離させています。

impl SimpleLogger {
    #[must_use = "You must call init() to begin logging"]
    pub fn new() -> SimpleLogger {
        SimpleLogger {
            default_level: LevelFilter::Trace,
            module_levels: Vec::new(),

            // 各フィーチャーフラグで有効化させるプロパティ
        }
    }
}

https://github.com/borntyping/rust-simple_logger/blob/3a78bcf7ab4f4b594c0b55290afe42a50b6a295f/src/lib.rs#LL105C1-L123C6

ここでは #[must_use] 属性を利用することで以下のようにロガー設定を行うための init 関数を呼び出していない場合には警告を発するようになっています。

fn main() {
    // warningが発生する
    SimpleLogger::new();
}
pub fn init(mut self) -> Result<(), SetLoggerError> {
    // ...

    self.module_levels
        .sort_by_key(|(name, _level)| name.len().wrapping_neg());
    let max_level = self.module_levels.iter().map(|(_name, level)| level).copied().max();
    let max_level = max_level
        .map(|lvl| lvl.max(self.default_level))
        .unwrap_or(self.default_level);
    log::set_max_level(max_level);
    log::set_boxed_logger(Box::new(self))?;
    Ok(())
}

https://github.com/borntyping/rust-simple_logger/blob/3a78bcf7ab4f4b594c0b55290afe42a50b6a295f/src/lib.rs#LL347C1-L363C6

この init 関数で最大のログレベルの設定やロガーのグローバルな値として登録を行なっていマス。また最大のログレベルは module_levels を調整するか default_level を調整する 2 つの方法があることがわかり、それぞれ SimpleLogger が提供している with_module_level 関数や with_level 関数を通して制御することが可能です。

SimpleLogger では env_logger の挙動を模倣させ環境変数からも最大のログレベルを設定することが可能です。

#[must_use = "You must call init() to begin logging"]
pub fn env(mut self) -> SimpleLogger {
    self.default_level = std::env::var("RUST_LOG")
        .ok()
        .as_deref()
        .map(log::LevelFilter::from_str)
        .and_then(Result::ok)
        .unwrap_or(self.default_level);

    self
}

https://github.com/borntyping/rust-simple_logger/blob/3a78bcf7ab4f4b594c0b55290afe42a50b6a295f/src/lib.rs#LL157C1-L167C6

こうした環境変数からの読み取りを行うメソッドが提供されているため、このメソッドを初期化の際に利用すれば、 RUST_LOG=info cargo run という形式で最大のログレベルを設定することができます。 dotenvy などと組み合わせれば、アプリケーションを動作させる環境ごとに異なるログレベルを設定することも容易です。

log クレートが提供している LevelFilterFromStr トレイトを実装しているため、環境変数から取得した文字列と事前に定義されたログレベルの文字列との比較を行うことで、対象の型への変換を行なっている。

static LOG_LEVEL_NAMES: [&str; 6] = ["OFF", "ERROR", "WARN", "INFO", "DEBUG", "TRACE"];

impl FromStr for LevelFilter {
    type Err = ParseLevelError;
    fn from_str(level: &str) -> Result<LevelFilter, Self::Err> {
        ok_or(
            LOG_LEVEL_NAMES
                .iter()
                .position(|&name| name.eq_ignore_ascii_case(level))
                .map(|p| LevelFilter::from_usize(p).unwrap()),
            ParseLevelError(()),
        )
    }
}

https://github.com/rust-lang/log/blob/304eef7d30526575155efbdf1056f92c5920238c/src/lib.rs#LL583C1-L594C2

なお、これらの設定を簡易的に行うための専用の関数も用意されています。

pub fn init_with_env() -> Result<(), SetLoggerError> {
    SimpleLogger::new().env().init()
}

https://github.com/borntyping/rust-simple_logger/blob/3a78bcf7ab4f4b594c0b55290afe42a50b6a295f/src/lib.rs#LL542C1-L544C2

まとめ

log クレートの調査をしていく中で Box::leak を利用した static なライフタイムを有する参照の作成方法であったり、 AtomicUsize を利用したマルチスレッド環境を考慮した状態遷移がどのように実装されているのかを把握することができました。

今までは以下のコードを見ても、マクロを実行したときにどのようにロガーを参照しているのか理解できていませんでしたが、コードリーディングを通してどのような機能を利用しているのか想像できるようになりました。

fn main() {
    SimpleLogger::new().init().unwrap();

    log::warn!("This is an example message.");
}

Log トレイトの実装を提供している他のクレートも同じことを行なっているはずなので、 env_loggerfern などのコードリーディングを行うときも、 log クレートが裏側でどのような処理を行なっているのか想像できる状態になっているため、そこまで苦労しなさそうです、