Skip to content
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.

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

Add an optional logger param #664

Open
wants to merge 11 commits into
base: master
Choose a base branch
from

Conversation

tisonkun
Copy link
Contributor

@tisonkun tisonkun commented Feb 1, 2025

This closes #645

@KodrAus I noticed that we previously introduced target for similar usage, but switching to a different logger is different.

This patch is for preview. I'm not quite sure how we pass the customized logger. The current implementation seems good. I think the log crate itself isn't suitable to hold a global name -> logger registry: that would be too heavy and too specific.

Signed-off-by: tison <[email protected]>
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.

Signed-off-by: tison <[email protected]>
@Thomasdezeeuw
Copy link
Collaborator

I'm not convinced this is a common enough use case that it has to be in facade, couldn't it be implemented in the logging implementation?

@tisonkun
Copy link
Contributor Author

tisonkun commented Feb 3, 2025

@Thomasdezeeuw

spdlog-rs implements this, with their own log! macro. When adapting to the log crate's macros, the functionality can't be used.

So, the logging implementation must implement the same functionality by bypassing our macro, which loses the value of a facade. If you have an idea how to implement and use it with our abstraction and a custom impl crate, I'm glad to know.

@Thomasdezeeuw
Copy link
Collaborator

So, the logging implementation must implement the same functionality by bypassing our macro, which loses the value of a facade. If you have an idea how to implement and use it with our abstraction and a custom impl crate, I'm glad to know.

I my crate I used the target to change the target of the logs. In this it uses a constant for the target to switch from logging to standard error to standard out. See https://docs.rs/std-logger/latest/std_logger/macro.request.html for an example, but any macro can be used by setting the target to a constant (https://docs.rs/std-logger/latest/std_logger/constant.REQUEST_TARGET.html)

@tisonkun
Copy link
Contributor Author

tisonkun commented Feb 3, 2025

Thanks for your information! I'm considering the difference between target and a logger field also.

In the description:

I noticed that we previously introduced target for similar usage, but switching to a different logger is different.

Switching targets still use the same (global & singleton) logger instance, while setting a new logger instance can avoid meta logging cycle - #645.

@Thomasdezeeuw
Copy link
Collaborator

Switching targets still use the same (global & singleton) logger instance, while setting a new logger instance can avoid meta logging cycle - #645.

The global logging implementation can be set up to call different loggers depending on target.

@KodrAus
Copy link
Contributor

KodrAus commented Feb 5, 2025

Personally, I think being able to target a different logger entirely using an argument is useful in a few scenarios:

  1. You want to log from your logging pipeline. If your pipeline is complex enough, you sometimes end up needing to do this.
  2. You don't want to use a global logger at all, but still want some of the nice ergonomics of the macros. You may do this, for example, to implement your own simplified contextual logging.

From a maintenance perspective it also keeps us a bit honest in not being able to assume that everything is shared by a single global logger.

If @Thomasdezeeuw isn't convinced it's worth adding though then we'll leave it for the time being.

@Thomasdezeeuw
Copy link
Collaborator

I'm not convinced the additional complexity is worth the use case that is already possible via the log implementation.

@tisonkun do you have any argument why it should be done this way, and not via the log implementation?

@tisonkun
Copy link
Contributor Author

tisonkun commented Feb 7, 2025

It's included in the issue description of #645:

Filter certain targets in specific appended:

impl log::Log KafkaAppender {
  fn log(&self, record: &Record) {
    if record.target().start_with("rdkafka") { return; }
  }
}
```

This is, however, both brittle and may filter logs from user code. I don't know how targets are defined and if we can reliably depend on that matches.

That said, passing a logger instance is determinate for what is installed in the log implementation (pipeline), while target is a loose contract (convention).

If you have a single log instance with a Kafka appender installed, you may first filter out logs with target "kafka". But what if a user application uses the same target for their actions over kafka? Then you need to agree on a reserved target and every user should learn about it.

Instead, a pass-in logger can be an explicit contract that the certain logger is used by kafka client internally (if a client library adopts this) and thus you can fine tune the manner and be sure that it would be used in that scenario.

You don't want to use a global logger at all, but still want some of the nice ergonomics of the macros. You may do this, for example, to implement your own simplified contextual logging.

This is also a good point that when you have different log requirements for different components, instead of making a global instance and dispatching the application logic (rather than barely appending to multiple destinations), it would be easier to keep the logger instance separated.

Finally, if we support logging with a pass-in instance, it's possible to use a global instance everywhere. But the reverse direction is not true. slog's macros always has a logger param, while there is slog-global to use a global instance when it's satisfied.

@NobodyXu
Copy link

NobodyXu commented Feb 8, 2025

This PR reminds me of with_default:

Sets this Subscriber as the default for the current thread for the duration of a closure.

The default subscriber is used when creating a new Span or Event.

Sounds like you actually want something like this?

@tisonkun

@tisonkun
Copy link
Contributor Author

tisonkun commented Feb 8, 2025

Sounds like you actually want something like this?

@NobodyXu No. This is a thread-local default, which can be even worse than a global default to tune with. The logger field in log! macro is an explicit instance, with_default is a more subtle implict.

Copy link
Contributor

@SpriteOvO SpriteOvO left a comment

Choose a reason for hiding this comment

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

Hi, I'm the author of spdlog-rs, and I'd like to thank @tisonkun for mentioning my crate and nominating to merge this feature into log crate, and @KodrAus for supporting this feature in the issue. I'll give my two cents here.

The introduction of the logger parameter (and replaceable global logger) in spdlog-rs (as well as the same concept in C++ spdlog) was primarily to address the inconvenience of singleton - can only be set once at startup.

Imagine you have a huge project with many components. Some components just print to standard streams, some components need to report logs to a specific network endpoint (maybe even this endpoint needs to be dynamically obtained and unknown at startup). In the singleton model, the initial setup needs to prepare all components for their needs, rather than being managed by the components themselves. And since the discriminator target is just a string, ambiguities may be uncommon but are by no means absent especially when match rules like starts_with are involved.

The addition of the logger parameter is not killing the singleton pattern, which is still the easiest way for lightweight projects, but larger projects can benefit from this harmless addition.

@tisonkun
Copy link
Contributor Author

Merge master branch and resolve conflicts.

May we have another round to review this patch?

Copy link
Contributor

@KodrAus KodrAus left a comment

Choose a reason for hiding this comment

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

This looks good to me @tisonkun 👍

@Thomasdezeeuw are you happy if we move forwards with this feature? I think pushing back on additions is a good position that keeps us from accumulating bloat, but feel like this one specifically is a reasonable enhancement aligned with the existing macro capabilities.

@Thomasdezeeuw
Copy link
Collaborator

@Thomasdezeeuw are you happy if we move forwards with this feature? I think pushing back on additions is a good position that keeps us from accumulating bloat, but feel like this one specifically is a reasonable enhancement aligned with the existing macro capabilities.

I still think the use case can be solved without this change, hence I don't think it's worth the additional complexity to be honest.

However, if we go forward with it have we looked at the code size changes? Work has been done in the past to reduce the compiler code size, is that affected at all? /cc @EFanZh in case you're still interested in this

@KodrAus
Copy link
Contributor

KodrAus commented Feb 26, 2025

I still think the use case can be solved without this change

Some of them can, but some can be done more easily without needing to write dispatching logic based on targets. Being able to plug a logger in to the macro calls would let you use local loggers for contextual logging, without needing a centrally synchronized place to store them. That could also potentially be solved with the key-value support though if we let you plug in an additional Source alongside specific key-values.

Maybe we can think of it more like print! vs write!. The former doesn't let you specify where the output goes, whereas the latter does. If we want to decide that log! is just print! with a configurable output via set_boxed_logger then this change isn't something we'd pursue. If we want the log! macros to be a general interface to any Log impl, then I think it would be very useful.

Copy link
Collaborator

@Thomasdezeeuw Thomasdezeeuw left a comment

Choose a reason for hiding this comment

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

I won't block this (any further) if code size isn't a concern.

I do think we should add some more documentation for this change as I don't see any. I would at least expect the logger argument to be documented and stating that by default it will use the global logger.

@tisonkun
Copy link
Contributor Author

I do this we should add some more documentation for this change as I don't see any. I would at least expect the logger argument to be documented and stating that by default it will use the global logger.

Thanks for your suggestions. Then please leave me a few days so that I can pick up this patch :D

@@ -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

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.

Comment on lines +1227 to +1239
impl Log for GlobalLogger {
fn enabled(&self, metadata: &Metadata) -> bool {
logger().enabled(metadata)
}

fn log(&self, record: &Record) {
logger().log(record)
}

fn flush(&self) {
logger().flush()
}
}
Copy link
Contributor Author

Choose a reason for hiding this comment

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

Shall we #[inline] here? In my application development conventions, I trust the compiler to do the inlining based on its analysis.

Copy link
Contributor

Choose a reason for hiding this comment

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

I think it's ok to leave #[inline] off these for now. Usually, if someone spots the opportunity to inline through other performance analysis they're doing they'll find their way here and propose it. At that point we'll have more information to see what the impact is.

Comment on lines +13 to +21
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 ..

@EFanZh
Copy link
Contributor

EFanZh commented Feb 28, 2025

Another thought: with the current implementation, user specified logger will always be passed by reference, which might not be ideal for binary size. Do we want to support the case where user can specify a zero-sized logger to reduce binary size?

@tisonkun
Copy link
Contributor Author

tisonkun commented Feb 28, 2025

Another thought: with the current implementation, user specified logger will always be passed by reference

What does it mean? We already accept L that can be an owned logger. Could you give a concrete example where a performance concern can occur.

Does 2bb47d6 implements what you mean for passing a zero-sized logger? If not, why.

@EFanZh
Copy link
Contributor

EFanZh commented Feb 28, 2025

@tisonkun: Oh, I thought the implementation still passes reference for user specified loggers. Now the implementation passes logger argument as is, then I have no further questions.

@tisonkun tisonkun requested a review from EFanZh February 28, 2025 14:56
@tisonkun
Copy link
Contributor Author

@EFanZh OK. Good to know the clarification.

Then just leave me some time to figure out how to improve the docs :D

@tisonkun tisonkun requested a review from EFanZh March 17, 2025 14:55
@tisonkun
Copy link
Contributor Author

@Thomasdezeeuw @KodrAus Added some docs. Welcome to give a review and see how we can improve.

/// to the logger registered with the `set_boxed_logger` or `set_logger`
/// methods if there is one, or a nop logger as default.
#[derive(Copy, Clone, Default, Debug)]
pub struct GlobalLogger;
Copy link
Collaborator

Choose a reason for hiding this comment

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

Should we hide this as an implementation detail?

Copy link
Contributor

Choose a reason for hiding this comment

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

I think we should keep this private, at least for now

Copy link
Contributor Author

Choose a reason for hiding this comment

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

OK. Then we may need to no_run the docs? Or it may be too wordy to define a dummy logger for each doc segments.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

We use this logger in the macro so we may expose it anyway. Do you mean move it to __private_api.rs?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

For why do we have this GlobalLogger, see #664 (comment).

Copy link
Contributor

Choose a reason for hiding this comment

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

I think we'd move it to __private_api. It would be an issue to try and actually use it for anything except in the logger argument. Attempting to install it via set_boxed_logger would be a bad time, for instance.

In the docs, we can at least hide the sections that define any custom loggers.

src/macros.rs Outdated
let lvl = $lvl;
if lvl <= $crate::STATIC_MAX_LEVEL && lvl <= $crate::max_level() {
let logger = $logger;
Copy link
Contributor

Choose a reason for hiding this comment

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

Also, maybe move $logger to the argument position? So that it can support temporary expressions such as std::convert::identity(&MyLogger::new());

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Let me give it a try ..

Copy link
Contributor

@KodrAus KodrAus left a comment

Choose a reason for hiding this comment

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

Thanks for working through this @tisonkun! There's been a lot of back-and-forth and you've done a lot to accommodate the various requirements of other users. I've just left a few comments.

Comment on lines +1227 to +1239
impl Log for GlobalLogger {
fn enabled(&self, metadata: &Metadata) -> bool {
logger().enabled(metadata)
}

fn log(&self, record: &Record) {
logger().log(record)
}

fn flush(&self) {
logger().flush()
}
}
Copy link
Contributor

Choose a reason for hiding this comment

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

I think it's ok to leave #[inline] off these for now. Usually, if someone spots the opportunity to inline through other performance analysis they're doing they'll find their way here and propose it. At that point we'll have more information to see what the impact is.

// 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 ..

@@ -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

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.

Signed-off-by: tison <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Question: meta logging in logger?
6 participants