[Bug]: Context::current().with_remote_span_context() not working

[hkford]

What happened?

I try generating span with remote span context. I generate trace using tracing and associate it with a OpenTelemetry trace using set_parent(). The parameter of set_parent() is Context so I generate Context using Context.with_remote_span_context().

use lambda_runtime::Error;
use opentelemetry::trace::SpanContext;
use opentelemetry::trace::TracerProvider as _;
use opentelemetry::Context;
use opentelemetry_aws::trace::xray_propagator::span_context_from_str;

use opentelemetry_sdk::trace::TracerProvider;

use tracing::{info, info_span};
// For using subscriber.with()
use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;
use tracing_subscriber::{fmt, fmt::format, EnvFilter};
// For using span.context()
use tracing_opentelemetry::OpenTelemetrySpanExt;
// For using Context.with_remote_span_context()
use opentelemetry::trace::TraceContextExt;
fn init_observability() {
    let exporter = opentelemetry_otlp::new_exporter()
        .tonic()
        .build_span_exporter()
        .expect("Failed to build span exporter");
    // Create a new OpenTelemetry trace pipeline that prints to stdout
    let provider = TracerProvider::builder()
        .with_simple_exporter(exporter)
        .build();
    let tracer = provider.tracer("lambda");
    let fmt_layer = fmt::layer().event_format(format().json());
    let filter_layer = EnvFilter::from_default_env();
    let telemetry_layer = tracing_opentelemetry::layer().with_tracer(tracer);

    tracing_subscriber::registry()
        .with(filter_layer)
        .with(fmt_layer)
        .with(telemetry_layer)
        .init();
}
fn retrieve_span_context_from_xray_traceid(xray_trace_id: &str) -> Result<SpanContext, Error> {
    span_context_from_str(xray_trace_id).ok_or("Invalid _X_AMZN_TRACE_ID".into())
}

#[tokio::main]
async fn main() {
    init_observability();
    let _r = run().expect("Run failed");
}

fn run() -> Result<(), Error> {
    let xray_trace_id = "Root=1-65dc5008-1561ed7046ffcbcb114af027;Parent=b510129166d5a083;Sampled=1;Lineage=f98dd9ff:0";
    let parent_spancontext = retrieve_span_context_from_xray_traceid(&xray_trace_id)?;

    info!("Prent SpanContext is not empty: {:?}", &parent_spancontext);
    let span = info_span!("Handler is called");

    let ctx = Context::current().with_remote_span_context(parent_spancontext);
    info!("Context with remote_span_context is {:?}", ctx);
    info!("Span before set_parent is {:?}", span.context());
    span.set_parent(ctx);

    info!("Span after set_parent is {:?}", span.context());
    Ok(())
}

Running RUST_LOG=info cargo run and I saw span has no span in its context after set_parent.

{"timestamp":"2024-03-06T09:03:32.739847Z","level":"INFO","fields":{"message":"Prent SpanContext is not empty: SpanContext { trace_id: 65dc50081561ed7046ffcbcb114af027, span_id: b510129166d5a083, trace_flags: TraceFlags(1), is_remote: true, trace_state: TraceState(Some([(\"lineage\", \"f98dd9ff:0\")])) }"},"target":"playground"}
{"timestamp":"2024-03-06T09:03:32.739977Z","level":"INFO","fields":{"message":"Context with remote_span_context is Context { entries: 0 }"},"target":"playground"}
{"timestamp":"2024-03-06T09:03:32.740000Z","level":"INFO","fields":{"message":"Span before set_parent is Context { entries: 0 }"},"target":"playground"}
{"timestamp":"2024-03-06T09:03:32.740016Z","level":"INFO","fields":{"message":"Span after set_parent is Context { entries: 0 }"},"target":"playground"}

API Version

Cargo.toml

tracing = { version = "0.1.40", features = ["log","attributes"] }
tracing-subscriber = { version = "0.3.18", features = ["std", "env-filter","json"] }
opentelemetry = { version = "0.22.0" }
opentelemetry_sdk = { version = "0.22.0", features = ["rt-tokio"] }
opentelemetry-aws = "0.10.0"
opentelemetry-otlp = { version = "0.15.0", features = ["grpc-tonic", "tls"] }
tracing-opentelemetry = "0.23.0"

SDK Version

Cargo.toml

tracing = { version = "0.1.40", features = ["log","attributes"] }
tracing-subscriber = { version = "0.3.18", features = ["std", "env-filter","json"] }
opentelemetry = { version = "0.22.0" }
opentelemetry_sdk = { version = "0.22.0", features = ["rt-tokio"] }
opentelemetry-aws = "0.10.0"
opentelemetry-otlp = { version = "0.15.0", features = ["grpc-tonic", "tls"] }
tracing-opentelemetry = "0.23.0"

What Exporters are you seeing the problem on?

OTLP

Relevant log output

No response

[stormshield-fabs]

set_parent is a tracing-opentelemetry method that does not interact with the opentelemetry structures the way you expect but instead on its own OtelData.

Basically, you're dealing with two instrumentation APIs: opentelemetry and tracing (via tracing-opentelemetry). It looks like you want to use tracing for the rest of your instrumentation, so everything should work fine. You will find that the parent ID is correctly set when exporting the traces (example below in Jaeger).

[hkford]

Thank you for trying out my code. I could visualize traces using Jaeger too. How can I test that parent ID is set correctly?

[TommyCpp]

How can I test that parent ID is set correctly?

You can replace the OTLP exporter with stdout exporter

let exporter = opentelemetry_stdout::SpanExporterBuilder::default().build();

This will print the span information to stdout and you can inspect the parentSpanId there. You will also need to keep reference to tracer provider so it doesn't drop when init_observability function. I recommend to set it as global default by adding this line in the init_observability function

opentelemetry::global::set_tracer_provider(provider);

I tried this and this is the what I get

{
  "resourceSpans": [
    {
      "resource": {
        "attributes": [
          {
            "key": "telemetry.sdk.language",
            "value": {
              "stringValue": "rust"
            }
          },
          {
            "key": "telemetry.sdk.version",
            "value": {
              "stringValue": "0.22.1"
            }
          },
          {
            "key": "telemetry.sdk.name",
            "value": {
              "stringValue": "opentelemetry"
            }
          },
          {
            "key": "service.name",
            "value": {
              "stringValue": "unknown_service"
            }
          }
        ]
      },
      "scopeSpans": [
        {
          "scope": {
            "name": "lambda"
          },
          "spans": [
            {
              "traceId": "65dc50081561ed7046ffcbcb114af027",
              "spanId": "8c7d1cb651742fe8",
              "parentSpanId": "b510129166d5a083",
              "name": "Handler is called",
              "kind": 1,
              "startTimeUnixNano": 1710026004438046310,
              "startTime": "2024-03-09 23:13:24.438",
              "endTimeUnixNano": 1710026004438126497,
              "endTime": "2024-03-09 23:13:24.438",
              "attributes": [
                {
                  "key": "code.filepath",
                  "value": {
                    "stringValue": "examples/tracing-jaeger/src/main.rs"
                  }
                },
                {
                  "key": "code.namespace",
                  "value": {
                    "stringValue": "tracing_jaeger"
                  }
                },
                {
                  "key": "code.lineno",
                  "value": {
                    "intValue": 54
                  }
                },
                {
                  "key": "thread.id",
                  "value": {
                    "intValue": 1
                  }
                },
                {
                  "key": "thread.name",
                  "value": {
                    "stringValue": "main"
                  }
                },
                {
                  "key": "busy_ns",
                  "value": {
                    "intValue": 0
                  }
                },
                {
                  "key": "idle_ns",
                  "value": {
                    "intValue": 0
                  }
                }
              ],
              "droppedAttributesCount": 0,
              "droppedEventsCount": 0,
              "flags": 1,
              "droppedLinksCount": 0,
              "status": {}
            }
          ]
        }
      ]
    }
  ]
}

I will close this issue for now as the behavior is intented. Feel free to reopen should you have more questions