Skip to content

Add an optional logger param #664

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 12 commits into from
Mar 23, 2025
Merged

Add an optional logger param #664

Show file tree
Hide file tree
Changes from 6 commits
Commits
Show all changes
12 commits
Select commit Hold shift + click to select a range
d5061b6
Add an optional logger param
tisonkun Feb 1, 2025
2851f2b
fixup MSRV
tisonkun Feb 1, 2025
a3f72c8
separate logger
tisonkun Feb 1, 2025
dd835fe
fixup msrv tests
tisonkun Feb 1, 2025
c300df0
Merge branch 'master' into logger-field
tisonkun Feb 25, 2025
cde2585
allows us to pass zero-sized logger
tisonkun Feb 27, 2025
2bb47d6
use a zero-sized GlobalLogger
tisonkun Feb 28, 2025
11af9f1
move logger expr to execute conditionally
tisonkun Mar 17, 2025
da3dd1f
add docs
tisonkun Mar 17, 2025
0bf505d
more docs
tisonkun Mar 17, 2025
66a7ab7
address comment
tisonkun Mar 18, 2025
088f9f3
address comments
tisonkun Mar 21, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
23 changes: 16 additions & 7 deletions src/__private_api.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
//! WARNING: this is not part of the crate's public API and is subject to change at any time

use self::sealed::KVs;
use crate::{Level, Metadata, Record};
use crate::{Level, Log, Metadata, Record};
use std::fmt::Arguments;
use std::panic::Location;
pub use std::{format_args, module_path, stringify};
Expand Down Expand Up @@ -34,7 +34,8 @@ impl<'a> KVs<'a> for () {

// Log implementation.

fn log_impl(
fn log_impl<L: Log>(
logger: L,
args: Arguments,
level: Level,
&(target, module_path, loc): &(&str, &'static str, &'static Location),
Expand All @@ -58,22 +59,30 @@ fn log_impl(
#[cfg(feature = "kv")]
builder.key_values(&kvs);

crate::logger().log(&builder.build());
logger.log(&builder.build());
}

pub fn log<'a, K>(
pub fn log<'a, K, L>(
logger: L,
args: Arguments,
level: Level,
target_module_path_and_loc: &(&str, &'static str, &'static Location),
kvs: K,
) where
K: KVs<'a>,
L: Log,
{
log_impl(args, level, target_module_path_and_loc, kvs.into_kvs())
log_impl(
logger,
args,
level,
target_module_path_and_loc,
kvs.into_kvs(),
)
}

pub fn enabled(level: Level, target: &str) -> bool {
crate::logger().enabled(&Metadata::builder().level(level).target(target).build())
pub fn enabled<L: Log>(logger: L, level: Level, target: &str) -> bool {
logger.enabled(&Metadata::builder().level(level).target(target).build())
}

#[track_caller]
Expand Down
128 changes: 112 additions & 16 deletions src/macros.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -30,11 +30,13 @@
#[macro_export]
#[clippy::format_args]
macro_rules! log {
// log!(target: "my_target", Level::Info, key1:? = 42, key2 = true; "a {} event", "log");
(target: $target:expr, $lvl:expr, $($key:tt $(:$capture:tt)? $(= $value:expr)?),+; $($arg:tt)+) => ({
// log!(logger: my_logger, target: "my_target", Level::Info, key1:? = 42, key2 = true; "a {} event", "log");
(logger: $logger:expr, target: $target:expr, $lvl:expr, $($key:tt $(:$capture:tt)? $(= $value:expr)?),+; $($arg:tt)+) => ({
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think we should take logger by value here since we don't take any other inputs by value, and the write! macro doesn't take its input writer by value.

In order to get the most benefit from a zero-sized logger we'd need to do some refactoring of the __private_api::log function, to invoke the log function at the callsite, or figure something else out, but we can do that in a follow-up PR.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for your advice. Let me give it another consideration ..

let logger = $logger;
let lvl = $lvl;
if lvl <= $crate::STATIC_MAX_LEVEL && lvl <= $crate::max_level() {
$crate::__private_api::log::<&_>(
$crate::__private_api::log::<&_, _>(
logger,
$crate::__private_api::format_args!($($arg)+),
lvl,
&($target, $crate::__private_api::module_path!(), $crate::__private_api::loc()),
Expand All @@ -43,11 +45,13 @@ macro_rules! log {
}
});

// log!(target: "my_target", Level::Info, "a {} event", "log");
(target: $target:expr, $lvl:expr, $($arg:tt)+) => ({
// log!(logger: my_logger, target: "my_target", Level::Info, "a {} event", "log");
(logger: $logger:expr, target: $target:expr, $lvl:expr, $($arg:tt)+) => ({
let logger = $logger;
let lvl = $lvl;
if lvl <= $crate::STATIC_MAX_LEVEL && lvl <= $crate::max_level() {
$crate::__private_api::log(
logger,
$crate::__private_api::format_args!($($arg)+),
lvl,
&($target, $crate::__private_api::module_path!(), $crate::__private_api::loc()),
Expand All @@ -56,8 +60,20 @@ macro_rules! log {
}
});

// log!(logger: my_logger, Level::Info, "a log event")
(logger: $logger:expr, $lvl:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, target: $crate::__private_api::module_path!(), $lvl, $($arg)+)
});

// log!(target: "my_target", Level::Info, "a log event")
(target: $target:expr, $lvl:expr, $($arg:tt)+) => ({
$crate::log!(logger: $crate::logger(), target: $target, $lvl, $($arg)+)
});

// log!(Level::Info, "a log event")
($lvl:expr, $($arg:tt)+) => ($crate::log!(target: $crate::__private_api::module_path!(), $lvl, $($arg)+));
($lvl:expr, $($arg:tt)+) => ({
$crate::log!(target: $crate::__private_api::module_path!(), $lvl, $($arg)+)
});
}

/// Logs a message at the error level.
Expand All @@ -77,9 +93,23 @@ macro_rules! log {
#[macro_export]
#[clippy::format_args]
macro_rules! error {
// error!(logger: my_logger, target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// error!(logger: my_logger, target: "my_target", "a {} event", "log")
(logger: $logger:expr, target: $target:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, target: $target, $crate::Level::Error, $($arg)+)
});

// error!(logger: my_logger, key1 = 42, key2 = true; "a {} event", "log")
// error!(logger: my_logger, "a {} event", "log")
(logger: $logger:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, $crate::Level::Error, $($arg)+)
});

// error!(target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// error!(target: "my_target", "a {} event", "log")
(target: $target:expr, $($arg:tt)+) => ($crate::log!(target: $target, $crate::Level::Error, $($arg)+));
(target: $target:expr, $($arg:tt)+) => ({
$crate::log!(target: $target, $crate::Level::Error, $($arg)+)
});

// error!("a {} event", "log")
($($arg:tt)+) => ($crate::log!($crate::Level::Error, $($arg)+))
Expand All @@ -102,9 +132,23 @@ macro_rules! error {
#[macro_export]
#[clippy::format_args]
macro_rules! warn {
// warn!(logger: my_logger, target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// warn!(logger: my_logger, target: "my_target", "a {} event", "log")
(logger: $logger:expr, target: $target:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, target: $target, $crate::Level::Warn, $($arg)+)
});

// warn!(logger: my_logger, key1 = 42, key2 = true; "a {} event", "log")
// warn!(logger: my_logger, "a {} event", "log")
(logger: $logger:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, $crate::Level::Warn, $($arg)+)
});

// warn!(target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// warn!(target: "my_target", "a {} event", "log")
(target: $target:expr, $($arg:tt)+) => ($crate::log!(target: $target, $crate::Level::Warn, $($arg)+));
(target: $target:expr, $($arg:tt)+) => ({
$crate::log!(target: $target, $crate::Level::Warn, $($arg)+)
});

// warn!("a {} event", "log")
($($arg:tt)+) => ($crate::log!($crate::Level::Warn, $($arg)+))
Expand All @@ -129,9 +173,23 @@ macro_rules! warn {
#[macro_export]
#[clippy::format_args]
macro_rules! info {
// info!(logger: my_logger, target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// info!(logger: my_logger, target: "my_target", "a {} event", "log")
(logger: $logger:expr, target: $target:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, target: $target, $crate::Level::Info, $($arg)+)
});

// info!(logger: my_logger, key1 = 42, key2 = true; "a {} event", "log")
// info!(logger: my_logger, "a {} event", "log")
(logger: $logger:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, $crate::Level::Info, $($arg)+)
});

// info!(target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// info!(target: "my_target", "a {} event", "log")
(target: $target:expr, $($arg:tt)+) => ($crate::log!(target: $target, $crate::Level::Info, $($arg)+));
(target: $target:expr, $($arg:tt)+) => ({
$crate::log!(target: $target, $crate::Level::Info, $($arg)+)
});

// info!("a {} event", "log")
($($arg:tt)+) => ($crate::log!($crate::Level::Info, $($arg)+))
Expand All @@ -155,9 +213,23 @@ macro_rules! info {
#[macro_export]
#[clippy::format_args]
macro_rules! debug {
// debug!(logger: my_logger, target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// debug!(logger: my_logger, target: "my_target", "a {} event", "log")
(logger: $logger:expr, target: $target:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, target: $target, $crate::Level::Debug, $($arg)+)
});

// debug!(logger: my_logger, key1 = 42, key2 = true; "a {} event", "log")
// debug!(logger: my_logger, "a {} event", "log")
(logger: $logger:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, $crate::Level::Debug, $($arg)+)
});

// debug!(target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// debug!(target: "my_target", "a {} event", "log")
(target: $target:expr, $($arg:tt)+) => ($crate::log!(target: $target, $crate::Level::Debug, $($arg)+));
(target: $target:expr, $($arg:tt)+) => ({
$crate::log!(target: $target, $crate::Level::Debug, $($arg)+)
});

// debug!("a {} event", "log")
($($arg:tt)+) => ($crate::log!($crate::Level::Debug, $($arg)+))
Expand All @@ -183,9 +255,23 @@ macro_rules! debug {
#[macro_export]
#[clippy::format_args]
macro_rules! trace {
// trace!(logger: my_logger, target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// trace!(logger: my_logger, target: "my_target", "a {} event", "log")
(logger: $logger:expr, target: $target:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, target: $target, $crate::Level::Trace, $($arg)+)
});

// trace!(logger: my_logger, key1 = 42, key2 = true; "a {} event", "log")
// trace!(logger: my_logger, "a {} event", "log")
(logger: $logger:expr, $($arg:tt)+) => ({
$crate::log!(logger: $logger, $crate::Level::Trace, $($arg)+)
});

// trace!(target: "my_target", key1 = 42, key2 = true; "a {} event", "log")
// trace!(target: "my_target", "a {} event", "log")
(target: $target:expr, $($arg:tt)+) => ($crate::log!(target: $target, $crate::Level::Trace, $($arg)+));
(target: $target:expr, $($arg:tt)+) => ({
$crate::log!(target: $target, $crate::Level::Trace, $($arg)+)
});

// trace!("a {} event", "log")
($($arg:tt)+) => ($crate::log!($crate::Level::Trace, $($arg)+))
Expand Down Expand Up @@ -219,15 +305,25 @@ macro_rules! trace {
/// ```
#[macro_export]
macro_rules! log_enabled {
(target: $target:expr, $lvl:expr) => {{
(logger: $logger:expr, target: $target:expr, $lvl:expr) => ({
let logger = $logger;
let lvl = $lvl;
lvl <= $crate::STATIC_MAX_LEVEL
&& lvl <= $crate::max_level()
&& $crate::__private_api::enabled(lvl, $target)
}};
($lvl:expr) => {
&& $crate::__private_api::enabled(logger, lvl, $target)
});

(logger: $logger:expr, $lvl:expr) => ({
$crate::log_enabled!(logger: $logger, target: $crate::__private_api::module_path!(), $lvl)
});

(target: $target:expr, $lvl:expr) => ({
$crate::log_enabled!(logger: $crate::logger(), target: $target, $lvl)
});

($lvl:expr) => ({
$crate::log_enabled!(target: $crate::__private_api::module_path!(), $lvl)
};
});
}

// These macros use a pattern of #[cfg]s to produce nicer error
Expand Down
32 changes: 16 additions & 16 deletions tests/integration.rs
View file
Open in desktop
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is just a good target to test our new logger param.

Previously, the global logger state is shared with all the macros tests and causes the result unstable.

Original file line number Diff line number Diff line change
Expand Up @@ -53,31 +53,31 @@ fn main() {
last_log_location: Mutex::new(None),
});
let a = me.clone();
set_boxed_logger(Box::new(Logger(me))).unwrap();
let logger = Logger(me);
Copy link
Contributor

@SpriteOvO SpriteOvO Feb 28, 2025 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What happens if we call a log macro with logger param here? The macro would expand a let logger = $logger;, which seems to move rather than borrow the logger variable.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IIUC it would be debug!(logger: &logger, ...) then. That is, use ref from the user size.

One of the rationales is @EFanZh's comment about "binary size", see:

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see. If explicitly passing ref from the user side is intentional, then I'm fine with that.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I made a comment above, but don't think we should take logger by value. We can try resolve the binary size issue independently, but from a public API perspective, we should follow the convention of std::write!, and other inputs to log!, which don't take non-copy inputs by-value.

Copy link
Contributor

@EFanZh EFanZh Mar 23, 2025 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@KodrAus: How about keeping __private_api::log taking logger argument by value, but the logger macros pass references for custom loggers, and pass global logger by value? In this way, the global logger can still utilize the ZST optimization, although not the custom ones.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@EFanZh That sounds good to me 👍 We're currently halfway there; the __private_api::log function takes the logger by value, but the way we expand log! macros always takes by reference. I'll follow up with that change to make an unspecified logger accept GlobalLogger by value. That's also a good way for me to get fully across the new code.


test_filter(&a, LevelFilter::Off);
test_filter(&a, LevelFilter::Error);
test_filter(&a, LevelFilter::Warn);
test_filter(&a, LevelFilter::Info);
test_filter(&a, LevelFilter::Debug);
test_filter(&a, LevelFilter::Trace);
test_filter(&logger, &a, LevelFilter::Off);
test_filter(&logger, &a, LevelFilter::Error);
test_filter(&logger, &a, LevelFilter::Warn);
test_filter(&logger, &a, LevelFilter::Info);
test_filter(&logger, &a, LevelFilter::Debug);
test_filter(&logger, &a, LevelFilter::Trace);

test_line_numbers(&a);
test_line_numbers(&logger, &a);
}
}

fn test_filter(a: &State, filter: LevelFilter) {
fn test_filter(logger: &dyn Log, a: &State, filter: LevelFilter) {
// tests to ensure logs with a level beneath 'max_level' are filtered out
log::set_max_level(filter);
error!("");
error!(logger: logger, "");
last(a, t(Level::Error, filter));
warn!("");
warn!(logger: logger, "");
last(a, t(Level::Warn, filter));
info!("");
info!(logger: logger, "");
last(a, t(Level::Info, filter));
debug!("");
debug!(logger: logger, "");
last(a, t(Level::Debug, filter));
trace!("");
trace!(logger: logger, "");
last(a, t(Level::Trace, filter));

fn t(lvl: Level, filter: LevelFilter) -> Option<Level> {
Expand All @@ -93,10 +93,10 @@ fn test_filter(a: &State, filter: LevelFilter) {
}
}

fn test_line_numbers(state: &State) {
fn test_line_numbers(logger: &dyn Log, state: &State) {
log::set_max_level(LevelFilter::Trace);

info!(""); // ensure check_line function follows log macro
info!(logger: logger, ""); // ensure check_line function follows log macro
check_log_location(state);

#[track_caller]
Expand Down
19 changes: 18 additions & 1 deletion tests/macros.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,4 @@
use log::{log, log_enabled};
use log::{log, log_enabled, Log, Metadata, Record};

macro_rules! all_log_macros {
($($arg:tt)*) => ({
Expand All @@ -10,6 +10,16 @@ macro_rules! all_log_macros {
});
}

struct NopLogger;

impl Log for NopLogger {
fn enabled(&self, _: &Metadata) -> bool {
false
}
fn log(&self, _: &Record) {}
fn flush(&self) {}
}
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This inspires me to consider whether we should export the NopLogger ..


#[test]
fn no_args() {
for lvl in log::Level::iter() {
Expand All @@ -28,6 +38,11 @@ fn no_args() {

all_log_macros!(target: "my_target", "hello");
all_log_macros!(target: "my_target", "hello",);

all_log_macros!(logger: NopLogger, "hello");
all_log_macros!(logger: NopLogger, "hello",);
all_log_macros!(logger: NopLogger, target: "my_target", "hello");
all_log_macros!(logger: NopLogger, target: "my_target", "hello",);
}

#[test]
Expand Down Expand Up @@ -115,6 +130,8 @@ fn kv_no_args() {
log!(lvl, cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello");
}

all_log_macros!(logger: NopLogger, cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello");
all_log_macros!(logger: NopLogger, target: "my_target", cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello");
all_log_macros!(target: "my_target", cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello");
all_log_macros!(target = "my_target", cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello");
all_log_macros!(cat_1 = "chashu", cat_2 = "nori", cat_count = 2; "hello");
Expand Down