tracing-subscriber's Directive parsing adds 600us to startup time

[dpc]

Bug Report

I was debugging/optimizing startup time of a cli tool I'm working on, and I've noticed
that:

EnvFilter::builder().with_regex(false).parse("debug")

takes around 600us on my machine. Yes, I'm using --release. It seems to me that lazy-compiling the regex used to parse the directives is where the time is spent, because changing to .parse("") is almost instant, and adding a lot of other directives does not seem to change much either.

600us is not all that much, but when we're talking about "blazingly fast" it kind of adds up (another part that I'm looking at is clap, bringing the minimum startup time of my CLI to 1.5ms area in debug builds, and 800us in release builds).

Version

tracing v0.1.41

tracing-subscriber v0.3.19

Platform

Linux ren 6.12.0-rc6 #1-NixOS SMP PREEMPT_DYNAMIC Tue Jan  1 00:00:00 UTC 1980 x86_64 GNU/Linux

[bjorn3]

For rustup this amounts to about 14% of the total time of rustup which rustc.

[davidbarsky]

14% of rustup which rustc is... not great. I don't know how much of this we'll be able to fix unless we get rid of regex entirely, but maybe using Targets might be better.

[dpc]

@davidbarsky I don't understand. It seemed to me that slowdown was entirely due to time it takes to compile regex for parsing RUST_LOG. Using regex is convenient, but could be done in other ways that do not require relatively slow regex compilation at runtime.

[davidbarsky]

@davidbarsky I don't understand. It seemed to me that slowdown was entirely due to time it takes to compile regex for parsing RUST_LOG. Using regex is convenient, but could be done in other ways that do not require relatively slow regex compilation at runtime.

I'm trying to say until we get rid of the regex in EnvFilter, using the Targets might be a reasonable workaround.

[bjorn3]

It would have been nice if there was a filter which could be configured using RUST_LOG like EnvFilter, but for which you can also set a default in a way similar to Targets without having to parse anything.

[davidbarsky]

Yeah, we should have a Targets::from_env that reads RUST_LOG, but until we do, I think the following should suffice:

let rust_log = std::env::var("RUST_LOG")?;
let filter = rust_log.parse::<filter::Targets>()?;

// setup the rest of subscriber...

[djc]

Just submitted #3243 -- @dpc, would be awesome if you could casually benchmark it.