Report creation takes a lock

[akshayknarayan]

❯ cargo tree | grep eyre
│   ├── color-eyre v0.6.2
│   │   ├── eyre v0.6.8

I have some code that looks roughly like this:

loop {
  spin_poller().wrap_err(eyre!("error"))?;
}

This is bad for performance because it turns out error creation (eyre!) takes a lock when it calls std::env::var here: https://github.com/yaahc/color-eyre/blob/4a7b4d6988c6b0da5e04e29c9d6e10595b5dc302/src/config.rs#L1208

Instead, the better way is probably like this:

loop {
  spin_poller().wrap_err_with(|| eyre!("error"))?;
}

I'd like to suggest that either:

1. We add documentation for eyre! and wrap_err() that makes it clear that eyre! is not free and that wrap_err_with should be used in most cases.
2. lib_verbosity become feature-gated (perhaps returning Verbosity::Minimal by default), so that eyre! is cheap to call.

Thanks!

[yaahc]

Hey, the problem here is with color-eyre not eyre itself IIRC. I've no objections to adding a note to color-eyre somewhere mentioning the potential footgun here, but it wouldn't make sense to add the documentation note to eyre! since that's part of the upstream crate. The biggest risk in the upstream crate is the EyreHandler creation step, but I'm not sure off of the top of my head exactly how the performance characteristics of a OnceCell compare the lock in std::env:var so that might already be a non issue.

I'd suggest writing your own EyreHandler, even if it's just a do-nothing test case to see how replacing color-eyre impacts the performance and if the OnceCell still poses an issue. Something like:

struct FastestEyreHandlerInTheWest;

impl EyreHandler for FastestEyreHandlerInTheWest {
    fn debug(
        &self,
        _: &(dyn StdError + 'static),
        _: &mut core::fmt::Formatter<'_>,
    ) -> core::fmt::Result { Ok(()) }
}

As for the suggestion to feature gate lib_verbosity to make it so you can continue to use color-eyre in this case, I have no objections and would happily merge such a PR, we just need to be careful to not break backwards compatibility when introducing the new feature flag, and we should probably run the test above I mentioned just to make sure that such a fix would actually meet your performance needs.

Also, be fore-warned that CI is currently broken because of the syn 2.0 release and I'm working on getting that fixed in eyre.

[akshayknarayan]

Over at https://github.com/akshayknarayan/color-eyre/tree/report-handler-bench I have done a little bit of benchmarking. There are 2 x 3 cases to consider: (wrap_err vs wrap_err_with) x ("default handler", "fastest handler" (as above), color_eyre::config::HookBuilder::default().install).

The benchmark function is just:

fn spin_1000_[plain/with]() -> Result<(), Report> {
    for _ in 0..1000 {
        black_box(dummy: Ok::<_, Report>(())).wrap_err[_with](msg: eyre!("error"))?;
    }

    Ok(())
}

Some initial results below:

WrapErr/color:wrap_err(eyre!(...))
                        time:   [1.0408 ms 1.0430 ms 1.0456 ms]
WrapErr/color:wrap_err_with(|| eyre!(...))
                        time:   [18.247 µs 18.465 µs 18.641 µs]

WrapErr/default:wrap_err(eyre!(...))
                        time:   [88.563 µs 88.924 µs 89.293 µs]
WrapErr/default:wrap_err_with(|| eyre!(...))
                        time:   [17.349 µs 17.546 µs 17.757 µs]

WrapErr/fastest:wrap_err(eyre!(...))
                        time:   [42.158 µs 42.396 µs 42.616 µs]
WrapErr/fastest:wrap_err_with(|| eyre!(...))
                        time:   [18.383 µs 18.521 µs 18.638 µs]

It seems clear that the handler matters, but that using wrap_err_with avoids whatever its cost is. The existence of the OnceCell seems to not matter. When I have a bit more time I will take a look at feature-gating lib_verbosity, but it seems for now just adding a bit of documentation that suggests wrap_err_with might be enough?

[LeoniePhiline]

Issue can be closed, fixed by #93.