Broken trace example

[cijothomas]

This issue is simple example to showcase broken traces when intermixing OTel Tracing API and Tokio-tracing API.

Cargo.toml

[package]
name = "otel-tracing-interop"
version = "0.1.0"
edition = "2021"

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

[dependencies]
opentelemetry = "0.22.0"
opentelemetry-stdout = { version = "0.3.0", features = ["trace"] }
opentelemetry_sdk = "0.22.1"
serde_json = "1.0.116"
tracing = "0.1.40"
tracing-opentelemetry = "0.23.0"
tracing-subscriber = "0.3.18"

main.rs

use opentelemetry::{
    trace::{Span, Tracer, TracerProvider as _},
    KeyValue,
};

use opentelemetry_sdk::{
    resource,
    trace::{config, Config, TracerProvider},
    Resource,
};
use opentelemetry_stdout::SpanExporterBuilder;
use tracing::span;
use tracing_subscriber::{layer::SubscriberExt, Registry};

fn main() {
    println!("Hello, world!");
    let stdout_exporter = SpanExporterBuilder::default()
        .with_encoder(|writer, data| {
            serde_json::to_writer_pretty(writer, &data).unwrap();
            Ok(())
        })
        .build();
    let provider = TracerProvider::builder()
        .with_config(Config::default().with_resource(Resource::new(vec![])))
        .with_simple_exporter(stdout_exporter)
        .build();
    let tracer = provider.tracer("tracing-opentelemetry");
    let telemetry = tracing_opentelemetry::layer().with_tracer(tracer);
    let subscriber = Registry::default().with(telemetry);

    tracing::subscriber::with_default(subscriber, || {
        let tracer = provider.tracer("otel-tracing");

        // this is the root span created using tokio tracing api
        let root = span!(tracing::Level::TRACE, "tokio-tracing-span-parent");
        let _enter = root.enter();

        // this is a child span created using tokio tracing api
        // this correctly parented to the root span
        let child = span!(tracing::Level::TRACE, "tokio-tracing-span-child");
        let _enter_child = child.enter();

        // this is another child, created using otel tracing api
        // but this is *NOT* parented to the above spans
        // demonstrating broken traces when mixing and matching tracing and opentelemetry apis
        let mut span = tracer.span_builder("otel-tracing-span").start(&tracer);
        span.end();
    });
}

[lalitb]

The problem here is that if the Span is active in the tracing context, tracing-opentelemetry willn't make it active in the thread_local otel context. So any span created thereafter using otel API will have no information of the span created and made active by tracing API. So in the current state, the Otel tracing API will need to read the active span from the tracing context (along with the otel context as done already) to figure out the parent. The issue is somewhat similar to logging as described here.

[TommyCpp]

In order to bring the information from tracing to Opentelemetry. We need to extract the context from the tracing and start the span with it

Something like this should work

use tracing_opentelemetry::OpenTelemetrySpanExt;
// ...
        let mut span = tracer
            .start_with_context("otel-tracing-span", &child.context());

The context method was implemented as an extension of the tracing::Span using OpenTelemetrySpanExt trait.

The results:

{
  "resourceSpans": [
    {
      "resource": {
        "attributes": []
      },
      "scopeSpans": [
        {
          "scope": {
            "name": "otel-tracing"
          },
          "spans": [
            {
              "traceId": "5f3bf6b7e6e791cc58840e59d998015c",
              "spanId": "92656ad10ad9c62f",
              "parentSpanId": "6efbe97b2a32461a",
              "name": "otel-tracing-span",
              /// ...
            }
          ]
        }
      ]
    }
  ]
}
{
  "resourceSpans": [
    {
      "resource": {
        "attributes": []
      },
      "scopeSpans": [
        {
          "scope": {
            "name": "tracing-opentelemetry"
          },
          "spans": [
            {
              "traceId": "5f3bf6b7e6e791cc58840e59d998015c",
              "spanId": "6efbe97b2a32461a",
              "parentSpanId": "b41e4bad40cd5898",
              "name": "tokio-tracing-span-child",
             // ....
            }
          ]
        }
      ]
    }
  ]
}
{
  "resourceSpans": [
    {
      "resource": {
        "attributes": []
      },
      "scopeSpans": [
        {
          "scope": {
            "name": "tracing-opentelemetry"
          },
          "spans": [
            {
              "traceId": "5f3bf6b7e6e791cc58840e59d998015c",
              "spanId": "b41e4bad40cd5898",
              "parentSpanId": "0000000000000000",
              "name": "tokio-tracing-span-parent",
            }
          ]
        }
      ]
    }
  ]
}