Consider changing the default enabled log levels

alexcrichton commented

2017-05-19 14:58:42 -05:00

(Migrated from github.com)

Right now I believe all log levels are enabled by default in all builds. @sfackler provided some good rationale for this during the evaluation, @sfackler want to copy that down here as well?

In any case would be worth discussing before a 1.0 release!

Right now I believe all log levels are enabled by default in all builds. @sfackler provided some good rationale for this during the evaluation, @sfackler want to copy that down here as well? In any case would be worth discussing before a 1.0 release!

lucab commented

2017-06-01 03:08:23 -05:00

(Migrated from github.com)

Bump for this for the missing offline comments. Also, has build-time stubbing of disabled levels (like slog does) been discussed? Is it in scope here?

Bump for this for the missing offline comments. Also, has build-time stubbing of disabled levels (like [slog does](https://github.com/slog-rs/slog/wiki/FAQ#can-i-disable-some-logging-levels-at-compile-time)) been discussed? Is it in scope here?

sfackler commented

2017-06-01 12:42:19 -05:00

(Migrated from github.com)

Oops, sorry!

You can already statically disable levels actually: https://github.com/rust-lang-nursery/log/blob/master/Cargo.toml#L23-L35. The question here is over defaults.

I feel pretty strongly that we shouldn't disable any level of logging by default. The whole point of logging is that you have bunch of diagnostic information available to you when you need it. You normally don't need to look at debug or trace level logging, but when you do it's invaluable! For example, Hyper's trace-level logging helped track down a bug in its chunked request body parser in a running server.

If, for example, trace logging were disabled by default, you'd have several problems. If I ran into that Hyper problem above, I'd have to ship a new custom build of the server with trace logging enabled to actually be able to get the information I need. If the issue you're looking into is one of the annoying transient ones that no-one knows how to reproduce but pops up in production every once in a while, it's really important to be able to look very closely at whatever box it shows up on immediately! I could also override the default to enable trace logging by default, but then I potentially have other issues - if people become too used to trace logging being turned off, you may run into issues where those log events are extremely expensive or even broken! Rustc has some of those issues - the old log framework disabled debug logging in prod builds, and didn't evaluate log arguments if the log event wasn't enabled and it turned out that several would panic if actually evaluated.

In addition, there is a fast path for logging levels that are entirely disabled at runtime. If you don't have any trace-level logging enabled in your logger configuration, the cost of a trace! statement is a relaxed atomic load, comparison against a constant, and branch. If you're logging so much that that fast path ends up slowing things down significantly, I don't really see how that level of verbosity can possibly be useful.

Oops, sorry! You can already statically disable levels actually: https://github.com/rust-lang-nursery/log/blob/master/Cargo.toml#L23-L35. The question here is over defaults. I feel pretty strongly that we shouldn't disable any level of logging by default. The whole point of logging is that you have bunch of diagnostic information available to you when you need it. You normally don't need to look at debug or trace level logging, but when you do it's invaluable! For example, Hyper's trace-level logging helped track down a bug in its chunked request body parser in a running server. If, for example, trace logging were disabled by default, you'd have several problems. If I ran into that Hyper problem above, I'd have to ship a new custom build of the server with trace logging enabled to actually be able to get the information I need. If the issue you're looking into is one of the annoying transient ones that no-one knows how to reproduce but pops up in production every once in a while, it's really important to be able to look very closely at whatever box it shows up on immediately! I could also override the default to enable trace logging by default, but then I potentially have other issues - if people become too used to trace logging being turned off, you may run into issues where those log events are extremely expensive or even broken! Rustc has some of those issues - the old log framework disabled debug logging in prod builds, and didn't evaluate log arguments if the log event wasn't enabled and it turned out that several would panic if actually evaluated. In addition, there is a fast path for logging levels that are entirely disabled at runtime. If you don't have any trace-level logging enabled in your logger configuration, the cost of a `trace!` statement is a relaxed atomic load, comparison against a constant, and branch. If you're logging so much that that fast path ends up slowing things down significantly, I don't really see how that level of verbosity can possibly be useful.

lucab commented

2017-06-01 13:27:50 -05:00

(Migrated from github.com)

Thanks for the feedback! It looks like my knowledge around here is wrong/stale, so I'm paging @dpc for some informed comment.

dpc commented

2017-06-01 15:01:13 -05:00

(Migrated from github.com)

I understand @sfackler points, and I think they make sense. I also don't feel strongly about default logging level in slog. I gave the matter some consideration and picked the defaults.

As a library writer, it is convenient to have a logging level for your disposal, that you don't have to feel guilty about using, and comes handy when you are testing and debugging your library while you are working on it, change it etc.. It is not optimal if hyper is important enough to have trace information, but mysillylibrarymust be cautious or jump through custom macro hoops because it's somehow of lesser category or something like that. So that would be my main concern. I was hoping to get to think about it more, and maybe do some prototyping of something that could satisfy everyone, ideas include:

special set of logging macros that can be used when working on the library itself
statically compiled logging levels per-crate

There are some differences between slog and slog that change the dynamics a bit: slog supports lazily evaluated values, so the risk of panics during with logging enabled is inherent. That is kind of OK, because slog treats logging as first class citizen. You need to take care of API changes related to logging, logging logical structure and context etc.

Also, because in slog you do compose how the different pices of your software route their logging messages, it is possible to modify in-flight eg. lowering logging levels of your dependencies. Even if they do overuse trace, or debug, and you turned it on, they still wouldn't get logged and their overhead would be minimal.

So in slog, if there's something useful to know in production, no matter how minor it might be from global perspective you can make it an info. If something is only useful for debugging you make it debug, and so on. The users of your library can decide how much they care (or typically not care). And you can stuff your code with trace for your own (maintainer/developer of given library) use, without much worrying about affecting your users.

So I don't think log should neccesarily copy slog defaults.

I understand @sfackler points, and I think they make sense. I also don't feel strongly about default logging level in `slog`. I gave the matter some consideration and picked the defaults. As a library writer, it is convenient to have a logging level for your disposal, that you don't have to feel guilty about using, and comes handy when you are testing and debugging your library while you are working on it, change it etc.. It is not optimal if `hyper` is important enough to have `trace` information, but `mysillylibrary`must be cautious or jump through custom macro hoops because it's somehow of lesser category or something like that. So that would be my main concern. I was hoping to get to think about it more, and maybe do some prototyping of something that could satisfy everyone, ideas include: * special set of logging macros that can be used when working on the library itself * statically compiled logging levels per-crate There are some differences between `slog` and `slog` that change the dynamics a bit: `slog` supports lazily evaluated values, so the risk of panics during with logging enabled is inherent. That is kind of OK, because `slog` treats logging as first class citizen. You need to take care of API changes related to logging, logging logical structure and context etc. Also, because in slog you do compose how the different pices of your software route their logging messages, it is possible to modify in-flight eg. lowering logging levels of your dependencies. Even if they do overuse trace, or debug, and you turned it on, they still wouldn't get logged and their overhead would be minimal. So in slog, if there's something useful to know in production, no matter how minor it might be from global perspective you can make it an `info`. If something is only useful for debugging you make it `debug`, and so on. The users of your library can decide how much they care (or typically not care). And you can stuff your code with `trace` for your own (maintainer/developer of given library) use, without much worrying about affecting your users. So I don't think `log` should neccesarily copy `slog` defaults.

lucab commented

2017-06-01 17:26:28 -05:00

(Migrated from github.com)

For reference, I ended up here today because of such discussions happening around TLS libraries and logging:

For reference, I ended up here today because of such discussions happening around TLS libraries and logging: * https://github.com/ctz/hyper-rustls/issues/20 * https://github.com/ctz/rustls/issues/22

brson commented

2017-06-02 21:46:32 -05:00

(Migrated from github.com)

I think a concur that all log levels should be compiled in by default. Would be quite surprising for a naive user to deploy an app, go to turn on verbose logs and discover they don't exist.

brson commented

2017-07-05 21:25:20 -05:00

(Migrated from github.com)