Use lower logging levels?

[dpc]

I started playing with Iroh and I see it logs things on WARN etc. levels which by default is getting in a way of debugging my own code.

My philosophy of logging levels is that since they (somewhat unfortunately) are typically globally shared, they should be used with an end to end point of view.

I'd expect Iroh will always be used as a lower level infrastructure layer, and thus what's happening inside it will always be some kind of trace information, maybe debug for most important iroh logging statements, and not application level "information", "warning" or "error" which should be reserved for applications.

[flub]

Hi, in general we agree that not much should be logged on ERROR, WARN, and not even that much on INFO. I think the rough guideline is that ERROR is a serious issue, potentially rendering the entire iroh Endpoint broken, while WARN is for things that are likely to be bugs.

So this makes my question to you: which message are you seeing specifically? Maybe we have bugs to fix, or maybe we did get the log level wrong (there certainly are still those cases about).

Also in the interim, are you aware of the EnvFilter directives which allow tweaking log levels per crate and module?

[dpc]

The core guidance IMO is that it all needs to be considered from the end user perspective.

If Iroh is hitting condition that means that the application is likely screwed and needs immediate user/administrator attention than it might deserve an error logging, sure, maybe. But it's rarely the case. An Endpoint simply being broken will rarely be a completely unexpected condition or something that the user can do anything about. The higher level application code using Endpoint will receive errors from Endpoint related methods anyway and then the app can log them as it see fits: if this Endpoint not working is actually a critical problem and unexpected, it will get logged as error. "Log + return up" is IMO antipatern, so errors should usually be logged only when they are no longer "thrown up the call chain".

That's another reason why libraries should not need to log all that much anyway - they should be returning errors to the app and let it handle it. Sometimes it is even worthwhile to expose something like a broadcast channel where the application can register to handle events (like errors) as it see fits. This is useful for exposing things from background threads etc. that can't simply return errors upwards to the higher level code.

BTW. I wish error was renamed to crit because over and over devs conflate it, and mistakenly log every error, no matter how expected and mundane at error logging level, but that's another story.

Also in the interim, are you aware of the EnvFilter directives which allow tweaking log levels per crate and module?

Sure I am. I have spent quite a bit of time, effort and thought on Rust logging, e.g. being an author of slog logging ecosystem.

It is a workable bandaid, yes, but very crude. Typically applications end up maintaining some long list of muted dependencies, and having dependency simply muted like that is less than ideal. Over last few years I've reported similar issues to many libraries, trying to keep such list as short as possible. :)

And then putting anything in RUST_LOG often has a runtime cost, and having many filters is not free either, sometimes unexpectedly very expensive.

[flub]

We do have some places where things can be problems, bugs either in use or -more common- implementation, where the problem is not fatal and we can not error out to the user. The nature of all the things the Endpoint needs to do under the hood makes this unfortunately reasonably common. In those cases we opt for error or warning logs so that we have a chance of getting bug reports etc.

One point were we might digress from your vision is that we are fairly verbose on debug level. And this is generally essential for debugging user problems. I expect as the library matures that these lower logging levels will slowly reduce.

I still think we essentially agree with the use of logging though. So please, if you have specific log messages that are showing up too much do point them out so we can figure out if there are some bugs or whether we need to tweak the logging.

[dpc]

One point were we might digress from your vision is that we are fairly verbose on debug level. And this is generally essential for debugging user problems. I expect as the library matures that these lower logging levels will slowly reduce.

Debug is a fair game. Ideally, it would be showing things relevant in debugging possible application's issues related to Iroh, but ... debug is debug. All logging messages are fair in love and debugging or something like that.

Usually in apps I default to INFO, as the assumption is this is what the user should be informed about. Anything below that is much less of a problem anyway, as it only shows up when something non-default is being done.

, if you have specific log messages that are showing up too much

Will do. It will take some time, as I'm slowly going through my app work.

[dpc]

2024-12-28T07:37:01.956378Z  INFO ep{me=zxagwbdyflz6ghm5}:magicsock:actor: iroh_net::magicsock: home is now relay https://use1-1.relay.iroh.network
./, was None
2024-12-28T07:37:01.956649Z  INFO ep{me=zxagwbdyflz6ghm5}:magicsock:relay-actor: iroh_net::magicsock::relay_actor: adding connection to relay: https://use1-1.relay.iroh.network./ for home-keep-alive

[flub]

So #3080 does address the 2nd one. The first one I'm not convinced yet that I want to remove it. Typically this will be emitted once at startup, which is very reasonable I think. And it is a nice log message to stand out from all the debugging stuff.

[flub]

n0-computer/net-tools#8 is also a bunch that I noticed and definitely don't want in the logs. Maybe those ones were a regression.

[dpc]

n0-computer/net-tools#8 is also a bunch that I noticed and definitely don't want in the logs

Cool. I will eventually pick up the newest release and if I spot anything I will report back. Feel free to close or not the issue. I can keep posting anyway.

Maybe those ones were a regression.

BTW. I recommend setting up semgrep or something like it to enforce things like that. In our project we have bunch of things to enforce for various reasons: wasm support, logging preferences, project-specific lints.

[flub]

semgrep looks interesting! Thanks for the tip.

Will close this for now, but yes, feel free to call out other things.