From 77267abf926c2a372fabab6e76bce1271a8841a2 Mon Sep 17 00:00:00 2001 From: David Hewitt Date: Mon, 24 Mar 2025 17:55:40 +0000 Subject: [PATCH] fix print to console to emit spans in the right order --- src/bridges/tracing.rs | 23 +-- src/internal/exporters/console.rs | 7 +- src/lib.rs | 278 +++++++++++++++++++++++++++++- 3 files changed, 281 insertions(+), 27 deletions(-) diff --git a/src/bridges/tracing.rs b/src/bridges/tracing.rs index 5c47648..69a27f8 100644 --- a/src/bridges/tracing.rs +++ b/src/bridges/tracing.rs @@ -3,7 +3,7 @@ use opentelemetry::{ global::ObjectSafeSpan, trace::{SamplingDecision, TraceContextExt}, }; -use tracing::{Subscriber, span}; +use tracing::Subscriber; use tracing_opentelemetry::{OtelData, PreSampledTracer}; use tracing_subscriber::{Layer, registry::LookupSpan}; @@ -31,28 +31,9 @@ where "logfire.level_num", level_to_level_number(*attrs.metadata().level()), )); - attributes.push(KeyValue::new("logfire.span_type", "span")); - } - } - - // Emit a pending span when this span is first entered, if this span will be sampled. - fn on_enter(&self, id: &span::Id, ctx: tracing_subscriber::layer::Context<'_, S>) { - /// Dummy struct to mark that we've already entered this span. - struct LogfireSpanEntered; - - let span = ctx.span(id).expect("span not found"); - let mut extensions = span.extensions_mut(); - - if extensions.get_mut::().is_some() { - return; - } - extensions.insert(LogfireSpanEntered); - - // Guaranteed to be on first entering of the span - - if let Some(otel_data) = extensions.get_mut::() { + // Emit a pending span, if this span will be sampled. let context = self.0.sampled_context(otel_data); let sampling_result = otel_data .builder diff --git a/src/internal/exporters/console.rs b/src/internal/exporters/console.rs index 60ecd8a..d8abf5d 100644 --- a/src/internal/exporters/console.rs +++ b/src/internal/exporters/console.rs @@ -92,7 +92,7 @@ impl SimpleConsoleSpanExporter { .unwrap_or(Cow::Borrowed("span")); // only print for pending span and logs - if span_type == "pending_span" { + if span_type == "span" { return Ok(()); } @@ -117,6 +117,7 @@ impl SimpleConsoleSpanExporter { // Filter out known values ATTRIBUTES_SPAN_TYPE_KEY | "logfire.json_schema" + | "logfire.pending_parent_id" | "code.filepath" | "code.lineno" | "thread.id" @@ -218,12 +219,12 @@ mod tests { let output = std::str::from_utf8(&output).unwrap(); assert_snapshot!(output, @r#" + 1970-01-01T00:00:00.000000Z INFO logfire::internal::exporters::console::tests root span 1970-01-01T00:00:01.000000Z INFO logfire::internal::exporters::console::tests hello world span 1970-01-01T00:00:03.000000Z DEBUG logfire::internal::exporters::console::tests debug span 1970-01-01T00:00:05.000000Z DEBUG logfire::internal::exporters::console::tests debug span with explicit parent 1970-01-01T00:00:07.000000Z INFO logfire::internal::exporters::console::tests hello world log - 1970-01-01T00:00:08.000000Z ERROR logfire panic: oh no! location=src/internal/exporters/console.rs:210:17, backtrace=disabled backtrace - 1970-01-01T00:00:00.000000Z INFO logfire::internal::exporters::console::tests root span + 1970-01-01T00:00:08.000000Z ERROR logfire panic: oh no! location=src/internal/exporters/console.rs:211:17, backtrace=disabled backtrace "#); } } diff --git a/src/lib.rs b/src/lib.rs index 636c539..5604dc4 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -1244,6 +1244,142 @@ mod tests { attributes: [], }, }, + SpanData { + span_context: SpanContext { + trace_id: 000000000000000000000000000000f0, + span_id: 00000000000000f5, + trace_flags: TraceFlags( + 1, + ), + is_remote: false, + trace_state: TraceState( + None, + ), + }, + parent_span_id: 00000000000000f4, + span_kind: Internal, + name: "debug span", + start_time: SystemTime { + tv_sec: 3, + tv_nsec: 0, + }, + end_time: SystemTime { + tv_sec: 3, + tv_nsec: 0, + }, + attributes: [ + KeyValue { + key: Static( + "code.filepath", + ), + value: String( + Static( + "src/lib.rs", + ), + ), + }, + KeyValue { + key: Static( + "code.namespace", + ), + value: String( + Static( + "logfire::tests", + ), + ), + }, + KeyValue { + key: Static( + "code.lineno", + ), + value: I64( + 831, + ), + }, + KeyValue { + key: Static( + "thread.id", + ), + value: I64( + 0, + ), + }, + KeyValue { + key: Static( + "thread.name", + ), + value: String( + Owned( + "tests::test_basic_span", + ), + ), + }, + KeyValue { + key: Static( + "logfire.msg", + ), + value: String( + Owned( + "debug span", + ), + ), + }, + KeyValue { + key: Static( + "logfire.json_schema", + ), + value: String( + Owned( + "{\"type\":\"object\",\"properties\":{}}", + ), + ), + }, + KeyValue { + key: Static( + "logfire.level_num", + ), + value: I64( + 5, + ), + }, + KeyValue { + key: Static( + "logfire.span_type", + ), + value: String( + Static( + "pending_span", + ), + ), + }, + KeyValue { + key: Static( + "logfire.pending_parent_id", + ), + value: String( + Owned( + "00000000000000f0", + ), + ), + }, + ], + dropped_attributes_count: 0, + events: SpanEvents { + events: [], + dropped_count: 0, + }, + links: SpanLinks { + links: [], + dropped_count: 0, + }, + status: Unset, + instrumentation_scope: InstrumentationScope { + name: "logfire", + version: None, + schema_url: None, + attributes: [], + }, + }, SpanData { span_context: SpanContext { trace_id: 000000000000000000000000000000f0, @@ -1389,7 +1525,143 @@ mod tests { SpanData { span_context: SpanContext { trace_id: 000000000000000000000000000000f0, - span_id: 00000000000000f5, + span_id: 00000000000000f7, + trace_flags: TraceFlags( + 1, + ), + is_remote: false, + trace_state: TraceState( + None, + ), + }, + parent_span_id: 00000000000000f6, + span_kind: Internal, + name: "debug span with explicit parent", + start_time: SystemTime { + tv_sec: 5, + tv_nsec: 0, + }, + end_time: SystemTime { + tv_sec: 5, + tv_nsec: 0, + }, + attributes: [ + KeyValue { + key: Static( + "code.filepath", + ), + value: String( + Static( + "src/lib.rs", + ), + ), + }, + KeyValue { + key: Static( + "code.namespace", + ), + value: String( + Static( + "logfire::tests", + ), + ), + }, + KeyValue { + key: Static( + "code.lineno", + ), + value: I64( + 833, + ), + }, + KeyValue { + key: Static( + "thread.id", + ), + value: I64( + 0, + ), + }, + KeyValue { + key: Static( + "thread.name", + ), + value: String( + Owned( + "tests::test_basic_span", + ), + ), + }, + KeyValue { + key: Static( + "logfire.msg", + ), + value: String( + Owned( + "debug span with explicit parent", + ), + ), + }, + KeyValue { + key: Static( + "logfire.json_schema", + ), + value: String( + Owned( + "{\"type\":\"object\",\"properties\":{}}", + ), + ), + }, + KeyValue { + key: Static( + "logfire.level_num", + ), + value: I64( + 5, + ), + }, + KeyValue { + key: Static( + "logfire.span_type", + ), + value: String( + Static( + "pending_span", + ), + ), + }, + KeyValue { + key: Static( + "logfire.pending_parent_id", + ), + value: String( + Owned( + "00000000000000f0", + ), + ), + }, + ], + dropped_attributes_count: 0, + events: SpanEvents { + events: [], + dropped_count: 0, + }, + links: SpanLinks { + links: [], + dropped_count: 0, + }, + status: Unset, + instrumentation_scope: InstrumentationScope { + name: "logfire", + version: None, + schema_url: None, + attributes: [], + }, + }, + SpanData { + span_context: SpanContext { + trace_id: 000000000000000000000000000000f0, + span_id: 00000000000000f6, trace_flags: TraceFlags( 1, ), @@ -1531,7 +1803,7 @@ mod tests { SpanData { span_context: SpanContext { trace_id: 000000000000000000000000000000f0, - span_id: 00000000000000f6, + span_id: 00000000000000f8, trace_flags: TraceFlags( 1, ), @@ -1657,7 +1929,7 @@ mod tests { SpanData { span_context: SpanContext { trace_id: 000000000000000000000000000000f0, - span_id: 00000000000000f7, + span_id: 00000000000000f9, trace_flags: TraceFlags( 1, ),