LukeMathWalker/tracing-actix-web

OpenTelemetry feature breaks when when using `root_span!` macro

markhildreth-deepgram opened this issue · 2 comments

markhildreth-deepgram commented

I have reproduced this issue in the main branch, as well as on beta.14. I am running Rust 1.51 on Linux.

If you attempt to use opentelemetry feature (for the purpose of accepting trace propagation headers) and also use a custom root span builder, the opentelemetry propagation mechanism silently stops working.

To reproduce:

Run the opentelemetry example as-is.

Run the opentelemetry example, which uses the default span builder. In another terminal, run a request with a traceparent...

curl -H "traceparent: 00-0af7651916cd43dd8448eb211c80319c-b9c7c989f97918e1-01" localhost:8080

You should see the 0af7651916cd43dd8448eb211c80319c trace id in the end result of the logs.

{"v":0,"name":"tracing-actix-web-demo","msg":"[HTTP REQUEST - END]", ... "trace_id":"0af7651916cd43dd8448eb211c80319c", ...}

Use a custom span builder

Add the following into code into the opentelemetry example (examples/opentelemetry/src/main.rs):

pub(crate) struct CustomRootSpanBuilder;

use actix_web::dev::{ServiceRequest, ServiceResponse};
use actix_web::Error;
use tracing::Span;
use tracing_actix_web::RootSpanBuilder;
impl RootSpanBuilder for CustomRootSpanBuilder {
    fn on_request_start(request: &ServiceRequest) -> Span {
        use tracing_actix_web::root_span;
        tracing_actix_web::root_span!(request)
    }   

    fn on_request_end<B>(span: Span, outcome: &Result<ServiceResponse<B>, Error>) {
        tracing_actix_web::DefaultRootSpanBuilder::on_request_end(span, outcome);
    }   
}

Also, change out the default logger for the custom one...

      App::new()
          .wrap(TracingLogger::default())            
          //.wrap(TracingLogger::<CustomRootSpanBuilder>::new())
          .service(web::resource("/hello").to(hello))

Run the same curl test as above. Note that this time, the trace id is not included in the span. Adding debug printlns to the function which should be grabbing this trace id shows that it is never being called.

markhildreth-deepgram commented

I think the problem happening here is that the root_span! macro includes lines like the following:

tracing-actix-web/src/root_span_macro.rs

Lines 100 to 106 in c08c3c3

#[cfg(any(
feature = "opentelemetry_0_13",
feature = "opentelemetry_0_14",
feature = "opentelemetry_0_15",
feature = "opentelemetry_0_16"
))]
$crate::root_span_macro::private::set_otel_parent(&$request, &span);

What seems to be happening is that the macro will take those cfg lines and put them verbatim into the calling code before resolving the feature flags, as opposed to being resolved in the tracing-actix-web package and THEN moved into the binary package. As a result, the features flags will be resolved differently depending on where the root_span! macro is called.

  • When used in DefaultRootSpanBuilder opentelemetry_0_* feature flags are checked for the tracing-actix-web crate, which is correct.
  • However, when the macro is used in a binary crate (or the example crate), then the feature flags lines are copied in and checked against the binary crate. If I add the opentelemetry_0_14 feature to the opentelemetry example and enable that feature, the trace propagation works again.
  • 👍1
LukeMathWalker commented

A massive thank you for the excellent bug report and the PR to patch it 🙏🏻

  • 👍1