Statically disable debug logging in optimized builds

[mbrubeck]

This PR modifies log! and associated macros to disable logging at compile time for the Debug and Trace log levels when the debug_assertions option is disabled (which it is by default when optimizations are enabled).

The goal of this change is to make it easy to leave debug logging in place throughout a project and its dependencies, but to pay for it only in debug builds, and have it completely optimized out in release builds.

The log_level configuration option provides an existing way to do this. However, in practice there is no supported way to toggle log_level for a package and all of its dependencies when building with Cargo. However, Cargo does provide per-profile options for controlling rustc's built-in debug_assertions option. This option is a pretty good fit for debug logging, since it is intended to statically disable code that is useful for debugging but may have a performance cost. In fact, rustc's internal liblog already uses it this way for its debug! logging macro.

This PR is alternative to rust-lang/cargo#1948 which was closed by @alexcrichton in favor of “options that are local to the log crate itself.” Compared to the Cargo PR, this one is not as configurable, but does not require any external changes.

[alexcrichton]

I wonder if it may be worth putting this sort of functionality behind a feature flag for now to preserve the old behavior. I know that I personally really enjoy having debug logs in Cargo even in release builds! Although the other way around may also make sense where a feature flag enables debug logging in release builds as well.

Either way, though, could you add a test for this functionality? Also cc @sfackler, curious on your thoughts as well.

[mbrubeck]

I know that I personally really enjoy having debug logs in Cargo even in release builds!

Yes — if this change is accepted, developers will have reason to be more picky about which log levels they use: info or lower for things that should remain in release builds, and debug or trace only for things that they would like compiled out in production.

I'll work on adding a feature flag and test.

[sfackler]

I'm on board with a feature flag, but would really like some way to have the more robust log_level cfg configurability exposed in a reasonable way through cargo.

[mbrubeck]

Me too! Maybe you can help me convince the Cargo developers to either add log_level explicitly, or add a way to set arbitrary --cfg options that apply to the entire dependency tree. :)

[mbrubeck]

@sfackler This now includes a test for the new behavior, and a feature to restore the old behavior. Feel free to bikeshed the feature name; I wasn't sure what to call it.

Note: I added the Rust "stable" channel to .travis.yml and removed Rust 1.0.0, because Rust 1.0.0 doesn't include Cargo feature support.

[sfackler]

I think we'll actually want to invert the behavior of the feature and keep everything enabled by default to make sure everything's backwards compatible.

[mbrubeck]

@sfackler:

I think we'll actually want to invert the behavior of the feature and keep everything enabled by default to make sure everything's backwards compatible.

I flipped the feature so the new behavior is now opt-in (though personally I still feel that statically disabling debug code in release builds is a better default for most projects).

[sfackler]

Thinking about it more, I kind of want to go further and have sets of Cargo features to control the maximum release and debug log levels that would supplant the current log_level cfg things that aren't really usable right now. Something like:

[features]
max_level_off = []
max_level_error = ["max_level_off"]
max_level_warn = ["max_level_error"]
max_level_info = ["max_level_warn"]
max_level_debug = ["max_level_info"]
max_level_trace = ["max_level_debug"]

debug_max_level_off = []
debug_max_level_error = ["debug_max_level_off"]
debug_max_level_warn = ["debug_max_level_error"]
debug_max_level_info = ["debug_max_level_warn"]
debug_max_level_debug = ["debug_max_level_info"] # The naming here's a bit bizarre :/
debug_max_level_trace = ["debug_max_level_debug"]

And then have something like

#[inline(always)]
#[doc(hidden)]
pub fn __static_max_level() -> LogLevelFilter {
    if cfg!(debug_assertions) {
        if cfg!(feature = "debug_max_level_trace") {
            LogLevelFilter::Trace
        } else if cfg!(feature = "debug_max_level_debug") {
            LogLevelFilter::Debug
        } else if cfg!(feature = "debug_max_level_info") {
            LogLevelFilter::Info
        } else if cfg!(feature = "debug_max_level_warn") {
            LogLevelFilter::Warn
        } else if cfg!(feature = "debug_max_level_error") {
            LogLevelFilter::Error
        } else if cfg!(feature = "debug_max_level_off") {
            LogLevelFilter::Off
        } else {
            LogLevelFilter::Trace
        }
    } else {
        if cfg!(feature = "max_level_trace") {
            LogLevelFilter::Trace
        } else if cfg!(feature = "max_level_debug") {
            LogLevelFilter::Debug
        } else if cfg!(feature = "max_level_info") {
            LogLevelFilter::Info
        } else if cfg!(feature = "max_level_warn") {
            LogLevelFilter::Warn
        } else if cfg!(feature = "max_level_error") {
            LogLevelFilter::Error
        } else if cfg!(feature = "max_level_off") {
            LogLevelFilter::Off
        } else {
            LogLevelFilter::Trace
        }
    }
}

[mbrubeck]

Updated to replace the cfg(log_level) with a set of Cargo features, based on @sfackler's suggestion above.

[alexcrichton]

Can you leave 1.0.0 here? The intention with that is to ensure that this continues to always compile on 1.0.0 Rust

[mbrubeck]

Rust 1.0.0 does not support Cargo features. :(

EDIT: Actually, it did... but for some reason Cargo from Rust 1.0.0 can't parse the Cargo.toml files in this PR. https://travis-ci.org/rust-lang-nursery/log/builds/83363467

[alexcrichton]

Are you sure? Features have been around since Cargo's inception basically...

[alexcrichton]

This looks good to me, thanks @mbrubeck!

r? @sfackler

[mbrubeck]

Updated to wrap comments to 80 columns and restore Rust 1.0.0 to the list of Travis jobs. (An earlier version of this PR failed to parse Cargo.toml with Rust 1.0, but it looks like it's passing now.)

[sfackler]

Should we worry about breaking back-compat for people that are actually using the log_level cfg? I don't know if any of those people exist, but might be worth leaving this around to support them? Thoughts @alexcrichton?

[sfackler]

Looks good to me modulo the back-compat questions!

[mbrubeck]

I think if we ever want to make breaking changes to this crate, it should happen now while it's still in the nursery, and sooner is better than later.

So unless we want to support two (static) ways of setting the log level forever, I think it's better to remove the old one now. If we bump the package version, it shouldn't cause any silent breakage.

[sfackler]

I'm not opposed to making breaking changes to this crate, but we have to be somewhat careful about how we do it. The location of the crate in Github doesn't matter all that much - liblog is incredibly heavily depended upon, and bad things will happen if a single executable has multiple copies lying around (some log messages will disappear into the ether!). If we want to break back compat, I'd like to do it to make significantly larger changes than just cutting some obscure cfg switches.

[mbrubeck]

So I guess the question is whether this breaks anyone's code in practice. I believe the only built-in way to make Cargo set the log_level option is to output cargo:rustc-cfg=log_level="debug" from a build script. Is it possible to find out if any packages on crates.io are doing this in their build scripts?

[alexcrichton]

Yeah I also suspect that this actually isn't being used that much in practice (e.g. it's obscure and not super documented), so I'm fine breaking it for now (and we can always add it back in a future point release). Along the lines of the whole "technically but not practically breaking"

Thanks again @mbrubeck!

[sfackler]

👍