Slog does not honor `#[track_caller]`

[ppershing]

Internally, slog uses file!() macro and its friends. This unfortunately does not work as expected if user opts in to #[track_caller] directive.

As a reference log crate fixed this in https://github.com/rust-lang/log/pull/633/files (with discussion starting back in rust-lang/log#410)

I can try to create an MR working in similar ways as the abovementioned MR on log if you are interested.

[Techcable]

This is more difficult to do than in the log crate, because we need to construct an &'static slog::RecordStruct at compile time.

It turns out that Location::caller does not respect #[track_caller] in a const-eval context.

Here is a gist giving the demonstration: https://gist.github.com/Techcable/a80e3a4c4d928a2038dc45bd6d91f9e4
You can run in the playground.

[Techcable]

I spent several hours tracking this down, and it is arguably a bug in the compiler.

[Techcable]

With more thought, I realize this is not a compiler bug. The implementation of #[track_caller] works by passing an extra &Location parameter to the function. Since this parameter is only known at runtime and can vary depending on the caller, then there is no way to know at const-eval time.

The only solutions would be to add a separate &Location file to Record or replace slog::RecordLocation with &Location.

[dpc]

I didn't understand the details, but notably macro, static location etc. are used to make the logging statement as cheap as possible and put as much as data into static data file segment.

passing an extra &Location parameter to the function.

Sound like a runtime value, which would could break it and enforce a cost (possibly non-trivial) on all logging statements.

[Techcable]

First, I want to apologize for mistakenly editing your comment instead of adding my own. I fixed it and restored the original version.

I didn't understand the details, but notably macro, static location etc. are used to make the logging statement as cheap as possible and put as much as data into static data file segment.

Yup! Here is an explanation of #[track_caller]:

The core::panic::Location type is equivalent to the slog::RecordLocation without the module_name and function fields. In most cases, Location::caller is equivalent to const { &Location(file!(), line!(), column!()) } producing a &'static Location at compile time.

However, the location differs is if the function is annotated with #[track_caller]. RFC #2091 added this attribute so that panics in Option::unwrap would report the location of user code rather than pointing to the stdlib.

This is implemented by adding an implicit &'static core::panic::Location parameter to the start of Option::unwrap. The caller passes its own location as an implicit parameter to Option::unwrap, so panics point to the caller rather than unwrap. Assuming Option::unwrap is inlined, the location becomes a constant value just like a normal value.

passing an extra &Location parameter to the function.

Sound like a runtime value, which would could break it and enforce a cost (possibly non-trivial) on all logging statements.

Unless the function has a #[track_caller] annotation, the value of Location::caller is a constant pointer just like RecordLocation. Even if a function has #[track_caller] this runtime value becomes a constant after inlining. In practice, #[track_caller] functions are rare. When they do occur, they are usually small helpers like Option::unwrap that are inlined.

However, you are right about the additional costs. Since there are occasional cases where Location is not known until runtime, it would need to be added to slog::Record rather than slog::RecordStatic.

In total, this would increase the size of slog::Record by a single pointer and require adding an alternate constructor like slog::Record::new_with_location in addition to using slog::Record::new.