1use opentelemetry::{
2 logs::{AnyValue, LogRecord, Logger, LoggerProvider, Severity},
3 Context, InstrumentationScope, Key,
4};
5use std::borrow::Cow;
6use tracing_core::Level;
7#[cfg(feature = "experimental_metadata_attributes")]
8use tracing_core::Metadata;
9#[cfg(feature = "experimental_metadata_attributes")]
10use tracing_log::NormalizeEvent;
11use tracing_subscriber::Layer;
12
13const INSTRUMENTATION_LIBRARY_NAME: &str = "opentelemetry-appender-tracing";
14
15struct EventVisitor<'a, LR: LogRecord> {
17 log_record: &'a mut LR,
18}
19
20#[cfg(feature = "experimental_metadata_attributes")]
22fn is_duplicated_metadata(field: &'static str) -> bool {
23 field
24 .strip_prefix("log.")
25 .map(|remainder| matches!(remainder, "file" | "line" | "module_path" | "target"))
26 .unwrap_or(false)
27}
28
29#[cfg(feature = "experimental_metadata_attributes")]
30fn get_filename(filepath: &str) -> &str {
31 if let Some((_, filename)) = filepath.rsplit_once('/') {
32 return filename;
33 }
34 if let Some((_, filename)) = filepath.rsplit_once('\\') {
35 return filename;
36 }
37 filepath
38}
39
40impl<'a, LR: LogRecord> EventVisitor<'a, LR> {
41 fn new(log_record: &'a mut LR) -> Self {
42 EventVisitor { log_record }
43 }
44
45 #[cfg(feature = "experimental_metadata_attributes")]
46 fn visit_experimental_metadata(&mut self, meta: &Metadata) {
47 if let Some(module_path) = meta.module_path() {
48 self.log_record.add_attribute(
49 Key::new("code.namespace"),
50 AnyValue::from(module_path.to_owned()),
51 );
52 }
53
54 if let Some(filepath) = meta.file() {
55 self.log_record.add_attribute(
56 Key::new("code.filepath"),
57 AnyValue::from(filepath.to_owned()),
58 );
59 self.log_record.add_attribute(
60 Key::new("code.filename"),
61 AnyValue::from(get_filename(filepath).to_owned()),
62 );
63 }
64
65 if let Some(line) = meta.line() {
66 self.log_record
67 .add_attribute(Key::new("code.lineno"), AnyValue::from(line));
68 }
69 }
70}
71
72impl<LR: LogRecord> tracing::field::Visit for EventVisitor<'_, LR> {
73 fn record_debug(&mut self, field: &tracing::field::Field, value: &dyn std::fmt::Debug) {
74 #[cfg(feature = "experimental_metadata_attributes")]
75 if is_duplicated_metadata(field.name()) {
76 return;
77 }
78 if field.name() == "message" {
79 self.log_record.set_body(format!("{:?}", value).into());
80 } else {
81 self.log_record
82 .add_attribute(Key::new(field.name()), AnyValue::from(format!("{value:?}")));
83 }
84 }
85
86 fn record_str(&mut self, field: &tracing_core::Field, value: &str) {
87 #[cfg(feature = "experimental_metadata_attributes")]
88 if is_duplicated_metadata(field.name()) {
89 return;
90 }
91 self.log_record
99 .add_attribute(Key::new(field.name()), AnyValue::from(value.to_owned()));
100 }
101
102 fn record_bool(&mut self, field: &tracing_core::Field, value: bool) {
103 self.log_record
104 .add_attribute(Key::new(field.name()), AnyValue::from(value));
105 }
106
107 fn record_f64(&mut self, field: &tracing::field::Field, value: f64) {
108 self.log_record
109 .add_attribute(Key::new(field.name()), AnyValue::from(value));
110 }
111
112 fn record_i64(&mut self, field: &tracing::field::Field, value: i64) {
113 #[cfg(feature = "experimental_metadata_attributes")]
114 if is_duplicated_metadata(field.name()) {
115 return;
116 }
117 self.log_record
118 .add_attribute(Key::new(field.name()), AnyValue::from(value));
119 }
120
121 }
123
124pub struct OpenTelemetryTracingBridge<P, L>
125where
126 P: LoggerProvider<Logger = L> + Send + Sync,
127 L: Logger + Send + Sync,
128{
129 logger: L,
130 _phantom: std::marker::PhantomData<P>, }
132
133impl<P, L> OpenTelemetryTracingBridge<P, L>
134where
135 P: LoggerProvider<Logger = L> + Send + Sync,
136 L: Logger + Send + Sync,
137{
138 pub fn new(provider: &P) -> Self {
139 let scope = InstrumentationScope::builder(INSTRUMENTATION_LIBRARY_NAME)
140 .with_version(Cow::Borrowed(env!("CARGO_PKG_VERSION")))
141 .build();
142
143 OpenTelemetryTracingBridge {
144 logger: provider.logger_with_scope(scope),
145 _phantom: Default::default(),
146 }
147 }
148}
149
150impl<S, P, L> Layer<S> for OpenTelemetryTracingBridge<P, L>
151where
152 S: tracing::Subscriber,
153 P: LoggerProvider<Logger = L> + Send + Sync + 'static,
154 L: Logger + Send + Sync + 'static,
155{
156 fn on_event(
157 &self,
158 event: &tracing::Event<'_>,
159 _ctx: tracing_subscriber::layer::Context<'_, S>,
160 ) {
161 #[cfg(feature = "experimental_metadata_attributes")]
162 let normalized_meta = event.normalized_metadata();
163
164 #[cfg(feature = "experimental_metadata_attributes")]
165 let meta = normalized_meta.as_ref().unwrap_or_else(|| event.metadata());
166
167 #[cfg(not(feature = "experimental_metadata_attributes"))]
168 let meta = event.metadata();
169
170 let mut log_record = self.logger.create_log_record();
171
172 log_record.set_target(meta.target().to_string());
174 log_record.set_event_name(meta.name());
175 log_record.set_severity_number(severity_of_level(meta.level()));
176 log_record.set_severity_text(meta.level().as_str());
177 if let Some(trace_id) = find_current_trace_id() {
178 log_record.add_attribute("trace.id", trace_id);
179 } else {
180 log_record.add_attribute("trace.id", "none");
181 }
182 if let Some(span_id) = tracing::Span::current().id() {
183 log_record.add_attribute("span.id", span_id.into_u64().to_string());
184 }
185 let mut visitor = EventVisitor::new(&mut log_record);
186 #[cfg(feature = "experimental_metadata_attributes")]
187 visitor.visit_experimental_metadata(meta);
188 event.record(&mut visitor);
190
191 self.logger.emit(log_record);
193 }
194
195 #[cfg(feature = "spec_unstable_logs_enabled")]
196 fn event_enabled(
197 &self,
198 _event: &tracing_core::Event<'_>,
199 _ctx: tracing_subscriber::layer::Context<'_, S>,
200 ) -> bool {
201 let severity = severity_of_level(_event.metadata().level());
202 self.logger
203 .event_enabled(severity, _event.metadata().target())
204 }
205}
206
207const fn severity_of_level(level: &Level) -> Severity {
208 match *level {
209 Level::TRACE => Severity::Trace,
210 Level::DEBUG => Severity::Debug,
211 Level::INFO => Severity::Info,
212 Level::WARN => Severity::Warn,
213 Level::ERROR => Severity::Error,
214 }
215}
216
217fn find_current_context() -> Context {
218 use tracing_opentelemetry::OpenTelemetrySpanExt;
219 tracing::Span::current().context()
220}
221
222fn find_current_trace_id() -> Option<String> {
223 find_trace_id(&find_current_context())
224}
225
226fn find_trace_id(context: &Context) -> Option<String> {
227 use opentelemetry::trace::TraceContextExt;
228
229 let span = context.span();
230 let span_context = span.span_context();
231 span_context
232 .is_valid()
233 .then(|| span_context.trace_id().to_string())
234}
235
236#[cfg(test)]
237mod tests {
238 use crate::layer;
239 use async_trait::async_trait;
240 use opentelemetry::logs::Severity;
241 use opentelemetry::trace::TracerProvider as _;
242 use opentelemetry::trace::{TraceContextExt, TraceFlags, Tracer};
243 use opentelemetry::{logs::AnyValue, Key};
244 use opentelemetry_sdk::export::logs::{LogBatch, LogExporter};
245 use opentelemetry_sdk::logs::{LogRecord, LogResult, LoggerProvider};
246 use opentelemetry_sdk::testing::logs::InMemoryLogExporter;
247 use opentelemetry_sdk::trace::{Sampler, TracerProvider};
248 use tracing::{error, warn};
249 use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt;
250 use tracing_subscriber::util::SubscriberInitExt;
251 use tracing_subscriber::{EnvFilter, Layer};
252
253 pub fn attributes_contains(log_record: &LogRecord, key: &Key, value: &AnyValue) -> bool {
254 log_record
255 .attributes_iter()
256 .any(|(k, v)| k == key && v == value)
257 }
258
259 fn create_tracing_subscriber(
260 _exporter: InMemoryLogExporter,
261 logger_provider: &LoggerProvider,
262 ) -> impl tracing::Subscriber {
263 let level_filter = tracing_subscriber::filter::LevelFilter::WARN; let layer =
265 layer::OpenTelemetryTracingBridge::new(logger_provider).with_filter(level_filter); tracing_subscriber::registry().with(layer)
268 }
269
270 #[derive(Clone, Debug, Default)]
273 struct ReentrantLogExporter;
274
275 #[async_trait]
276 impl LogExporter for ReentrantLogExporter {
277 async fn export(&self, _batch: LogBatch<'_>) -> LogResult<()> {
278 warn!(name: "my-event-name", target: "reentrant", event_id = 20, user_name = "otel", user_email = "otel@opentelemetry.io");
281 Ok(())
282 }
283 }
284
285 #[test]
286 #[ignore = "See issue: https://github.com/open-telemetry/opentelemetry-rust/issues/1745"]
287 fn simple_processor_deadlock() {
288 let exporter: ReentrantLogExporter = ReentrantLogExporter;
289 let logger_provider = LoggerProvider::builder()
290 .with_simple_exporter(exporter.clone())
291 .build();
292
293 let layer = layer::OpenTelemetryTracingBridge::new(&logger_provider);
294
295 tracing_subscriber::registry().with(layer).init();
297 warn!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "otel@opentelemetry.io");
298 }
299
300 #[test]
301 #[ignore = "While this test runs fine, this uses global subscriber and does not play well with other tests."]
302 fn simple_processor_no_deadlock() {
303 let exporter: ReentrantLogExporter = ReentrantLogExporter;
304 let logger_provider = LoggerProvider::builder()
305 .with_simple_exporter(exporter.clone())
306 .build();
307
308 let layer = layer::OpenTelemetryTracingBridge::new(&logger_provider);
309
310 let filter = EnvFilter::new("debug").add_directive("reentrant=error".parse().unwrap());
313 tracing_subscriber::registry()
315 .with(filter)
316 .with(layer)
317 .init();
318 warn!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "otel@opentelemetry.io");
319 }
320
321 #[tokio::test(flavor = "multi_thread", worker_threads = 1)]
322 #[ignore = "While this test runs fine, this uses global subscriber and does not play well with other tests."]
323 async fn batch_processor_no_deadlock() {
324 let exporter: ReentrantLogExporter = ReentrantLogExporter;
325 let logger_provider = LoggerProvider::builder()
326 .with_batch_exporter(exporter.clone(), opentelemetry_sdk::runtime::Tokio)
327 .build();
328
329 let layer = layer::OpenTelemetryTracingBridge::new(&logger_provider);
330
331 tracing_subscriber::registry().with(layer).init();
332 warn!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "otel@opentelemetry.io");
333 }
334
335 #[test]
336 fn tracing_appender_standalone() {
337 let exporter: InMemoryLogExporter = InMemoryLogExporter::default();
339 let logger_provider = LoggerProvider::builder()
340 .with_simple_exporter(exporter.clone())
341 .build();
342
343 let subscriber = create_tracing_subscriber(exporter.clone(), &logger_provider);
344
345 let _guard = tracing::subscriber::set_default(subscriber);
348
349 error!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "otel@opentelemetry.io");
351 logger_provider.force_flush();
352
353 let exported_logs = exporter
355 .get_emitted_logs()
356 .expect("Logs are expected to be exported.");
357 assert_eq!(exported_logs.len(), 1);
358 let log = exported_logs
359 .first()
360 .expect("Atleast one log is expected to be present.");
361
362 assert_eq!(log.instrumentation.name(), "opentelemetry-appender-tracing");
364 assert_eq!(log.record.severity_number, Some(Severity::Error));
365
366 assert!(log.record.trace_context.is_none());
368
369 #[cfg(not(feature = "experimental_metadata_attributes"))]
371 assert_eq!(log.record.attributes_iter().count(), 3);
372 #[cfg(feature = "experimental_metadata_attributes")]
373 assert_eq!(log.record.attributes_iter().count(), 7);
374 assert!(attributes_contains(
375 &log.record,
376 &Key::new("event_id"),
377 &AnyValue::Int(20)
378 ));
379 assert!(attributes_contains(
380 &log.record,
381 &Key::new("user_name"),
382 &AnyValue::String("otel".into())
383 ));
384 assert!(attributes_contains(
385 &log.record,
386 &Key::new("user_email"),
387 &AnyValue::String("otel@opentelemetry.io".into())
388 ));
389 #[cfg(feature = "experimental_metadata_attributes")]
390 {
391 assert!(attributes_contains(
392 &log.record,
393 &Key::new("code.filename"),
394 &AnyValue::String("layer.rs".into())
395 ));
396 assert!(attributes_contains(
397 &log.record,
398 &Key::new("code.namespace"),
399 &AnyValue::String("opentelemetry_appender_tracing::layer::tests".into())
400 ));
401 let attributes_key: Vec<Key> = log
405 .record
406 .attributes_iter()
407 .map(|(key, _)| key.clone())
408 .collect();
409 assert!(attributes_key.contains(&Key::new("code.filepath")));
410 assert!(attributes_key.contains(&Key::new("code.lineno")));
411 assert!(!attributes_key.contains(&Key::new("log.target")));
412 }
413 }
414
415 #[test]
416 fn tracing_appender_inside_tracing_context() {
417 let exporter: InMemoryLogExporter = InMemoryLogExporter::default();
419 let logger_provider = LoggerProvider::builder()
420 .with_simple_exporter(exporter.clone())
421 .build();
422
423 let subscriber = create_tracing_subscriber(exporter.clone(), &logger_provider);
424
425 let _guard = tracing::subscriber::set_default(subscriber);
428
429 let tracer_provider = TracerProvider::builder()
431 .with_sampler(Sampler::AlwaysOn)
432 .build();
433 let tracer = tracer_provider.tracer("test-tracer");
434
435 let (trace_id_expected, span_id_expected) = tracer.in_span("test-span", |cx| {
437 let trace_id = cx.span().span_context().trace_id();
438 let span_id = cx.span().span_context().span_id();
439
440 error!(name: "my-event-name", target: "my-system", event_id = 20, user_name = "otel", user_email = "otel@opentelemetry.io");
442 (trace_id, span_id)
443 });
444
445 logger_provider.force_flush();
446
447 let exported_logs = exporter
449 .get_emitted_logs()
450 .expect("Logs are expected to be exported.");
451 assert_eq!(exported_logs.len(), 1);
452 let log = exported_logs
453 .first()
454 .expect("Atleast one log is expected to be present.");
455
456 assert_eq!(log.instrumentation.name(), "opentelemetry-appender-tracing");
458 assert_eq!(log.record.severity_number, Some(Severity::Error));
459
460 assert!(log.record.trace_context.is_some());
462 assert_eq!(
463 log.record.trace_context.as_ref().unwrap().trace_id,
464 trace_id_expected
465 );
466 assert_eq!(
467 log.record.trace_context.as_ref().unwrap().span_id,
468 span_id_expected
469 );
470 assert_eq!(
471 log.record
472 .trace_context
473 .as_ref()
474 .unwrap()
475 .trace_flags
476 .unwrap(),
477 TraceFlags::SAMPLED
478 );
479
480 #[cfg(not(feature = "experimental_metadata_attributes"))]
482 assert_eq!(log.record.attributes_iter().count(), 3);
483 #[cfg(feature = "experimental_metadata_attributes")]
484 assert_eq!(log.record.attributes_iter().count(), 7);
485 assert!(attributes_contains(
486 &log.record,
487 &Key::new("event_id"),
488 &AnyValue::Int(20.into())
489 ));
490 assert!(attributes_contains(
491 &log.record,
492 &Key::new("user_name"),
493 &AnyValue::String("otel".into())
494 ));
495 assert!(attributes_contains(
496 &log.record,
497 &Key::new("user_email"),
498 &AnyValue::String("otel@opentelemetry.io".into())
499 ));
500 #[cfg(feature = "experimental_metadata_attributes")]
501 {
502 assert!(attributes_contains(
503 &log.record,
504 &Key::new("code.filename"),
505 &AnyValue::String("layer.rs".into())
506 ));
507 assert!(attributes_contains(
508 &log.record,
509 &Key::new("code.namespace"),
510 &AnyValue::String("opentelemetry_appender_tracing::layer::tests".into())
511 ));
512 let attributes_key: Vec<Key> = log
516 .record
517 .attributes_iter()
518 .map(|(key, _)| key.clone())
519 .collect();
520 assert!(attributes_key.contains(&Key::new("code.filepath")));
521 assert!(attributes_key.contains(&Key::new("code.lineno")));
522 assert!(!attributes_key.contains(&Key::new("log.target")));
523 }
524 }
525
526 #[test]
527 fn tracing_appender_standalone_with_tracing_log() {
528 let exporter: InMemoryLogExporter = InMemoryLogExporter::default();
530 let logger_provider = LoggerProvider::builder()
531 .with_simple_exporter(exporter.clone())
532 .build();
533
534 let subscriber = create_tracing_subscriber(exporter.clone(), &logger_provider);
535
536 let _guard = tracing::subscriber::set_default(subscriber);
539 drop(tracing_log::LogTracer::init());
540
541 log::error!(target: "my-system", "log from log crate");
543 logger_provider.force_flush();
544
545 let exported_logs = exporter
547 .get_emitted_logs()
548 .expect("Logs are expected to be exported.");
549 assert_eq!(exported_logs.len(), 1);
550 let log = exported_logs
551 .first()
552 .expect("Atleast one log is expected to be present.");
553
554 assert_eq!(log.instrumentation.name(), "opentelemetry-appender-tracing");
556 assert_eq!(log.record.severity_number, Some(Severity::Error));
557
558 assert!(log.record.trace_context.is_none());
560
561 #[cfg(feature = "experimental_metadata_attributes")]
563 assert_eq!(log.record.attributes_iter().count(), 4);
564
565 #[cfg(feature = "experimental_metadata_attributes")]
566 {
567 assert!(attributes_contains(
568 &log.record,
569 &Key::new("code.filename"),
570 &AnyValue::String("layer.rs".into())
571 ));
572 assert!(attributes_contains(
573 &log.record,
574 &Key::new("code.namespace"),
575 &AnyValue::String("opentelemetry_appender_tracing::layer::tests".into())
576 ));
577 let attributes_key: Vec<Key> = log
581 .record
582 .attributes_iter()
583 .map(|(key, _)| key.clone())
584 .collect();
585 assert!(attributes_key.contains(&Key::new("code.filepath")));
586 assert!(attributes_key.contains(&Key::new("code.lineno")));
587 assert!(!attributes_key.contains(&Key::new("log.target")));
588 }
589 }
590
591 #[test]
592 fn tracing_appender_inside_tracing_context_with_tracing_log() {
593 let exporter: InMemoryLogExporter = InMemoryLogExporter::default();
595 let logger_provider = LoggerProvider::builder()
596 .with_simple_exporter(exporter.clone())
597 .build();
598
599 let subscriber = create_tracing_subscriber(exporter.clone(), &logger_provider);
600
601 let _guard = tracing::subscriber::set_default(subscriber);
604 drop(tracing_log::LogTracer::init());
605
606 let tracer_provider = TracerProvider::builder()
608 .with_sampler(Sampler::AlwaysOn)
609 .build();
610 let tracer = tracer_provider.tracer("test-tracer");
611
612 let (trace_id_expected, span_id_expected) = tracer.in_span("test-span", |cx| {
614 let trace_id = cx.span().span_context().trace_id();
615 let span_id = cx.span().span_context().span_id();
616
617 log::error!(target: "my-system", "log from log crate");
619 (trace_id, span_id)
620 });
621
622 logger_provider.force_flush();
623
624 let exported_logs = exporter
626 .get_emitted_logs()
627 .expect("Logs are expected to be exported.");
628 assert_eq!(exported_logs.len(), 1);
629 let log = exported_logs
630 .first()
631 .expect("Atleast one log is expected to be present.");
632
633 assert_eq!(log.instrumentation.name(), "opentelemetry-appender-tracing");
635 assert_eq!(log.record.severity_number, Some(Severity::Error));
636
637 assert!(log.record.trace_context.is_some());
639 assert_eq!(
640 log.record.trace_context.as_ref().unwrap().trace_id,
641 trace_id_expected
642 );
643 assert_eq!(
644 log.record.trace_context.as_ref().unwrap().span_id,
645 span_id_expected
646 );
647 assert_eq!(
648 log.record
649 .trace_context
650 .as_ref()
651 .unwrap()
652 .trace_flags
653 .unwrap(),
654 TraceFlags::SAMPLED
655 );
656
657 #[cfg(feature = "experimental_metadata_attributes")]
659 assert_eq!(log.record.attributes_iter().count(), 4);
660
661 #[cfg(feature = "experimental_metadata_attributes")]
662 {
663 assert!(attributes_contains(
664 &log.record,
665 &Key::new("code.filename"),
666 &AnyValue::String("layer.rs".into())
667 ));
668 assert!(attributes_contains(
669 &log.record,
670 &Key::new("code.namespace"),
671 &AnyValue::String("opentelemetry_appender_tracing::layer::tests".into())
672 ));
673 let attributes_key: Vec<Key> = log
677 .record
678 .attributes_iter()
679 .map(|(key, _)| key.clone())
680 .collect();
681 assert!(attributes_key.contains(&Key::new("code.filepath")));
682 assert!(attributes_key.contains(&Key::new("code.lineno")));
683 assert!(!attributes_key.contains(&Key::new("log.target")));
684 }
685 }
686}