Bad interaction with tracing-error

[asonix]

Hey, I'm encountering an issue when trying to integrate tracing-error into my code with actix-web-tracing. Since my error types are now capturing span information, which it accesses in the impl Display, when actix-web-tracing goes to log the error, both the error and the middleware are accessing span information simultaneously, and it's causing a panic with rwlock read lock would result in deadlock

I don't really know what to do about this other than "not use tracing-error" which would be a shame

[asonix]

After trying and failing to build a minimal reproduction, I'm thinking this is potentially because I have actix-web types inside my error type. I'll try to update that and see if it gets fixed

[asonix]

Update: I think it's probably not my second hunch, but I can't replicate this on a small scale, so I don't really know where to go from here.

[asonix]

Okay I have a minimal repro, but I needed to spin up a full actix-web server to do it. Just hitting localhost:8000 while this is running causes a panic

[dependencies]
actix-web = { version = "4.0.0-beta.9", default-features = false }
tracing = "0.1"
tracing-actix-web = "0.4.0-beta.8"
tracing-error = "0.1"
tracing-subscriber = { version = "0.2", features = ["fmt"] }

use tracing_error::{ErrorLayer, SpanTrace};
use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};

#[derive(Debug)]
struct MyError {
    context: SpanTrace,
}

impl MyError {
    fn new() -> Self {
        MyError {
            context: SpanTrace::capture(),
        }
    }
}

impl std::fmt::Display for MyError {
    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
        write!(f, "Blows up!")
    }
}

impl std::error::Error for MyError {}
impl actix_web::error::ResponseError for MyError {}

async fn index() -> Result<&'static str, MyError> {
    Err(MyError::new())
}

#[actix_web::main]
async fn main() -> Result<(), Box<dyn std::error::Error>> {
    let env_filter = EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info"));
    let subscriber = Registry::default()
        .with(env_filter)
        .with(ErrorLayer::default())
        .with(tracing_subscriber::fmt::layer());
    tracing::subscriber::set_global_default(subscriber)?;

    actix_web::HttpServer::new(|| {
        actix_web::App::new()
            .wrap(tracing_actix_web::TracingLogger::default())
            .route("/", actix_web::web::get().to(index))
    })
    .bind("0.0.0.0:8000")?
    .run()
    .await?;
    Ok(())
}

[asonix]

I've narrowed it down to these lines in root_span_builder

    span.record(
        "exception.message",
        &tracing::field::display(response_error),
    );
    span.record("exception.details", &tracing::field::debug(response_error));

Changing this to the following:

    let display = format!("{}", response_error);
    let debug = format!("{:?}", response_error);
    span.record(
        "exception.message",
        &tracing::field::display(display),
    );
    span.record("exception.details", &tracing::field::display(debug));

Solves it, but I'm not sure if that's an okay change to make, since I'm less experienced with tracing & I don't really know what those display and debug methods are actually doing

[LukeMathWalker]

I have bumped into this in an unrelated project as well, coming around to the very same fix you suggested.
On one side, it is no ideal: if a user disables tracing via their feature flags, now they are still paying for the formatting cost of the errors.
On the other side, almost nobody disables error-level traces (and uses this crate!).

So I'd be inclined to merge the workaround while we look upstream for a more proper fix.

[asonix]

I created a more minimal repro & opened an issue against Tracing, linked above. Should I also open a PR here which pre-formats the text?

[LukeMathWalker]

Yes, a PR would be appreciated!