Opentelemetry layer incorrectly attaches event location attributes

[hubertbudzynski]

Bug Report

Version

tracing-opentelemetry = { version = "0.17.2", default-features = false }

Description

If event_location (introduced in #1910) is enabled then location data is pushed to span's attributes instead of event's attributes.

This is because in the on_event method in subscriber.rs the location attributes are pushed to SpanBuilder::attributes where it seems more logical to push it to the otel_event's attributes.

Tried this code:

use opentelemetry::sdk::export::trace::stdout;
use tracing::{info, span};
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::Registry;

fn main() {
    let tracer = stdout::new_pipeline().install_simple();
    let telemetry = tracing_opentelemetry::layer()
        .with_tracer(tracer)
        .with_event_location(true);
    let subscriber = Registry::default().with(telemetry);

    tracing::subscriber::with_default(subscriber, || {
        let root = span!(tracing::Level::INFO, "app_start");
        let _enter = root.enter();

        info!("Event in line 17");

        info!("Event in line 19");
    });

    opentelemetry::global::shutdown_tracer_provider();
}

output:

SpanData { span_context: SpanContext { trace_id: 35d9d6278361f6e7c4986ce884deb9f4, span_id: b27cad4a0a248418, trace_flags: TraceFlags(1), is_remote: false, trace_state: TraceState(None) }, parent_span_id: 0000000000000000, span_kind: Internal, name: "app_start", start_time: SystemTime { tv_sec: 1650960225, tv_nsec: 459736247 }, end_time: SystemTime { tv_sec: 1650960225, tv_nsec: 459843147 }, attributes: EvictedHashMap { map: {Key("code.filepath"): String("src/main.rs"), Key("idle_ns"): I64(86601), Key("code.lineno"): I64(20), Key("code.namespace"): String("tracing_otel_example"), Key("busy_ns"): I64(25970)}, evict_list: [Key("idle_ns"), Key("busy_ns"), Key("code.lineno"), Key("code.namespace"), Key("code.filepath")], max_len: 128, dropped_count: 0 }, events: EvictedQueue { queue: Some([Event { name: "Event in line 18", timestamp: SystemTime { tv_sec: 1650960225, tv_nsec: 459818227 }, attributes: [KeyValue { key: Key("level"), value: String("INFO") }, KeyValue { key: Key("target"), value: String("tracing_otel_example") }], dropped_attributes_count: 0 }, Event { name: "Event in line 20", timestamp: SystemTime { tv_sec: 1650960225, tv_nsec: 459830097 }, attributes: [KeyValue { key: Key("level"), value: String("INFO") }, KeyValue { key: Key("target"), value: String("tracing_otel_example") }], dropped_attributes_count: 0 }]), max_len: 128, dropped_count: 0 }, links: EvictedQueue { queue: None, max_len: 128, dropped_count: 0 }, status_code: Unset, status_message: "", resource: Some(Resource { attrs: {Key("service.name"): String("unknown_service")} }), instrumentation_lib: InstrumentationLibrary { name: "opentelemetry", version: Some("0.17.0") } }

This is not very good because the events don't store the info on their locations. If we change this code:

tracing/tracing-opentelemetry/src/subscriber.rs

Lines 598 to 606 in 92ec839

	if let Some(file) = file {
	builder_attrs.push(KeyValue::new("code.filepath", file));
	}
	if let Some(module) = module {
	builder_attrs.push(KeyValue::new("code.namespace", module));
	}
	if let Some(line) = meta.line() {
	builder_attrs.push(KeyValue::new("code.lineno", line as i64));
	}

to

if let Some(file) = file {
    otel_event
        .attributes
        .push(KeyValue::new("code.filepath", file));
}
if let Some(module) = module {
    otel_event
        .attributes
        .push(KeyValue::new("code.namespace", module));
}
if let Some(line) = meta.line() {
    otel_event
        .attributes
        .push(KeyValue::new("code.lineno", line as i64));
}

We get:

SpanData { span_context: SpanContext { trace_id: 793a7691b139efbe457dd9d6639536c7, span_id: 7105b1f466f94eec, trace_flags: TraceFlags(1), is_remote: false, trace_state: TraceState(None) }, parent_span_id: 0000000000000000, span_kind: Internal, name: "app_start", start_time: SystemTime { tv_sec: 1650960500, tv_nsec: 24653215 }, end_time: SystemTime { tv_sec: 1650960500, tv_nsec: 24762556 }, attributes: EvictedHashMap { map: {Key("idle_ns"): I64(88401), Key("code.filepath"): String("src/main.rs"), Key("code.namespace"): String("tracing_otel_example"), Key("busy_ns"): I64(27160), Key("code.lineno"): I64(20)}, evict_list: [Key("idle_ns"), Key("busy_ns"), Key("code.lineno"), Key("code.namespace"), Key("code.filepath")], max_len: 128, dropped_count: 0 }, events: EvictedQueue { queue: Some([Event { name: "Event in line 18", timestamp: SystemTime { tv_sec: 1650960500, tv_nsec: 24736946 }, attributes: [KeyValue { key: Key("level"), value: String("INFO") }, KeyValue { key: Key("target"), value: String("tracing_otel_example") }, KeyValue { key: Key("code.filepath"), value: String("src/main.rs") }, KeyValue { key: Key("code.namespace"), value: String("tracing_otel_example") }, KeyValue { key: Key("code.lineno"), value: I64(18) }], dropped_attributes_count: 0 }, Event { name: "Event in line 20", timestamp: SystemTime { tv_sec: 1650960500, tv_nsec: 24749306 }, attributes: [KeyValue { key: Key("level"), value: String("INFO") }, KeyValue { key: Key("target"), value: String("tracing_otel_example") }, KeyValue { key: Key("code.filepath"), value: String("src/main.rs") }, KeyValue { key: Key("code.namespace"), value: String("tracing_otel_example") }, KeyValue { key: Key("code.lineno"), value: I64(20) }], dropped_attributes_count: 0 }]), max_len: 128, dropped_count: 0 }, links: EvictedQueue { queue: None, max_len: 128, dropped_count: 0 }, status_code: Unset, status_message: "", resource: Some(Resource { attrs: {Key("service.name"): String("unknown_service")} }), instrumentation_lib: InstrumentationLibrary { name: "opentelemetry", version: Some("0.17.0") } }

After the change each event stores the location data in it's attributes.

If this approach is ok I'm happy to make a PR.

[hawkw]

After the change each event stores the location data in it's attributes.

If this approach is ok I'm happy to make a PR.

The change you suggested looks correct to me, thank you! A PR would be great (although I'd also want to hear from @jtescher before merging).

[jtescher]

@hawkw @hubertbudzynski yep good idea, definitely an improvement 👍