serenity-rs / poise

Discord bot command framework for serenity, with advanced features like edit tracking and flexible argument parsing
MIT License
624 stars 111 forks source link

feat: switch to `tracing` #223

Closed vidhanio closed 9 months ago

vidhanio commented 9 months ago

closes #221

vidhanio commented 9 months ago

also, running cargo machete to make sure i left no useless log-related deps found that futures-core is in the Cargo.toml but never used. should i remove it in this pr?

kangalio commented 9 months ago

Just wondering, does this replacement improve anything about poise's logging at this point in time, from a user's perspective? Or does it just "unlock" fancier logging things in poise in the future, like #[instrument] and tracing spans, which another tracing+poise user would only then benefit from?

kangalio commented 9 months ago

also, running cargo machete to make sure i left no useless log-related deps found that futures-core is in the Cargo.toml but never used. should i remove it in this pr?

Haha that's really interesting. I tried to trace it back, but actually, the futures_core was not used ever. In https://github.com/serenity-rs/poise/commit/bf6a92c3025ab7eac3241509e1776b92ce57f106 I separated the futures dependency into futures_util and futures_core, but even in that commit, futures_core was seemingly not referenced anywhere. ¯_(ツ)_/¯ It can be removed. If this PR ends up getting merged, I don't mind that being part of this PR

vidhanio commented 9 months ago

Just wondering, does this replacement improve anything about poise's logging at this point in time, from a user's perspective? Or does it just "unlock" fancier logging things in poise in the future, like #[instrument] and tracing spans, which another tracing+poise user would only then benefit from?

the main benefit is the general benefits of tracing, being much more structured traces, better fit to work with asynchronous systems (spans which track a start and end of a call, so you can get nice cascading graphs with visual subscribers), which can be integrated more easily with other things in the tracing ecosystem. tracing does intelligently pick up logs and include them as "dumb" traces with no special metadata, but the support is not as good as proper tracing traces, which can track the entire (#[instrument]ed) call chain, meaning problems can be diagnosed easier. log is just about as useful as a println! with some extra niceties.

kangalio commented 9 months ago

The reason I'm asking is because I never felt the need for any of tracing's advanced capabilities in poise.log feels refreshingly simple, and exactly the level of simple poise needs.

So, since log and tracing seem to be intercompatible, I'd prefer to stick with log until the need for the more complex alternative actually arised?

vidhanio commented 9 months ago

The reason I'm asking is because I never felt the need for any of tracing's advanced capabilities in poise.log feels refreshingly simple, and exactly the level of simple poise needs.

So, since log and tracing seem to be intercompatible, I'd prefer to stick with log until the need for the more complex alternative actually arised?

that makes sense. if it changes your opinion at all, using tracing upstream still allows for log-only subscribers such as env_logger to collect logs downstream (without the special tracing metadata), but using log upstream greatly reduces the amount of useful information that tracing-compatible subscribers can pull downstream. using tracing in a library lets the user decide how much information they want, whereas using log in a library forces tracing-ready users to deal with less information than they could get.

in terms of simplicity, tracing macros' syntax is (iirc) a strict superet of log's, so the complexity in spitting out traces shouldn't change at all (in fact, i just ran a find-replace for log:: to tracing:: on the repository to port everything over).

i totally understand sticking with log though, because of the simplicity it provides.

kangalio commented 9 months ago

Interesting. Do you have examples on the useful information which tracing emits and log doesn't? I scoured the tracing codebase and the logging macros call chain but didn't learn much.

Btw I realized we could have a compromise solution; use tracing's logging macros in poise, but still use env_logger in all tests, examples etc. to avoid that weird boilerplate verbosity of tracing-subscriber (it looks ugly ngl)

Milo123459 commented 9 months ago

maybe make this feature gated, about which logging library to use?

kangalio commented 9 months ago

Nah, that doesn't give any benefit. Tracing is fully down compatible to log. If we invest the complexity and adopt tracing, log becomes totally redundant, and having both makes no sense

vidhanio commented 9 months ago

Interesting. Do you have examples on the useful information which tracing emits and log doesn't? I scoured the tracing codebase and the logging macros call chain but didn't learn much.

i don't have an example on hand, but a real life example from something i've worked on in the past is integrated tracing traces with opentelemetry and jaeger to get a waterfall-ish graph like this (only possible because tracing provides the start/end spans of a function call!) image great for analysis on which parts of the function are using the most time etc.

Btw I realized we could have a compromise solution; use tracing's logging macros in poise, but still use env_logger in all tests, examples etc. to avoid that weird boilerplate verbosity of tracing-subscriber (it looks ugly ngl)

that sounds like a good idea, i can push a new commit for that! yeah, i agree the whole EnvFilter::from_default_env() stuff is very verbose.

kangalio commented 9 months ago

(only possible because tracing provides the start/end spans of a function call!)

Only when using spans in the library code, right? Either directly, or indirectly via #[instrument]. The tracing calls in poise are single point in time events only.. I'd tend towards closing the PR, since it seems like using tracing as nothing more than a drop-in replacement to log gives no benefit to either poise devs or poise users. I'm happy to be corrected

vidhanio commented 9 months ago

(only possible because tracing provides the start/end spans of a function call!)

Only when using spans in the library code, right? Either directly, or indirectly via #[instrument]. The tracing calls in poise are single point in time events only.. I'd tend towards closing the PR, since it seems like using tracing as nothing more than a drop-in replacement to log gives no benefit to either poise devs or poise users. I'm happy to be corrected

yes, that would be true. without that, it would be about as useful as log.

vidhanio commented 9 months ago

however, just as a mention, using a tracing-enabled library (with the log feature) as a log user works out of the box, whereas using a log-enabled library as a tracing user requires adding another dependency (tracing-log) and setting up their converter on the user side.

kangalio commented 9 months ago

I'll push a commit that fixes those things and then merge

kangalio commented 9 months ago

Thanks, now I didn't even need to make the commit myself :D I'll wait for CI, then merge