tracing-bunyan-formatter icon indicating copy to clipboard operation
tracing-bunyan-formatter copied to clipboard

Possible log field collision when used with `tracing-actix-web`

Open colmanhumphrey opened this issue 5 years ago • 0 comments

This issue takes over from https://github.com/LukeMathWalker/tracing-actix-web/issues/1

When we define a tracing instrument that has fields also present in the info_span! used in tracing-actix-web, the collision results in the tracing-actix-web fields getting silently overwritten when logged out by this crate (potentially by other logs too, I'm not too sure!).

Here is the info_span! from tracing-actix-web:

        let span = tracing::info_span!(
            "Request",
            request_path = %req.path(),
            user_agent = %user_agent,
            client_ip_address = %req.connection_info().realip_remote_addr().unwrap_or(""),
            request_id = %Uuid::new_v4(),
            status_code = tracing::field::Empty,
        );

Example

If we e.g. use the following macro in our code:

#[tracing::instrument(
    name = "Adding a new subscriber",
    skip(payload, pool),
    fields(
        request_id=%Uuid::new_v4(),
        email = %payload.email,
        name = %payload.name
    )
)]

We'll have a collision on request_id, and we'll only see the request_id defined in our instrument in the resulting logs, and not the one from tracing-actix-web. This means we can potentially lose visibility in our logs (or just make it a bit more complex).

Expected Behaviour

As discussed in https://github.com/LukeMathWalker/tracing-actix-web/issues/1, a good outcome might be for this crate to throw a warning on such a collision.

Thanks

For the excellent crate!

colmanhumphrey avatar Oct 11 '20 22:10 colmanhumphrey