Executable size impact

[RazrFalcon]

Here is a simple demo:

#[macro_use] extern crate log;
extern crate fern;

fn main() {
    fern::Dispatch::new()
        .level(log::LevelFilter::Warn)
        .chain(std::io::stderr())
        .apply().unwrap();

    warn!("Hello, world!");
//     println!("Hello, world!");
    test();
}

fn test() {
    warn!("Hello, world!");
//     println!("Hello, world!");
}

According to the cargo-bloat, the code size with warn in the release build is 1000B and with println - 717B. Why it impacts the size so much? Maybe this is a cargo-bloat bug (yes, I'm the author)?

In the real world applications, the results are even more drastic. For example, if I remove all the logging from this module the size in the release build will be reduced from 9.1KiB to 3.1KiB. It's ridiculous.

I this is a correct behavior or am I missing something?

log v0.4.1
fern v0.5.5
cargo-bloat v0.5.0
rustc 1.26.1

[sfackler]

Log is tracking significantly more information than a println.

It's grabbing the filename, the line number, the module name, the log target, and the actual log string, rather than just the string, and performing an extra check against the global max log level: https://github.com/rust-lang-nursery/log/blob/master/src/macros.rs#L33-L51

It looks like a main function that just contains warn!("hello world") is 204 bytes and a main function that just contains println!("hello world") is 77 bytes.

There is some impact from the way the log macro is currently structured avoiding the construction of the Record struct cuts the size of main down to 124 bytes:

#[macro_use]
extern crate log;

use std::fmt::Arguments;
use log::{Level, RecordBuilder};

fn main() {
    if Level::Warn <= log::max_level() {
        log_fast(Level::Warn, "foo", format_args!("hello world"), module_path!(), file!(), line!());
    }
}

#[inline(never)]
fn log_fast(level: Level, target: &str, args: Arguments, module: &str, file: &str, line: u32) {
    log::logger()
        .log(
            &RecordBuilder::new()
                .level(level)
                .target(target)
                .args(args)
                .module_path(Some(module))
                .file(Some(file))
                .line(Some(line))
                .build(),
        );
}

That came up as an option during the 0.4 API overhauls, and it may be worth adding back a "secret" function like log_fast for the use of the log macros.

[RazrFalcon]

Hmm... Interesting.

I was able to reduce the exe/crate size to the same size a bit.

• default log! - 275.3KiB
• custom log! - 270.2KiB
• minimal custom log! - 267.6KiB
• eprintln! - 266.7KiB

Custom:

#[inline(never)]
fn log_fast(level: log::Level, module: &str, file: &str, line: u32, args: ::std::fmt::Arguments) {
    if level <= ::log::STATIC_MAX_LEVEL && level <= ::log::max_level() {
        log::logger()
            .log(
                &log::RecordBuilder::new()
                    .level(level)
                    .target(module)
                    .args(args)
                    .module_path(Some(module))
                    .file(Some(file))
                    .line(Some(line))
                    .build(),
            );
    }
}

macro_rules! log {
    ($lvl:expr, $($arg:tt)+) => ({
        ::log_fast($lvl, module_path!(), file!(), line!(), format_args!($($arg)+))
    });
    ($lvl:expr, $($arg:tt)+) => (log!($lvl, $($arg)+))
}

Minimal:

#[inline(never)]
fn log_fast(level: log::Level, args: ::std::fmt::Arguments) {
    if level <= ::log::STATIC_MAX_LEVEL && level <= ::log::max_level() {
        log::logger()
            .log(
                &log::RecordBuilder::new()
                    .level(level)
                    .target("")
                    .args(args)
                    .module_path(None)
                    .file(None)
                    .line(None)
                    .build(),
            );
    }
}

macro_rules! log {
    ($lvl:expr, $($arg:tt)+) => ({
        ::log_fast($lvl, format_args!($($arg)+))
    });
    ($lvl:expr, $($arg:tt)+) => (log!($lvl, $($arg)+))
}

PS: surprisingly, removing the useless trace! from a hot method reduced the size by 8% by itself with a default log implementation.

[sfackler]

That would make sense if the hot method was inlined in a bunch of places.

…

On Sun, Jun 3, 2018 at 11:16 AM Evgeniy Reizner ***@***.***> wrote: Hmm... Interesting. I was able to reduce the exe/crate size to the same size a bit. - default log! - 275.3KiB - custom log! - 270.2KiB - minimal custom log! - 267.6KiB - eprintln! - 266.7KiB Custom: #[inline(never)]fn log_fast(level: log::Level, module: &str, file: &str, line: u32, args: ::std::fmt::Arguments) { if level <= ::log::STATIC_MAX_LEVEL && level <= ::log::max_level() { log::logger() .log( &log::RecordBuilder::new() .level(level) .target(module) .args(args) .module_path(Some(module)) .file(Some(file)) .line(Some(line)) .build(), ); } } macro_rules! log { ($lvl:expr, $($arg:tt)+) => ({ ::log_fast($lvl, module_path!(), file!(), line!(), format_args!($($arg)+)) }); ($lvl:expr, $($arg:tt)+) => (log!($lvl, $($arg)+)) } Minimal: #[inline(never)]fn log_fast(level: log::Level, args: ::std::fmt::Arguments) { if level <= ::log::STATIC_MAX_LEVEL && level <= ::log::max_level() { log::logger() .log( &log::RecordBuilder::new() .level(level) .target("") .args(args) .module_path(None) .file(None) .line(None) .build(), ); } } macro_rules! log { ($lvl:expr, $($arg:tt)+) => ({ ::log_fast($lvl, format_args!($($arg)+)) }); ($lvl:expr, $($arg:tt)+) => (log!($lvl, $($arg)+)) } PS: surprisingly, removing the useless trace! from a hot method <https://github.com/RazrFalcon/usvg/blob/23d3c4addddd40e3621add31ed70eed2fd9ca2f4/src/traits.rs#L186> reduced the size by 8% by itself with a default log implementation. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#275 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ABY2UfzRUiZ6zpRI-fv0_R9SjDd_isf0ks5t5CgAgaJpZM4UYKCY> .

[RazrFalcon]

It was.

[sfackler]

You can also disable specific logging levels entirely at compile time, which will remove all of the code from the resulting binary, btw: https://docs.rs/log/0.4.1/log/#compile-time-filters