slog icon indicating copy to clipboard operation
slog copied to clipboard

Lazy and cached log fields

Open bobrik opened this issue 2 months ago • 6 comments

In our internal framework we have some relatively expensive log fields to compute (formatting is expensive):

"http.host" => format!("{:?}", extract_host(req))

We also have approximately zero logging in a course of normal request processing in the heaviest users, so all of this effort goes to waste. We can do this and switch to lazy evaluation:

"http.host" => PushFnValue(move |_, s| s.emit(format_args!("{host:?}")))

This is better, but it has an unfortunate downside for framework consumers that do log more than once during request processing.

We could get the best of both worlds by making evaluation both lazy (above) and cached (sketched by @TheJokr):

pub struct LazyValue<T, F>(LazyLock<T, F>);

impl<T: slog::Value, F: FnOnce() -> T> slog::Value for LazyValue<T, F> {
    fn serialize(&self, ...) -> ... {
        (*self.0).serialize(...)
    }
}

impl<T, F: FnOnce() -> T> LazyValue<T, F> {
    pub const fn new(init_fn: F) -> Self {
        Self(LazyLock::new(init_fn))
    }
}

It seems generally useful, so I think this should live in slog itself, as something like PushFnValueCached perhaps.

bobrik avatar Oct 09 '25 15:10 bobrik

Alternatively, in the slog crate itself, it's also possible to impl<T: slog::Value> slog::Value for LazyLock<T, _> directly. Both would require an MSRV of Rust 1.80 (or making it optional behind a feature.)

TheJokr avatar Oct 09 '25 16:10 TheJokr

Alternatively, in the slog crate itself, it's also possible to impl<T: slog::Value> slog::Value for LazyLock<T, _> directly. Both would require an MSRV of Rust 1.80 (or making it optional behind a feature.)

I think this is a good idea. We can use #[rustversion::since(1.80)] to avoid bumping the MSRV. I will add it to the v2.9.0 release, as the rust semver guidelines forbid adding a new trait implementation in a patch version.

Until the next major release, consider using the LazyValue type as a workaround. I have my own slog utility module in some of my own projects.

Techcable avatar Oct 09 '25 18:10 Techcable

Another question. Why does slog::FnValue not do what you need? It should only ever be called once.

Techcable avatar Oct 09 '25 18:10 Techcable

I'm not seeing what would make it only be called once. We're using it through a wrapper from foundations:

  • https://docs.rs/foundations/latest/foundations/telemetry/log/macro.add_fields.html

I added a new field to a per request context:

"hey.there" => FnValue(|_| { eprintln!("running FnValue"); "hello" }),

Then I sent one request that generated 4 log lines and each one called into FnValue:

    log::error_non_pii!("hello");
    log::error_non_pii!("there");
    log::error_non_pii!("general");
    log::error_non_pii!("kenobi");
running FnValue
{"msg":"hello","level":"ERRO","ts":"2025-10-09T23:01:51.442559975Z","hey.there":"hello"}
running FnValue
{"msg":"there","level":"ERRO","ts":"2025-10-09T23:01:51.442854977Z","hey.there":"hello"}
running FnValue
{"msg":"general","level":"ERRO","ts":"2025-10-09T23:01:51.442978218Z","hey.there":"hello"}
running FnValue
{"msg":"kenobi","level":"ERRO","ts":"2025-10-09T23:01:51.443091579Z","hey.there":"hello"}

bobrik avatar Oct 09 '25 23:10 bobrik

Yeah, I don't think FnValue are memoized, only lazily called if and when the logging actually happens, which is useful for stuff like timestamps or some live stats. . Lazy + Memoized seems neat and useful too.

dpc avatar Oct 10 '25 04:10 dpc

I've made a quick PR to do the LazyLock impl. Feel free to keep it open until it's time for v2.9.

We can use #[rustversion::since(1.80)] to avoid bumping the MSRV.

I wasn't aware of the rustversion crate, thanks for mentioning it!

TheJokr avatar Oct 10 '25 10:10 TheJokr