7

I'm writing a Rust crate for internal company use that wraps the excellent Tokio tracing crate, with a bit of additional functionality. Not only do I re-export the macros in tracing, but I also add a few of my own that internally invoke the tracing macros. My goal is to enable all of our other internal crates to depend only on my wrapper crate, without having to pull in tracing dependencies explicitly in each crate.

This works really well, until I ran into an issue today that took me a few hours to isolate. I've made a minimal example to show the behavior here.

In this example, I have a workspace with two crates: my-logger-crate which wraps tracing and exposes a macro print_trace!, and a binary crate my-binary-crate which has a dependency on my-logger-crate, and invokes the macro inside the main function.

The Cargo.toml for my-logger-crate is very simple; the only thing I added to the auto-generated skeleton is a tracing dependency:

[package]
name = "my-logger-crate"
version = "0.1.0"
authors = ["Adam Nelson <anelson@users.noreply.github.com>"]
edition = "2018"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]
tracing = "0.1.12"

This is the my-logger-crate macro:

/// Re-export everything in the `tracing` crate
pub use ::tracing::*;

/// A version of the `trace!` macro that sets a special target
#[macro_export]
macro_rules! print_trace {
    ($($arg:tt)*) => (
        // Invoke the `trace!` macro which is defined in the `tracing` crate but which has been
        // re-exported from this crate, so that downstream callers don't have to take an explicit
        // dependency on `tracing`
        $crate::trace!(target: "console", $($arg)*)
    )
}

This is used by my-binary-crate, whose Cargo.toml is also simple:

[package]
name = "my-binary-crate"
version = "0.1.0"
authors = ["Adam Nelson <anelson@users.noreply.github.com>"]
edition = "2018"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]
my-logger-crate = { path = "../my-logger-crate" }

# If the following line is uncommented, then the call to `print_trace!` in `main()` fails to compile.
# tower = "0.3"

And here's the main() function in my-binary-crate:

fn main() {
    println!("Hello, world!");

    // Log a trace event with the logging system
    my_logger_crate::print_trace!("this is a trace message from print_trace!");
}

If my-binary-crate doesn't have any conflicting dependencies, this compiles and runs fine.

But take a look at what happens if we have a dependency on tower in the my-binary-crate/Cargo.toml file:

[package]
name = "my-binary-crate"
version = "0.1.0"
authors = ["Adam Nelson <anelson@users.noreply.github.com>"]
edition = "2018"

# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html

[dependencies]
my-logger-crate = { path = "../my-logger-crate" }

# If the following line is uncommented, then the call to `print_trace!` in `main()` fails to compile.
tower = "0.3"

Here's what happens:

Compiling my-binary-crate v0.1.0 (/home/cornelius/scrap/e2780c4bd3dfa24758fcfd93e225b100/my-binary-crate)
error[E0433]: failed to resolve: use of undeclared type or module `tracing`
 --> my-binary-crate/src/main.rs:5:5
  |
  |     ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ use of undeclared type or module `tracing`
  |
  = note: this error originates in a macro outside of the current crate (in Nightly builds, run with -Z external-macro-backtrace for more info)

The print_trace! macro is expanding out to the tracing::trace! macro, which then expands to tracing::event!, and then expands to the code to log an event, which includes calls to tracing::.... All of this works fine before I add that tower dependency, so clearly the compiler is able to resolve tracing::... properly, even though my-binary-crate doesn't have a direct dependency on tracing itself.

I suspect this is related to a dependency conflict. tower pulls in a long dependency tree, including tower-buffer, which itself has a dependency on tracing = "0.1.2".

My understanding of how Cargo resolves this seeming conflict is that it would use tracing version 0.1.12, since my logging crate explicitly depends on version =0.1.12, and tower-buffer specifies 0.1.2, which is equivalent to ^0.1.2. But I don't understand why adding this additional dependency tree breaks the use of my macro.

For the moment I've worked around it by adding explicit dependencies on tracing in all of the downstream crates that use my logging crate, but that's far from ideal.

I ran with macro tracing enabled:

$ RUSTFLAGS="-Z macro-backtrace" cargo +nightly test
   Compiling my-binary-crate v0.1.0 (/home/cornelius/scrap/e2780c4bd3dfa24758fcfd93e225b100/my-binary-crate)
error[E0433]: failed to resolve: use of undeclared type or module `tracing`
   --> <::tracing::macros::__mk_format_args macros>:78:17
    |
1   |    /  (@ { $ (,) * $ ($ out : expr), * $ (,) * }, $ fmt : expr, fields : $ (,) *) =>
2   |    |  { format_args ! ($ fmt, $ ($ out), *) } ;
3   |    |  (@ { $ (,) * $ ($ out : expr), * }, $ fmt : expr, fields : $ ($ k : ident) . +
4   |    |   = ? $ val : expr $ (,) *) =>
...      |
78  |    |          (@ { }, tracing :: __mk_format_string ! ($ ($ kv) *), fields : $
    |    |                  ^^^^^^^ use of undeclared type or module `tracing`
79  |    |           ($ kv) *)
80  |    |      }
81  |    |  } ;
... [a lot of macro expansions snipped]

Not surprisingly, the error is an attempt to call tracing::__mk_format_string!, which fails because there is no such crate tracing referenced by my-binary-crate. The strange thing is that in order to get to this error, several other macros in tracing had to be evaluated. Perhaps this is a bug in tracing, and it should be $crate::__mk_format_string!. However I still don't understand why this works until I add a tower dependency on my-binary-crate.

kmdreko
  • 42,554
  • 6
  • 57
  • 106
anelson
  • 2,569
  • 1
  • 19
  • 30

0 Answers0