tracing
tracing copied to clipboard
Published
20 hours ago •
tokio-rs
tokio-rs
OpenTelemetry example missing root span
Bug Report
Version
tracing-examples v0.0.0 (/redacted/tracing/examples)
│ │ └── tracing v0.1.29
│ │ ├── tracing-attributes v0.1.18 (proc-macro)
│ │ └── tracing-core v0.1.21
│ ├── tracing v0.1.29 (*)
│ └── tracing v0.1.29 (*)
├── tracing v0.2.0 (/redacted/tracing/tracing)
│ ├── tracing-attributes v0.2.0 (proc-macro) (/redacted/tracing/tracing-attributes)
│ └── tracing-core v0.2.0 (/redacted/tracing/tracing-core)
├── tracing-appender v0.2.0 (/redacted/tracing/tracing-appender)
│ └── tracing-subscriber v0.3.0 (/redacted/tracing/tracing-subscriber)
│ ├── tracing v0.2.0 (/redacted/tracing/tracing) (*)
│ ├── tracing-core v0.2.0 (/redacted/tracing/tracing-core) (*)
│ ├── tracing-log v0.2.0 (/redacted/tracing/tracing-log)
│ │ └── tracing-core v0.2.0 (/redacted/tracing/tracing-core) (*)
│ └── tracing-serde v0.2.0 (/redacted/tracing/tracing-serde)
│ └── tracing-core v0.2.0 (/redacted/tracing/tracing-core) (*)
├── tracing-attributes v0.2.0 (proc-macro) (/redacted/tracing/tracing-attributes) (*)
├── tracing-core v0.2.0 (/redacted/tracing/tracing-core) (*)
├── tracing-error v0.2.0 (/redacted/tracing/tracing-error)
│ ├── tracing v0.2.0 (/redacted/tracing/tracing) (*)
│ └── tracing-subscriber v0.3.0 (/redacted/tracing/tracing-subscriber) (*)
├── tracing-flame v0.2.0 (/redacted/tracing/tracing-flame)
│ ├── tracing v0.2.0 (/redacted/tracing/tracing) (*)
│ └── tracing-subscriber v0.3.0 (/redacted/tracing/tracing-subscriber) (*)
├── tracing-futures v0.3.0 (/redacted/tracing/tracing-futures)
│ └── tracing v0.2.0 (/redacted/tracing/tracing) (*)
├── tracing-journald v0.2.0 (/redacted/tracing/tracing-journald)
│ ├── tracing-core v0.2.0 (/redacted/tracing/tracing-core) (*)
│ └── tracing-subscriber v0.3.0 (/redacted/tracing/tracing-subscriber) (*)
├── tracing-log v0.2.0 (/redacted/tracing/tracing-log) (*)
├── tracing-opentelemetry v0.15.0 (/redacted/tracing/tracing-opentelemetry)
│ ├── tracing v0.2.0 (/redacted/tracing/tracing) (*)
│ ├── tracing-core v0.2.0 (/redacted/tracing/tracing-core) (*)
│ ├── tracing-log v0.2.0 (/redacted/tracing/tracing-log) (*)
│ └── tracing-subscriber v0.3.0 (/redacted/tracing/tracing-subscriber) (*)
├── tracing-serde v0.2.0 (/redacted/tracing/tracing-serde) (*)
├── tracing-subscriber v0.3.0 (/redacted/tracing/tracing-subscriber) (*)
└── tracing-tower v0.1.0 (/redacted/tracing/tracing-tower)
├── tracing v0.2.0 (/redacted/tracing/tracing) (*)
└── tracing-futures v0.3.0 (/redacted/tracing/tracing-futures) (*)
Current Git HEAD: 500021c4
Platform
Linux redacted 5.12.18-1-ck-haswell #1 SMP PREEMPT Mon, 19 Jul 2021 10:10:38 +0000 x86_64 GNU/Linux
Crates
tracing-opentelemetry, examples
Description
When trying the example in the tracing-opentelemetry README, the span data that arrives in Jaeger is missing the root app_start span.
In an attempt to make sure it wasn't my fault, I tried both stable and nightly rustc, as well as the latest tag for Jaeger and various numbered releases. However, I don't really have any experience with OpenTelemetry in general, so I don't really know what else I might be doing wrong.
To check if this was maybe a Jaeger issue, I replaced the Jaeger exporter with a pretty-print stdout exporter to inspect the data generated, and got this:
SpanData {
span_context: SpanContext {
trace_id: TraceId(
115753407323867453817286726237859500592,
),
span_id: SpanId(
2412041107076759396,
),
trace_flags: TraceFlags(
1,
),
is_remote: false,
trace_state: TraceState(
None,
),
},
parent_span_id: SpanId(
17737724336709010573,
),
span_kind: Internal,
name: "expensive_step_1",
start_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 747121770,
},
end_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 772231941,
},
attributes: EvictedHashMap {
map: {
Key(
"code.filepath",
): String(
"examples/examples/opentelemetry.rs",
),
Key(
"code.namespace",
): String(
"opentelemetry",
),
Key(
"busy_ns",
): I64(
25085322,
),
Key(
"code.lineno",
): I64(
9,
),
Key(
"idle_ns",
): I64(
16055,
),
},
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: None,
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.16.0",
),
},
}
SpanData {
span_context: SpanContext {
trace_id: TraceId(
115753407323867453817286726237859500592,
),
span_id: SpanId(
2595018740449750974,
),
trace_flags: TraceFlags(
1,
),
is_remote: false,
trace_state: TraceState(
None,
),
},
parent_span_id: SpanId(
17737724336709010573,
),
span_kind: Internal,
name: "expensive_step_2",
start_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 772347981,
},
end_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 797478496,
},
attributes: EvictedHashMap {
map: {
Key(
"code.namespace",
): String(
"opentelemetry",
),
Key(
"busy_ns",
): I64(
25095343,
),
Key(
"code.lineno",
): I64(
11,
),
Key(
"idle_ns",
): I64(
29452,
),
Key(
"code.filepath",
): String(
"examples/examples/opentelemetry.rs",
),
},
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: None,
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.16.0",
),
},
}
SpanData {
span_context: SpanContext {
trace_id: TraceId(
115753407323867453817286726237859500592,
),
span_id: SpanId(
17737724336709010573,
),
trace_flags: TraceFlags(
1,
),
is_remote: false,
trace_state: TraceState(
None,
),
},
parent_span_id: SpanId(
11558622527446292642,
),
span_kind: Internal,
name: "expensive_work",
start_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 747087811,
},
end_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 797546890,
},
attributes: EvictedHashMap {
map: {
Key(
"code.namespace",
): String(
"opentelemetry",
),
Key(
"code.filepath",
): String(
"examples/examples/opentelemetry.rs",
),
Key(
"busy_ns",
): I64(
50422609,
),
Key(
"idle_ns",
): I64(
28263,
),
Key(
"code.lineno",
): I64(
6,
),
},
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: None,
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.16.0",
),
},
}
SpanData {
span_context: SpanContext {
trace_id: TraceId(
115753407323867453817286726237859500592,
),
span_id: SpanId(
10281780557043495479,
),
trace_flags: TraceFlags(
1,
),
is_remote: false,
trace_state: TraceState(
None,
),
},
parent_span_id: SpanId(
11558622527446292642,
),
span_kind: Internal,
name: "faster_work",
start_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 797597727,
},
end_time: SystemTime {
tv_sec: 1637678113,
tv_nsec: 807705519,
},
attributes: EvictedHashMap {
map: {
Key(
"idle_ns",
): I64(
37764,
),
Key(
"code.lineno",
): I64(
39,
),
Key(
"code.filepath",
): String(
"examples/examples/opentelemetry.rs",
),
Key(
"busy_ns",
): I64(
10066041,
),
Key(
"code.namespace",
): String(
"opentelemetry",
),
},
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: None,
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.16.0",
),
},
}
As you can see, the root app_start span is missing from the output.
I have the same issue: it works fine when using otel's stdout exporter, but the root span is missing when using an opentelemetry_otlp exporter (which suggests an issue on the otel exporter).
This is somewhat resolved by #2110—the core issue is that the root span in the example is closed after the collector shuts down due to drop rules.
It seems so. However, this feels like a very sneaky pitfall that one might not consider in a scenario where the root span is opened on application start-up, and should perhaps be mentioned in the documentation. I'm willing to close this issue either way; just putting the idea out there.