Debug builds seem to be really slow to render due to excessive logging via tracing

[stevepryde]

I'm running leptos with CSR via trunk serve and trying to render pages with a reasonable number of components, but no lists or data-heavy things. Debug rendering seems quite slow. The console shows a lot of TRACE logs showing "calling on() click".

If I remove the line to install the tracing logger, everything feels pretty quick. So it seems tracing adds quite a bit of overhead here.

Things I've tried:

• Adding a log filter fn to limit to DEBUG level (still slow)
• Adding the tracing feature flags max_level_debug and release_max_level_warn. Slightly better, but still quite slow
• Release build - this is fast. No issues
• Removing the line: tracing_wasm::set_as_global_default() - this also works. Rendering is pretty fast even in debug builds.

Any recommendations for removing this logging performance hit?

[stevepryde]

Leptos 0.6.4, Rust 1.75, stable

[stevepryde]

For some reason, this makes a huge difference:

let config = WASMLayerConfigBuilder::new()
    .set_max_level(Level::WARN)
    .set_report_logs_in_timings(false)
    .set_console_config(tracing_wasm::ConsoleConfig::ReportWithoutConsoleColor)
    .build();
tracing::subscriber::set_global_default(Registry::default().with(WASMLayer::new(config)))
    .expect("WASM logger failed");

But the exact same code with the max level set to Level::DEBUG is slow. I see no logs either way. A colleague suggested maybe spans are slowing it down even if nothing gets logged?

[gbj]

I can't say I've ever noticed any rendering speed issues in debug mode, but then again I usually don't have a tracing subscriber running, so I believe you. You're probably right about the tracing spans. Everything is instrumented in a pretty detailed way, to allow for ongoing work to build additional dev tooling.

That said, if tweaking the max level is allowed then it seems like it's not the instrumentation per se. I also don't think Leptos instruments anything with a level about trace at this point. But I'm not that deeply familiar with tracing, so I may be wrong about anything I've written above.

All the tracing instrumentation is omitted from release mode in CSR/hydration, hence the change you're seeing there.

[stevepryde]

Thanks for the response.

The only logs I see actually displayed are this one:
https://github.com/leptos-rs/leptos/blob/main/leptos_dom/src/lib.rs#L732
It gets output to the browser console 30-40 times while rendering the page (which is a showcase app full of examples of various UI components). But even when I filter those out by setting the level to DEBUG, it's still slow, which indicates the spans (possibly from that same function) are still adding some overhead. But I wondered if my code is doing something wrong to be triggering this log message so many times anyway.

So far setting the log level to max WARN seems to work ok. There is still a noticeable delay but it's less than a second.
We definitely still want the warnings logged since those are helpful. I think this will work ok for us.

[stevepryde]

For anyone else who might bump into this, the following log filtering may be useful:

use tracing::level_filters::LevelFilter;
use tracing_subscriber::{filter, layer::SubscriberExt, Layer, Registry};
use tracing_wasm::{WASMLayer, WASMLayerConfigBuilder};

// Put this somewhere global
const PACKAGE_NAME: &str = env!("CARGO_PKG_NAME");

    // put this at the top of main
    let filter_fn = filter::filter_fn(|metadata| {
        let mut level_filter = LevelFilter::WARN;
        // Allow all logs from this app only.
        if metadata.target().starts_with(PACKAGE_NAME) {
            level_filter = LevelFilter::TRACE;
        }
        metadata.level() <= &level_filter
    });

    let config = WASMLayerConfigBuilder::new()
        .set_report_logs_in_timings(false)
        .set_console_config(tracing_wasm::ConsoleConfig::ReportWithoutConsoleColor)
        .build();
    tracing::subscriber::set_global_default(
        Registry::default().with(WASMLayer::new(config).with_filter(filter_fn)),
    )
    .expect("WASM logger failed");