Skip to content

Commit 81b459a

Browse files
leghadjeu-christianbantonssoncijothomas
authored
feat(appender-tracing): add experimental span attributes enrichment (open-telemetry#3282)
Co-authored-by: Björn Antonsson <ban@rhsh.net> Co-authored-by: Cijo Thomas <cijo.thomas@gmail.com>
1 parent 8c82831 commit 81b459a

4 files changed

Lines changed: 606 additions & 5 deletions

File tree

‎opentelemetry-appender-tracing/CHANGELOG.md‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,8 @@
22

33
## vNext
44

5+
- New *experimental* feature to enrich log records with attributes from active tracing spans (`experimental_span_attributes`)
6+
57
- Remove the `experimental_use_tracing_span_context` since
68
`tracing-opentelemetry` now supports [activating][31901] the OpenTelemetry
79
context for the current tracing span.

‎opentelemetry-appender-tracing/Cargo.toml‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,7 @@ pprof = { workspace = true }
3434
[features]
3535
default = []
3636
experimental_metadata_attributes = ["dep:tracing-log"]
37+
experimental_span_attributes = []
3738
bench_profiling = []
3839

3940
[[bench]]
@@ -44,6 +45,10 @@ harness = false
4445
name = "log-attributes"
4546
harness = false
4647

48+
[[bench]]
49+
name = "span-attributes"
50+
harness = false
51+
4752
[lib]
4853
bench = false
4954

‎opentelemetry-appender-tracing/benches/span-attributes.rs‎

Lines changed: 247 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,247 @@
1+
/*
2+
// Run this benchmark with:
3+
// cargo bench --bench span-attributes --features experimental_span_attributes
4+
// The benchmark results:
5+
// Hardware: Intel(R) Core(TM) i7-7820HQ CPU @ 2.90GHz (4 cores)
6+
7+
| Test | Average time | Increment |
8+
|---------------------------|--------------|-----------|
9+
| span_4_attributes | 538 ns | - |
10+
| span_8_attributes | 1.03 µs | +492 ns |
11+
| nested_spans_1_levels | 591 ns | - |
12+
| nested_spans_2_levels | 1.42 µs | +829 ns |
13+
| nested_spans_3_levels | 2.24 µs | +820 ns |
14+
15+
*/
16+
17+
use criterion::{criterion_group, criterion_main, Criterion};
18+
use opentelemetry::InstrumentationScope;
19+
use opentelemetry_appender_tracing::layer as tracing_layer;
20+
use opentelemetry_sdk::error::OTelSdkResult;
21+
use opentelemetry_sdk::logs::{LogProcessor, SdkLogRecord, SdkLoggerProvider};
22+
use opentelemetry_sdk::Resource;
23+
#[cfg(all(not(target_os = "windows"), feature = "bench_profiling"))]
24+
use pprof::criterion::{Output, PProfProfiler};
25+
use tracing::info_span;
26+
use tracing_subscriber::prelude::*;
27+
use tracing_subscriber::Registry;
28+
29+
#[derive(Debug)]
30+
struct NoopProcessor;
31+
32+
impl LogProcessor for NoopProcessor {
33+
fn emit(&self, _: &mut SdkLogRecord, _: &InstrumentationScope) {}
34+
35+
fn force_flush(&self) -> OTelSdkResult {
36+
Ok(())
37+
}
38+
39+
fn shutdown_with_timeout(&self, _timeout: std::time::Duration) -> OTelSdkResult {
40+
Ok(())
41+
}
42+
}
43+
44+
/// Creates a benchmark for a specific number of attributes
45+
fn benchmark_span_attributes(c: &mut Criterion, num_attributes: usize) {
46+
let provider = SdkLoggerProvider::builder()
47+
.with_resource(
48+
Resource::builder_empty()
49+
.with_service_name("benchmark")
50+
.build(),
51+
)
52+
.with_log_processor(NoopProcessor)
53+
.build();
54+
55+
let ot_layer = tracing_layer::OpenTelemetryTracingBridge::new(&provider);
56+
let subscriber = Registry::default().with(ot_layer);
57+
58+
tracing::subscriber::with_default(subscriber, || {
59+
c.bench_function(&format!("span_{num_attributes}_attributes"), |b| {
60+
b.iter(|| match num_attributes {
61+
4 => {
62+
let span = info_span!(
63+
"test",
64+
attr1 = "value1",
65+
attr2 = "value2",
66+
attr3 = "value3",
67+
attr4 = "value4"
68+
);
69+
let _enter = span.enter();
70+
}
71+
8 => {
72+
let span = info_span!(
73+
"test",
74+
attr1 = "value1",
75+
attr2 = "value2",
76+
attr3 = "value3",
77+
attr4 = "value4",
78+
attr5 = "value5",
79+
attr6 = "value6",
80+
attr7 = "value7",
81+
attr8 = "value8"
82+
);
83+
let _enter = span.enter();
84+
}
85+
_ => {
86+
// Fall back to 8 attributes for any other number
87+
let span = info_span!(
88+
"test",
89+
attr1 = "value1",
90+
attr2 = "value2",
91+
attr3 = "value3",
92+
attr4 = "value4",
93+
attr5 = "value5",
94+
attr6 = "value6",
95+
attr7 = "value7",
96+
attr8 = "value8"
97+
);
98+
let _enter = span.enter();
99+
}
100+
});
101+
});
102+
});
103+
}
104+
105+
/// Creates a benchmark for nested spans with a specific depth
106+
/// Each span has 4 attributes
107+
fn benchmark_nested_spans(c: &mut Criterion, depth: usize) {
108+
let provider = SdkLoggerProvider::builder()
109+
.with_resource(
110+
Resource::builder_empty()
111+
.with_service_name("benchmark")
112+
.build(),
113+
)
114+
.with_log_processor(NoopProcessor)
115+
.build();
116+
117+
let ot_layer = tracing_layer::OpenTelemetryTracingBridge::new(&provider);
118+
let subscriber = Registry::default().with(ot_layer);
119+
120+
tracing::subscriber::with_default(subscriber, || {
121+
c.bench_function(&format!("nested_spans_{depth}_levels"), |b| {
122+
b.iter(|| match depth {
123+
1 => {
124+
let span1 = info_span!(
125+
"level_1",
126+
depth = 1,
127+
attr1 = "value1",
128+
attr2 = "value2",
129+
attr3 = "value3",
130+
attr4 = "value4"
131+
);
132+
let _enter1 = span1.enter();
133+
}
134+
2 => {
135+
let span1 = info_span!(
136+
"level_1",
137+
depth = 1,
138+
attr1 = "value1",
139+
attr2 = "value2",
140+
attr3 = "value3",
141+
attr4 = "value4"
142+
);
143+
let _enter1 = span1.enter();
144+
{
145+
let span2 = info_span!(
146+
"level_2",
147+
depth = 2,
148+
attr1 = "value1",
149+
attr2 = "value2",
150+
attr3 = "value3",
151+
attr4 = "value4"
152+
);
153+
let _enter2 = span2.enter();
154+
}
155+
}
156+
3 => {
157+
let span1 = info_span!(
158+
"level_1",
159+
depth = 1,
160+
attr1 = "value1",
161+
attr2 = "value2",
162+
attr3 = "value3",
163+
attr4 = "value4"
164+
);
165+
let _enter1 = span1.enter();
166+
{
167+
let span2 = info_span!(
168+
"level_2",
169+
depth = 2,
170+
attr1 = "value1",
171+
attr2 = "value2",
172+
attr3 = "value3",
173+
attr4 = "value4"
174+
);
175+
let _enter2 = span2.enter();
176+
{
177+
let span3 = info_span!(
178+
"level_3",
179+
depth = 3,
180+
attr1 = "value1",
181+
attr2 = "value2",
182+
attr3 = "value3",
183+
attr4 = "value4"
184+
);
185+
let _enter3 = span3.enter();
186+
}
187+
}
188+
}
189+
_ => {
190+
// Fall back to depth 2 for any higher number
191+
let span1 = info_span!(
192+
"level_1",
193+
depth = 1,
194+
attr1 = "value1",
195+
attr2 = "value2",
196+
attr3 = "value3",
197+
attr4 = "value4"
198+
);
199+
let _enter1 = span1.enter();
200+
{
201+
let span2 = info_span!(
202+
"level_2",
203+
depth = 2,
204+
attr1 = "value1",
205+
attr2 = "value2",
206+
attr3 = "value3",
207+
attr4 = "value4"
208+
);
209+
let _enter2 = span2.enter();
210+
}
211+
}
212+
});
213+
});
214+
});
215+
}
216+
217+
fn criterion_benchmark(c: &mut Criterion) {
218+
// Benchmark single spans with 4 and 8 attributes
219+
benchmark_span_attributes(c, 4);
220+
benchmark_span_attributes(c, 8);
221+
222+
// Benchmark nested spans (1-3 levels deep, each with 4 attributes)
223+
for i in 1..=3 {
224+
benchmark_nested_spans(c, i);
225+
}
226+
}
227+
228+
#[cfg(all(not(target_os = "windows"), feature = "bench_profiling"))]
229+
criterion_group! {
230+
name = benches;
231+
config = Criterion::default()
232+
.warm_up_time(std::time::Duration::from_secs(1))
233+
.measurement_time(std::time::Duration::from_secs(2))
234+
.with_profiler(PProfProfiler::new(100, Output::Flamegraph(None)));
235+
targets = criterion_benchmark
236+
}
237+
238+
#[cfg(any(target_os = "windows", not(feature = "bench_profiling")))]
239+
criterion_group! {
240+
name = benches;
241+
config = Criterion::default()
242+
.warm_up_time(std::time::Duration::from_secs(1))
243+
.measurement_time(std::time::Duration::from_secs(2));
244+
targets = criterion_benchmark
245+
}
246+
247+
criterion_main!(benches);

0 commit comments

Comments
 (0)