-
Notifications
You must be signed in to change notification settings - Fork 66
Internal logging code path: Raw logger support #1735
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Changes from all commits
7d91076
51e6559
00cdb25
0aaad0b
d8c7ac2
0c44470
58e988b
52a9610
7cb9db8
b374a47
cd80b0e
c7a7d0b
ce6a95b
165c940
686cd9e
21961df
8f8595c
f9a65a5
b95aea2
82f5cbe
cd4baee
f8f0eb7
92a9337
d80edc6
4e4b37f
657524d
cbb1000
2f02db6
ba09b56
c172e5d
60fea89
b9e8958
a6b6f46
983518f
241158e
93c118e
e235e85
54d6bf4
e1e52c8
7a1baed
9e86542
f277f09
9789407
953e38a
1f37dc1
77e6aed
2ed0f38
7fe247d
725e303
1e4b657
b148d98
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,199 @@ | ||
| // Copyright The OpenTelemetry Authors | ||
| // SPDX-License-Identifier: Apache-2.0 | ||
|
|
||
| //! Benchmarks for the compact log formatter. | ||
| //! | ||
| //! These benchmarks emit a single tracing event but perform N | ||
| //! encoding or encoding-and-formatting operations inside the callback | ||
| //! | ||
| //! Benchmark names follow the pattern: `group/description/N_events` | ||
| //! | ||
| //! Example: `encode/3_attrs/1000_events` = 300 µs → 300 ns per event | ||
|
|
||
| use criterion::{BenchmarkId, Criterion, criterion_group, criterion_main}; | ||
| use tracing::{Event, Subscriber}; | ||
| use tracing_subscriber::layer::Layer; | ||
| use tracing_subscriber::prelude::*; | ||
| use tracing_subscriber::registry::LookupSpan; | ||
|
|
||
| use otap_df_pdata::otlp::ProtoBuffer; | ||
| use otap_df_telemetry::self_tracing::{ | ||
| ConsoleWriter, DirectLogRecordEncoder, LogRecord, SavedCallsite, | ||
| }; | ||
|
|
||
| #[cfg(not(windows))] | ||
| use tikv_jemallocator::Jemalloc; | ||
|
|
||
| #[cfg(not(windows))] | ||
| #[global_allocator] | ||
| static GLOBAL: Jemalloc = Jemalloc; | ||
|
|
||
| /// The operation to perform on each event within the layer. | ||
| #[derive(Clone, Copy)] | ||
| enum BenchOp { | ||
| /// Encode the event into a LogRecord only. | ||
| Encode, | ||
| /// Encode once, then format N times. | ||
| Format, | ||
| /// Encode and format together N times. | ||
| EncodeAndFormat, | ||
| /// Encode to protobuf N times. | ||
| EncodeProto, | ||
| } | ||
|
|
||
| /// A layer that performs a configurable operation N times per event. | ||
| struct BenchLayer { | ||
| iterations: usize, | ||
| op: BenchOp, | ||
| } | ||
|
|
||
| impl BenchLayer { | ||
| fn new(iterations: usize, op: BenchOp) -> Self { | ||
| Self { iterations, op } | ||
| } | ||
| } | ||
|
|
||
| impl<S> Layer<S> for BenchLayer | ||
| where | ||
| S: Subscriber + for<'a> LookupSpan<'a>, | ||
| { | ||
| fn on_event(&self, event: &Event<'_>, _ctx: tracing_subscriber::layer::Context<'_, S>) { | ||
| match self.op { | ||
| BenchOp::Encode => { | ||
| for _ in 0..self.iterations { | ||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. any advantage doing the iteration ourselves, than doing just once, and let criterion do the repeated execution itself?
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. I did this I suppose to be certain that overhead from the subscriber isn't being picked up. I'm pleased when I see 100 executions at 8.6xxx and 1000 executions at 85.xxx. |
||
| let record = LogRecord::new(event); | ||
| let _ = std::hint::black_box(record); | ||
| } | ||
| } | ||
| BenchOp::Format => { | ||
| // Encode once, format N times | ||
| let record = LogRecord::new(event); | ||
| let writer = ConsoleWriter::no_color(); | ||
| let callsite = SavedCallsite::new(event.metadata()); | ||
|
|
||
| for _ in 0..self.iterations { | ||
| let line = writer.format_log_record(&record, &callsite); | ||
| let _ = std::hint::black_box(line); | ||
| } | ||
| } | ||
| BenchOp::EncodeAndFormat => { | ||
| let writer = ConsoleWriter::no_color(); | ||
|
|
||
| for _ in 0..self.iterations { | ||
| let record = LogRecord::new(event); | ||
| let callsite = SavedCallsite::new(event.metadata()); | ||
| let line = writer.format_log_record(&record, &callsite); | ||
| let _ = std::hint::black_box(line); | ||
| } | ||
| } | ||
| BenchOp::EncodeProto => { | ||
| let mut buf = ProtoBuffer::new(); | ||
| let mut encoder = DirectLogRecordEncoder::new(&mut buf); | ||
| let callsite = SavedCallsite::new(event.metadata()); | ||
|
|
||
| for _ in 0..self.iterations { | ||
| encoder.clear(); | ||
| let size = encoder.encode_log_record(LogRecord::new(event), &callsite); | ||
| let _ = std::hint::black_box(size); | ||
| } | ||
| } | ||
| } | ||
| } | ||
| } | ||
|
|
||
| /// Macro to generate benchmark functions for different attribute counts. | ||
| /// Each variant emits a consistent log statement for fair comparison. | ||
| macro_rules! emit_log { | ||
| (0) => { | ||
| tracing::info!("benchmark message") | ||
| }; | ||
| (3) => { | ||
| tracing::info!( | ||
| attr_str = "value", | ||
| attr_int = 42, | ||
| attr_bool = true, | ||
| "benchmark message" | ||
| ) | ||
| }; | ||
| (10) => { | ||
| tracing::info!( | ||
| attr_str1 = "string1", | ||
| attr_bool1 = true, | ||
| attr_str2 = "string2", | ||
| attr_float1 = 1.234, | ||
| attr_int1 = 42i64, | ||
| attr_str3 = "string3", | ||
| attr_bool2 = false, | ||
| attr_float2 = 5.678, | ||
| attr_int2 = 100u64, | ||
| attr_str4 = "string4", | ||
| "benchmark message" | ||
| ) | ||
| }; | ||
| } | ||
|
|
||
| /// Run a benchmark with the given layer, invoking the log emitter. | ||
| fn run_bench<L, F>(b: &mut criterion::Bencher<'_>, layer: L, emit: F) | ||
| where | ||
| L: Layer<tracing_subscriber::Registry> + Send + Sync + 'static, | ||
| F: Fn(), | ||
| { | ||
| let subscriber = tracing_subscriber::registry().with(layer); | ||
| let dispatch = tracing::Dispatch::new(subscriber); | ||
|
|
||
| b.iter(|| { | ||
| tracing::dispatcher::with_default(&dispatch, &emit); | ||
| std::hint::black_box(()); | ||
| }); | ||
| } | ||
|
|
||
| /// Benchmark a specific operation across different iteration counts. | ||
| fn bench_op(c: &mut Criterion, group_name: &str, op: BenchOp) { | ||
| let mut group = c.benchmark_group(group_name); | ||
|
|
||
| for &iterations in &[100, 1000] { | ||
| for &(attr_count, attr_label) in &[(0, "0_attrs"), (3, "3_attrs"), (10, "10_attrs")] { | ||
| let id = BenchmarkId::new(attr_label, format!("{}_events", iterations)); | ||
|
|
||
| let _ = group.bench_with_input(id, &iterations, |b, &iters| { | ||
| let layer = BenchLayer::new(iters, op); | ||
| match attr_count { | ||
| 0 => run_bench(b, layer, || emit_log!(0)), | ||
| 3 => run_bench(b, layer, || emit_log!(3)), | ||
| _ => run_bench(b, layer, || emit_log!(10)), | ||
| } | ||
| }); | ||
| } | ||
| } | ||
|
|
||
| group.finish(); | ||
| } | ||
|
|
||
| fn bench_encode(c: &mut Criterion) { | ||
| bench_op(c, "encode", BenchOp::Encode); | ||
| } | ||
|
|
||
| fn bench_format(c: &mut Criterion) { | ||
| bench_op(c, "format", BenchOp::Format); | ||
| } | ||
|
|
||
| fn bench_encode_and_format(c: &mut Criterion) { | ||
| bench_op(c, "encode_and_format", BenchOp::EncodeAndFormat); | ||
| } | ||
|
|
||
| fn bench_encode_proto(c: &mut Criterion) { | ||
| bench_op(c, "encode_proto", BenchOp::EncodeProto); | ||
| } | ||
|
|
||
| #[allow(missing_docs)] | ||
| mod bench_entry { | ||
| use super::*; | ||
|
|
||
| criterion_group!( | ||
| name = benches; | ||
| config = Criterion::default(); | ||
| targets = bench_encode, bench_format, bench_encode_and_format, bench_encode_proto | ||
| ); | ||
| } | ||
|
|
||
| criterion_main!(bench_entry::benches); | ||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
https://github.com/open-telemetry/opentelemetry-rust/pull/3307/changes
I was adding similar benches in OTel Rust to measure the cost of conversions!