1use crate::{
2 field::RecordFields,
3 fmt::{format, FormatEvent, FormatFields, MakeWriter, TestWriter},
4 layer::{self, Context},
5 registry::{self, LookupSpan, SpanRef},
6};
7use alloc::{fmt, format, string::String};
8use core::{any::TypeId, marker::PhantomData, ops::Deref};
9use format::{FmtSpan, TimingDisplay};
10use std::{cell::RefCell, env, eprintln, io, thread_local, time::Instant};
11use tracing_core::{
12 field,
13 span::{Attributes, Current, Id, Record},
14 Event, Metadata, Subscriber,
15};
16
17#[cfg_attr(docsrs, doc(cfg(all(feature = "fmt", feature = "std"))))]
63#[derive(Debug)]
64pub struct Layer<
65 S,
66 N = format::DefaultFields,
67 E = format::Format<format::Full>,
68 W = fn() -> io::Stdout,
69> {
70 make_writer: W,
71 fmt_fields: N,
72 fmt_event: E,
73 fmt_span: format::FmtSpanConfig,
74 is_ansi: bool,
75 log_internal_errors: bool,
76 max_buf_capacity: Option<usize>,
77 _inner: PhantomData<fn(S)>,
78}
79
80impl<S> Layer<S> {
81 pub fn new() -> Self {
83 Self::default()
84 }
85}
86
87impl<S, N, E, W> Layer<S, N, E, W>
89where
90 S: Subscriber + for<'a> LookupSpan<'a>,
91 N: for<'writer> FormatFields<'writer> + 'static,
92 W: for<'writer> MakeWriter<'writer> + 'static,
93{
94 pub fn event_format<E2>(self, e: E2) -> Layer<S, N, E2, W>
117 where
118 E2: FormatEvent<S, N> + 'static,
119 {
120 Layer {
121 fmt_fields: self.fmt_fields,
122 fmt_event: e,
123 fmt_span: self.fmt_span,
124 make_writer: self.make_writer,
125 is_ansi: self.is_ansi,
126 log_internal_errors: self.log_internal_errors,
127 max_buf_capacity: self.max_buf_capacity,
128 _inner: self._inner,
129 }
130 }
131
132 pub fn map_event_format<E2>(self, f: impl FnOnce(E) -> E2) -> Layer<S, N, E2, W>
148 where
149 E2: FormatEvent<S, N> + 'static,
150 {
151 Layer {
152 fmt_fields: self.fmt_fields,
153 fmt_event: f(self.fmt_event),
154 fmt_span: self.fmt_span,
155 make_writer: self.make_writer,
156 is_ansi: self.is_ansi,
157 log_internal_errors: self.log_internal_errors,
158 max_buf_capacity: self.max_buf_capacity,
159 _inner: self._inner,
160 }
161 }
162}
163
164impl<S, N, E, W> Layer<S, N, E, W> {
166 pub fn with_writer<W2>(self, make_writer: W2) -> Layer<S, N, E, W2>
183 where
184 W2: for<'writer> MakeWriter<'writer> + 'static,
185 {
186 Layer {
187 fmt_fields: self.fmt_fields,
188 fmt_event: self.fmt_event,
189 fmt_span: self.fmt_span,
190 is_ansi: self.is_ansi,
191 log_internal_errors: self.log_internal_errors,
192 max_buf_capacity: self.max_buf_capacity,
193 make_writer,
194 _inner: self._inner,
195 }
196 }
197
198 pub fn writer(&self) -> &W {
202 &self.make_writer
203 }
204
205 pub fn writer_mut(&mut self) -> &mut W {
233 &mut self.make_writer
234 }
235
236 #[cfg(feature = "ansi")]
243 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
244 pub fn set_ansi(&mut self, ansi: bool) {
245 self.is_ansi = ansi;
246 }
247
248 pub fn set_span_events(&mut self, kind: FmtSpan) {
263 self.fmt_span = format::FmtSpanConfig {
264 kind,
265 fmt_timing: self.fmt_span.fmt_timing,
266 }
267 }
268
269 pub fn with_test_writer(self) -> Layer<S, N, E, TestWriter> {
292 Layer {
293 fmt_fields: self.fmt_fields,
294 fmt_event: self.fmt_event,
295 fmt_span: self.fmt_span,
296 is_ansi: self.is_ansi,
297 log_internal_errors: self.log_internal_errors,
298 max_buf_capacity: self.max_buf_capacity,
299 make_writer: TestWriter::default(),
300 _inner: self._inner,
301 }
302 }
303
304 pub fn with_ansi(self, ansi: bool) -> Self {
332 #[cfg(not(feature = "ansi"))]
333 if ansi {
334 const ERROR: &str =
335 "tracing-subscriber: the `ansi` crate feature is required to enable ANSI terminal colors";
336 #[cfg(debug_assertions)]
337 panic!("{}", ERROR);
338 #[cfg(not(debug_assertions))]
339 eprintln!("{}", ERROR);
340 }
341
342 Self {
343 is_ansi: ansi,
344 ..self
345 }
346 }
347
348 pub fn log_internal_errors(self, log_internal_errors: bool) -> Self {
360 Self {
361 log_internal_errors,
362 ..self
363 }
364 }
365
366 pub fn with_buf_capacity_limit(self, max_capacity: usize) -> Self {
371 Self {
372 max_buf_capacity: Some(max_capacity),
373 ..self
374 }
375 }
376
377 pub fn map_writer<W2>(self, f: impl FnOnce(W) -> W2) -> Layer<S, N, E, W2>
397 where
398 W2: for<'writer> MakeWriter<'writer> + 'static,
399 {
400 Layer {
401 fmt_fields: self.fmt_fields,
402 fmt_event: self.fmt_event,
403 fmt_span: self.fmt_span,
404 is_ansi: self.is_ansi,
405 log_internal_errors: self.log_internal_errors,
406 max_buf_capacity: self.max_buf_capacity,
407 make_writer: f(self.make_writer),
408 _inner: self._inner,
409 }
410 }
411}
412
413impl<S, N, L, T, W> Layer<S, N, format::Format<L, T>, W>
414where
415 N: for<'writer> FormatFields<'writer> + 'static,
416{
417 pub fn with_timer<T2>(self, timer: T2) -> Layer<S, N, format::Format<L, T2>, W> {
432 Layer {
433 fmt_event: self.fmt_event.with_timer(timer),
434 fmt_fields: self.fmt_fields,
435 fmt_span: self.fmt_span,
436 make_writer: self.make_writer,
437 is_ansi: self.is_ansi,
438 log_internal_errors: self.log_internal_errors,
439 max_buf_capacity: self.max_buf_capacity,
440 _inner: self._inner,
441 }
442 }
443
444 pub fn without_time(self) -> Layer<S, N, format::Format<L, ()>, W> {
446 Layer {
447 fmt_event: self.fmt_event.without_time(),
448 fmt_fields: self.fmt_fields,
449 fmt_span: self.fmt_span.without_time(),
450 make_writer: self.make_writer,
451 is_ansi: self.is_ansi,
452 log_internal_errors: self.log_internal_errors,
453 max_buf_capacity: self.max_buf_capacity,
454 _inner: self._inner,
455 }
456 }
457
458 pub fn with_span_events(self, kind: FmtSpan) -> Self {
500 Layer {
501 fmt_span: self.fmt_span.with_kind(kind),
502 ..self
503 }
504 }
505
506 pub fn with_target(self, display_target: bool) -> Layer<S, N, format::Format<L, T>, W> {
508 Layer {
509 fmt_event: self.fmt_event.with_target(display_target),
510 ..self
511 }
512 }
513 pub fn with_file(self, display_filename: bool) -> Layer<S, N, format::Format<L, T>, W> {
518 Layer {
519 fmt_event: self.fmt_event.with_file(display_filename),
520 ..self
521 }
522 }
523
524 pub fn with_line_number(
529 self,
530 display_line_number: bool,
531 ) -> Layer<S, N, format::Format<L, T>, W> {
532 Layer {
533 fmt_event: self.fmt_event.with_line_number(display_line_number),
534 ..self
535 }
536 }
537
538 pub fn with_level(self, display_level: bool) -> Layer<S, N, format::Format<L, T>, W> {
540 Layer {
541 fmt_event: self.fmt_event.with_level(display_level),
542 ..self
543 }
544 }
545
546 pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W> {
551 Layer {
552 fmt_event: self.fmt_event.with_thread_ids(display_thread_ids),
553 ..self
554 }
555 }
556
557 pub fn with_thread_names(
562 self,
563 display_thread_names: bool,
564 ) -> Layer<S, N, format::Format<L, T>, W> {
565 Layer {
566 fmt_event: self.fmt_event.with_thread_names(display_thread_names),
567 ..self
568 }
569 }
570
571 pub fn compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W>
573 where
574 N: for<'writer> FormatFields<'writer> + 'static,
575 {
576 Layer {
577 fmt_event: self.fmt_event.compact(),
578 fmt_fields: self.fmt_fields,
579 fmt_span: self.fmt_span,
580 make_writer: self.make_writer,
581 is_ansi: self.is_ansi,
582 log_internal_errors: self.log_internal_errors,
583 max_buf_capacity: self.max_buf_capacity,
584 _inner: self._inner,
585 }
586 }
587
588 #[cfg(feature = "ansi")]
590 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
591 pub fn pretty(self) -> Layer<S, format::Pretty, format::Format<format::Pretty, T>, W> {
592 Layer {
593 fmt_event: self.fmt_event.pretty(),
594 fmt_fields: format::Pretty::default(),
595 fmt_span: self.fmt_span,
596 make_writer: self.make_writer,
597 is_ansi: self.is_ansi,
598 log_internal_errors: self.log_internal_errors,
599 max_buf_capacity: self.max_buf_capacity,
600 _inner: self._inner,
601 }
602 }
603
604 #[cfg(feature = "json")]
621 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
622 pub fn json(self) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
623 Layer {
624 fmt_event: self.fmt_event.json(),
625 fmt_fields: format::JsonFields::new(),
626 fmt_span: self.fmt_span,
627 make_writer: self.make_writer,
628 is_ansi: false,
630 log_internal_errors: self.log_internal_errors,
631 max_buf_capacity: self.max_buf_capacity,
632 _inner: self._inner,
633 }
634 }
635}
636
637#[cfg(feature = "json")]
638#[cfg_attr(docsrs, doc(cfg(feature = "json")))]
639impl<S, T, W> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
640 pub fn flatten_event(
644 self,
645 flatten_event: bool,
646 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
647 Layer {
648 fmt_event: self.fmt_event.flatten_event(flatten_event),
649 fmt_fields: format::JsonFields::new(),
650 ..self
651 }
652 }
653
654 pub fn with_current_span(
659 self,
660 display_current_span: bool,
661 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
662 Layer {
663 fmt_event: self.fmt_event.with_current_span(display_current_span),
664 fmt_fields: format::JsonFields::new(),
665 ..self
666 }
667 }
668
669 pub fn with_span_list(
674 self,
675 display_span_list: bool,
676 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
677 Layer {
678 fmt_event: self.fmt_event.with_span_list(display_span_list),
679 fmt_fields: format::JsonFields::new(),
680 ..self
681 }
682 }
683}
684
685impl<S, N, E, W> Layer<S, N, E, W> {
686 pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Layer<S, N2, E, W>
689 where
690 N2: for<'writer> FormatFields<'writer> + 'static,
691 {
692 Layer {
693 fmt_event: self.fmt_event,
694 fmt_fields,
695 fmt_span: self.fmt_span,
696 make_writer: self.make_writer,
697 is_ansi: self.is_ansi,
698 log_internal_errors: self.log_internal_errors,
699 max_buf_capacity: self.max_buf_capacity,
700 _inner: self._inner,
701 }
702 }
703
704 pub fn map_fmt_fields<N2>(self, f: impl FnOnce(N) -> N2) -> Layer<S, N2, E, W>
721 where
722 N2: for<'writer> FormatFields<'writer> + 'static,
723 {
724 Layer {
725 fmt_event: self.fmt_event,
726 fmt_fields: f(self.fmt_fields),
727 fmt_span: self.fmt_span,
728 make_writer: self.make_writer,
729 is_ansi: self.is_ansi,
730 log_internal_errors: self.log_internal_errors,
731 max_buf_capacity: self.max_buf_capacity,
732 _inner: self._inner,
733 }
734 }
735}
736
737impl<S> Default for Layer<S> {
738 fn default() -> Self {
739 let ansi = cfg!(feature = "ansi") && env::var("NO_COLOR").map_or(true, |v| v.is_empty());
742
743 Layer {
744 fmt_fields: format::DefaultFields::default(),
745 fmt_event: format::Format::default(),
746 fmt_span: format::FmtSpanConfig::default(),
747 make_writer: io::stdout,
748 is_ansi: ansi,
749 log_internal_errors: false,
750 max_buf_capacity: None,
751 _inner: PhantomData,
752 }
753 }
754}
755
756impl<S, N, E, W> Layer<S, N, E, W>
757where
758 S: Subscriber + for<'a> LookupSpan<'a>,
759 N: for<'writer> FormatFields<'writer> + 'static,
760 E: FormatEvent<S, N> + 'static,
761 W: for<'writer> MakeWriter<'writer> + 'static,
762{
763 #[inline]
764 fn make_ctx<'a>(&'a self, ctx: Context<'a, S>, event: &'a Event<'a>) -> FmtContext<'a, S, N> {
765 FmtContext {
766 ctx,
767 fmt_fields: &self.fmt_fields,
768 event,
769 }
770 }
771}
772
773#[derive(Default)]
783pub struct FormattedFields<E: ?Sized> {
784 _format_fields: PhantomData<fn(E)>,
785 was_ansi: bool,
786 pub fields: String,
788}
789
790impl<E: ?Sized> FormattedFields<E> {
791 pub fn new(fields: String) -> Self {
793 Self {
794 fields,
795 was_ansi: false,
796 _format_fields: PhantomData,
797 }
798 }
799
800 pub fn as_writer(&mut self) -> format::Writer<'_> {
805 format::Writer::new(&mut self.fields).with_ansi(self.was_ansi)
806 }
807}
808
809impl<E: ?Sized> fmt::Debug for FormattedFields<E> {
810 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
811 f.debug_struct("FormattedFields")
812 .field("fields", &self.fields)
813 .field("formatter", &format_args!("{}", std::any::type_name::<E>()))
814 .field("was_ansi", &self.was_ansi)
815 .finish()
816 }
817}
818
819impl<E: ?Sized> fmt::Display for FormattedFields<E> {
820 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
821 fmt::Display::fmt(&self.fields, f)
822 }
823}
824
825impl<E: ?Sized> Deref for FormattedFields<E> {
826 type Target = String;
827 fn deref(&self) -> &Self::Target {
828 &self.fields
829 }
830}
831
832macro_rules! with_event_from_span {
835 ($id:ident, $span:ident, $($field:literal = $value:expr),*, |$event:ident| $code:block) => {
836 let meta = $span.metadata();
837 let cs = meta.callsite();
838 let fs = field::FieldSet::new(&[$($field),*], cs);
839 #[allow(unused)]
840 let mut iter = fs.iter();
841 let v = [$(
842 (&iter.next().unwrap(), ::core::option::Option::Some(&$value as &dyn field::Value)),
843 )*];
844 let vs = fs.value_set(&v);
845 let $event = Event::new_child_of($id, meta, &vs);
846 $code
847 };
848}
849
850impl<S, N, E, W> layer::Layer<S> for Layer<S, N, E, W>
851where
852 S: Subscriber + for<'a> LookupSpan<'a>,
853 N: for<'writer> FormatFields<'writer> + 'static,
854 E: FormatEvent<S, N> + 'static,
855 W: for<'writer> MakeWriter<'writer> + 'static,
856{
857 fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
858 let span = ctx.span(id).expect("Span not found, this is a bug");
859 let mut extensions = span.extensions_mut();
860
861 if extensions.get_mut::<FormattedFields<N>>().is_none() {
862 let mut fields = FormattedFields::<N>::new(String::new());
863 if self
864 .fmt_fields
865 .format_fields(fields.as_writer().with_ansi(self.is_ansi), attrs)
866 .is_ok()
867 {
868 fields.was_ansi = self.is_ansi;
869 extensions.insert(fields);
870 } else {
871 eprintln!(
872 "[tracing-subscriber] Unable to format the following event, ignoring: {:?}",
873 attrs
874 );
875 }
876 }
877
878 if self.fmt_span.fmt_timing
879 && self.fmt_span.trace_close()
880 && extensions.get_mut::<Timings>().is_none()
881 {
882 extensions.insert(Timings::new());
883 }
884
885 if self.fmt_span.trace_new() {
886 with_event_from_span!(id, span, "message" = "new", |event| {
887 drop(extensions);
888 drop(span);
889 self.on_event(&event, ctx);
890 });
891 }
892 }
893
894 fn on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>) {
895 let span = ctx.span(id).expect("Span not found, this is a bug");
896 let mut extensions = span.extensions_mut();
897 if let Some(fields) = extensions.get_mut::<FormattedFields<N>>() {
898 let _ = self.fmt_fields.add_fields(fields, values);
899 return;
900 }
901
902 let mut fields = FormattedFields::<N>::new(String::new());
903 if self
904 .fmt_fields
905 .format_fields(fields.as_writer().with_ansi(self.is_ansi), values)
906 .is_ok()
907 {
908 fields.was_ansi = self.is_ansi;
909 extensions.insert(fields);
910 }
911 }
912
913 fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
914 if self.fmt_span.trace_enter() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
915 let span = ctx.span(id).expect("Span not found, this is a bug");
916 let mut extensions = span.extensions_mut();
917 if let Some(timings) = extensions.get_mut::<Timings>() {
918 if timings.entered_count == 0 {
919 let now = Instant::now();
920 timings.idle += (now - timings.last).as_nanos() as u64;
921 timings.last = now;
922 }
923 timings.entered_count += 1;
924 }
925
926 if self.fmt_span.trace_enter() {
927 with_event_from_span!(id, span, "message" = "enter", |event| {
928 drop(extensions);
929 drop(span);
930 self.on_event(&event, ctx);
931 });
932 }
933 }
934 }
935
936 fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
937 if self.fmt_span.trace_exit() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
938 let span = ctx.span(id).expect("Span not found, this is a bug");
939 let mut extensions = span.extensions_mut();
940 if let Some(timings) = extensions.get_mut::<Timings>() {
941 timings.entered_count -= 1;
942 if timings.entered_count == 0 {
943 let now = Instant::now();
944 timings.busy += (now - timings.last).as_nanos() as u64;
945 timings.last = now;
946 }
947 }
948
949 if self.fmt_span.trace_exit() {
950 with_event_from_span!(id, span, "message" = "exit", |event| {
951 drop(extensions);
952 drop(span);
953 self.on_event(&event, ctx);
954 });
955 }
956 }
957 }
958
959 fn on_close(&self, id: Id, ctx: Context<'_, S>) {
960 if self.fmt_span.trace_close() {
961 let span = ctx.span(&id).expect("Span not found, this is a bug");
962 let extensions = span.extensions();
963 if let Some(timing) = extensions.get::<Timings>() {
964 let Timings {
965 busy,
966 mut idle,
967 last,
968 entered_count,
969 } = *timing;
970 debug_assert_eq!(entered_count, 0);
971 idle += (Instant::now() - last).as_nanos() as u64;
972
973 let t_idle = field::display(TimingDisplay(idle));
974 let t_busy = field::display(TimingDisplay(busy));
975
976 with_event_from_span!(
977 id,
978 span,
979 "message" = "close",
980 "time.busy" = t_busy,
981 "time.idle" = t_idle,
982 |event| {
983 drop(extensions);
984 drop(span);
985 self.on_event(&event, ctx);
986 }
987 );
988 } else {
989 with_event_from_span!(id, span, "message" = "close", |event| {
990 drop(extensions);
991 drop(span);
992 self.on_event(&event, ctx);
993 });
994 }
995 }
996 }
997
998 fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
999 thread_local! {
1000 static BUF: RefCell<String> = const { RefCell::new(String::new()) };
1001 }
1002
1003 BUF.with(|buf| {
1004 let borrow = buf.try_borrow_mut();
1005 let mut a;
1006 let mut b;
1007 let mut buf = match borrow {
1008 Ok(buf) => {
1009 a = buf;
1010 &mut *a
1011 }
1012 _ => {
1013 b = String::new();
1014 &mut b
1015 }
1016 };
1017
1018 let ctx = self.make_ctx(ctx, event);
1019 if self
1020 .fmt_event
1021 .format_event(
1022 &ctx,
1023 format::Writer::new(&mut buf).with_ansi(self.is_ansi),
1024 event,
1025 )
1026 .is_ok()
1027 {
1028 let mut writer = self.make_writer.make_writer_for(event.metadata());
1029 let res = io::Write::write_all(&mut writer, buf.as_bytes());
1030 if self.log_internal_errors {
1031 if let Err(e) = res {
1032 eprintln!("[tracing-subscriber] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e);
1033 }
1034 }
1035 } else if self.log_internal_errors {
1036 let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n",
1037 event.metadata().name(), event.fields());
1038 let mut writer = self.make_writer.make_writer_for(event.metadata());
1039 let res = io::Write::write_all(&mut writer, err_msg.as_bytes());
1040 if let Err(e) = res {
1041 eprintln!("[tracing-subscriber] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e);
1042 }
1043 }
1044
1045 buf.clear();
1046 if let Some(max_cap) = self.max_buf_capacity {
1047 buf.shrink_to(max_cap);
1048 }
1049 });
1050 }
1051
1052 unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
1053 match () {
1058 _ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()),
1059 _ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()),
1060 _ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()),
1061 _ if id == TypeId::of::<W>() => Some(&self.make_writer as *const W as *const ()),
1062 _ => None,
1063 }
1064 }
1065}
1066
1067pub struct FmtContext<'a, S, N> {
1069 pub(crate) ctx: Context<'a, S>,
1070 pub(crate) fmt_fields: &'a N,
1071 pub(crate) event: &'a Event<'a>,
1072}
1073
1074impl<S, N> fmt::Debug for FmtContext<'_, S, N> {
1075 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1076 f.debug_struct("FmtContext").finish()
1077 }
1078}
1079
1080impl<'writer, S, N> FormatFields<'writer> for FmtContext<'_, S, N>
1081where
1082 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1083 N: FormatFields<'writer> + 'static,
1084{
1085 fn format_fields<R: RecordFields>(
1086 &self,
1087 writer: format::Writer<'writer>,
1088 fields: R,
1089 ) -> fmt::Result {
1090 self.fmt_fields.format_fields(writer, fields)
1091 }
1092}
1093
1094impl<S, N> FmtContext<'_, S, N>
1095where
1096 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1097 N: for<'writer> FormatFields<'writer> + 'static,
1098{
1099 pub fn visit_spans<E, F>(&self, mut f: F) -> Result<(), E>
1105 where
1106 F: FnMut(&SpanRef<'_, S>) -> Result<(), E>,
1107 {
1108 if let Some(scope) = self.event_scope() {
1110 for span in scope.from_root() {
1111 f(&span)?;
1112 }
1113 }
1114 Ok(())
1115 }
1116
1117 #[inline]
1122 pub fn metadata(&self, id: &Id) -> Option<&'static Metadata<'static>>
1123 where
1124 S: for<'lookup> LookupSpan<'lookup>,
1125 {
1126 self.ctx.metadata(id)
1127 }
1128
1129 #[inline]
1136 pub fn span(&self, id: &Id) -> Option<SpanRef<'_, S>>
1137 where
1138 S: for<'lookup> LookupSpan<'lookup>,
1139 {
1140 self.ctx.span(id)
1141 }
1142
1143 #[inline]
1145 pub fn exists(&self, id: &Id) -> bool
1146 where
1147 S: for<'lookup> LookupSpan<'lookup>,
1148 {
1149 self.ctx.exists(id)
1150 }
1151
1152 #[inline]
1159 pub fn lookup_current(&self) -> Option<SpanRef<'_, S>>
1160 where
1161 S: for<'lookup> LookupSpan<'lookup>,
1162 {
1163 self.ctx.lookup_current()
1164 }
1165
1166 pub fn current_span(&self) -> Current {
1168 self.ctx.current_span()
1169 }
1170
1171 pub fn parent_span(&self) -> Option<SpanRef<'_, S>> {
1180 self.ctx.event_span(self.event)
1181 }
1182
1183 pub fn span_scope(&self, id: &Id) -> Option<registry::Scope<'_, S>>
1210 where
1211 S: for<'lookup> LookupSpan<'lookup>,
1212 {
1213 self.ctx.span_scope(id)
1214 }
1215
1216 pub fn event_scope(&self) -> Option<registry::Scope<'_, S>>
1241 where
1242 S: for<'lookup> registry::LookupSpan<'lookup>,
1243 {
1244 self.ctx.event_scope(self.event)
1245 }
1246
1247 pub fn field_format(&self) -> &N {
1255 self.fmt_fields
1256 }
1257}
1258
1259struct Timings {
1260 idle: u64,
1261 busy: u64,
1262 last: Instant,
1263 entered_count: u64,
1264}
1265
1266impl Timings {
1267 fn new() -> Self {
1268 Self {
1269 idle: 0,
1270 busy: 0,
1271 last: Instant::now(),
1272 entered_count: 0,
1273 }
1274 }
1275}
1276
1277#[cfg(test)]
1278mod test {
1279 use super::*;
1280 use crate::fmt::{
1281 self,
1282 format::{self, test::MockTime, Format},
1283 layer::Layer as _,
1284 test::{MockMakeWriter, MockWriter},
1285 time,
1286 };
1287 use crate::Registry;
1288 use alloc::{string::ToString, vec, vec::Vec};
1289 use format::FmtSpan;
1290 use regex::Regex;
1291 use tracing::subscriber::with_default;
1292 use tracing_core::dispatcher::Dispatch;
1293
1294 #[test]
1295 fn impls() {
1296 let f = Format::default().with_timer(time::Uptime::default());
1297 let fmt = fmt::Layer::default().event_format(f);
1298 let subscriber = fmt.with_subscriber(Registry::default());
1299 let _dispatch = Dispatch::new(subscriber);
1300
1301 let f = format::Format::default();
1302 let fmt = fmt::Layer::default().event_format(f);
1303 let subscriber = fmt.with_subscriber(Registry::default());
1304 let _dispatch = Dispatch::new(subscriber);
1305
1306 let f = format::Format::default().compact();
1307 let fmt = fmt::Layer::default().event_format(f);
1308 let subscriber = fmt.with_subscriber(Registry::default());
1309 let _dispatch = Dispatch::new(subscriber);
1310 }
1311
1312 #[test]
1313 fn fmt_layer_downcasts() {
1314 let f = format::Format::default();
1315 let fmt = fmt::Layer::default().event_format(f);
1316 let subscriber = fmt.with_subscriber(Registry::default());
1317
1318 let dispatch = Dispatch::new(subscriber);
1319 assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some());
1320 }
1321
1322 #[test]
1323 fn fmt_layer_downcasts_to_parts() {
1324 let f = format::Format::default();
1325 let fmt = fmt::Layer::default().event_format(f);
1326 let subscriber = fmt.with_subscriber(Registry::default());
1327 let dispatch = Dispatch::new(subscriber);
1328 assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
1329 assert!(dispatch.downcast_ref::<format::Format>().is_some())
1330 }
1331
1332 #[test]
1333 fn is_lookup_span() {
1334 fn assert_lookup_span<T: for<'a> crate::registry::LookupSpan<'a>>(_: T) {}
1335 let fmt = fmt::Layer::default();
1336 let subscriber = fmt.with_subscriber(Registry::default());
1337 assert_lookup_span(subscriber)
1338 }
1339
1340 fn sanitize_timings(s: String) -> String {
1341 let re = Regex::new("time\\.(idle|busy)=([0-9.]+)[mµn]s").unwrap();
1342 re.replace_all(s.as_str(), "timing").to_string()
1343 }
1344
1345 #[test]
1346 fn format_error_print_to_stderr() {
1347 struct AlwaysError;
1348
1349 impl std::fmt::Debug for AlwaysError {
1350 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1351 Err(std::fmt::Error)
1352 }
1353 }
1354
1355 let make_writer = MockMakeWriter::default();
1356 let subscriber = crate::fmt::Subscriber::builder()
1357 .with_writer(make_writer.clone())
1358 .with_level(false)
1359 .with_ansi(false)
1360 .with_timer(MockTime)
1361 .finish();
1362
1363 with_default(subscriber, || {
1364 tracing::info!(?AlwaysError);
1365 });
1366 let actual = sanitize_timings(make_writer.get_string());
1367
1368 let expected = concat!(
1370 "Unable to format the following event. Name: event ",
1371 file!(),
1372 ":"
1373 );
1374 assert!(
1375 actual.as_str().starts_with(expected),
1376 "\nactual = {}\nshould start with expected = {}\n",
1377 actual,
1378 expected
1379 );
1380 }
1381
1382 #[test]
1383 fn format_error_ignore_if_log_internal_errors_is_false() {
1384 struct AlwaysError;
1385
1386 impl std::fmt::Debug for AlwaysError {
1387 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1388 Err(std::fmt::Error)
1389 }
1390 }
1391
1392 let make_writer = MockMakeWriter::default();
1393 let subscriber = crate::fmt::Subscriber::builder()
1394 .with_writer(make_writer.clone())
1395 .with_level(false)
1396 .with_ansi(false)
1397 .with_timer(MockTime)
1398 .log_internal_errors(false)
1399 .finish();
1400
1401 with_default(subscriber, || {
1402 tracing::info!(?AlwaysError);
1403 });
1404 let actual = sanitize_timings(make_writer.get_string());
1405 assert_eq!("", actual.as_str());
1406 }
1407
1408 #[test]
1409 fn synthesize_span_none() {
1410 let make_writer = MockMakeWriter::default();
1411 let subscriber = crate::fmt::Subscriber::builder()
1412 .with_writer(make_writer.clone())
1413 .with_level(false)
1414 .with_ansi(false)
1415 .with_timer(MockTime)
1416 .finish();
1418
1419 with_default(subscriber, || {
1420 let span1 = tracing::info_span!("span1", x = 42);
1421 let _e = span1.enter();
1422 });
1423 let actual = sanitize_timings(make_writer.get_string());
1424 assert_eq!("", actual.as_str());
1425 }
1426
1427 #[test]
1428 fn synthesize_span_active() {
1429 let make_writer = MockMakeWriter::default();
1430 let subscriber = crate::fmt::Subscriber::builder()
1431 .with_writer(make_writer.clone())
1432 .with_level(false)
1433 .with_ansi(false)
1434 .with_timer(MockTime)
1435 .with_span_events(FmtSpan::ACTIVE)
1436 .finish();
1437
1438 with_default(subscriber, || {
1439 let span1 = tracing::info_span!("span1", x = 42);
1440 let _e = span1.enter();
1441 });
1442 let actual = sanitize_timings(make_writer.get_string());
1443 assert_eq!(
1444 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1445 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n",
1446 actual.as_str()
1447 );
1448 }
1449
1450 #[test]
1451 fn synthesize_span_close() {
1452 let make_writer = MockMakeWriter::default();
1453 let subscriber = crate::fmt::Subscriber::builder()
1454 .with_writer(make_writer.clone())
1455 .with_level(false)
1456 .with_ansi(false)
1457 .with_timer(MockTime)
1458 .with_span_events(FmtSpan::CLOSE)
1459 .finish();
1460
1461 with_default(subscriber, || {
1462 let span1 = tracing::info_span!("span1", x = 42);
1463 let _e = span1.enter();
1464 });
1465 let actual = sanitize_timings(make_writer.get_string());
1466 assert_eq!(
1467 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1468 actual.as_str()
1469 );
1470 }
1471
1472 #[test]
1473 fn synthesize_span_close_no_timing() {
1474 let make_writer = MockMakeWriter::default();
1475 let subscriber = crate::fmt::Subscriber::builder()
1476 .with_writer(make_writer.clone())
1477 .with_level(false)
1478 .with_ansi(false)
1479 .with_timer(MockTime)
1480 .without_time()
1481 .with_span_events(FmtSpan::CLOSE)
1482 .finish();
1483
1484 with_default(subscriber, || {
1485 let span1 = tracing::info_span!("span1", x = 42);
1486 let _e = span1.enter();
1487 });
1488 let actual = sanitize_timings(make_writer.get_string());
1489 assert_eq!(
1490 "span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close\n",
1491 actual.as_str()
1492 );
1493 }
1494
1495 #[test]
1496 fn synthesize_span_full() {
1497 let make_writer = MockMakeWriter::default();
1498 let subscriber = crate::fmt::Subscriber::builder()
1499 .with_writer(make_writer.clone())
1500 .with_level(false)
1501 .with_ansi(false)
1502 .with_timer(MockTime)
1503 .with_span_events(FmtSpan::FULL)
1504 .finish();
1505
1506 with_default(subscriber, || {
1507 let span1 = tracing::info_span!("span1", x = 42);
1508 let _e = span1.enter();
1509 });
1510 let actual = sanitize_timings(make_writer.get_string());
1511 assert_eq!(
1512 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: new\n\
1513 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1514 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\
1515 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1516 actual.as_str()
1517 );
1518 }
1519
1520 #[test]
1521 fn make_writer_based_on_meta() {
1522 struct MakeByTarget {
1523 make_writer1: MockMakeWriter,
1524 make_writer2: MockMakeWriter,
1525 }
1526
1527 impl<'a> MakeWriter<'a> for MakeByTarget {
1528 type Writer = MockWriter;
1529
1530 fn make_writer(&'a self) -> Self::Writer {
1531 self.make_writer1.make_writer()
1532 }
1533
1534 fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer {
1535 if meta.target() == "writer2" {
1536 return self.make_writer2.make_writer();
1537 }
1538 self.make_writer()
1539 }
1540 }
1541
1542 let make_writer1 = MockMakeWriter::default();
1543 let make_writer2 = MockMakeWriter::default();
1544
1545 let make_writer = MakeByTarget {
1546 make_writer1: make_writer1.clone(),
1547 make_writer2: make_writer2.clone(),
1548 };
1549
1550 let subscriber = crate::fmt::Subscriber::builder()
1551 .with_writer(make_writer)
1552 .with_level(false)
1553 .with_target(false)
1554 .with_ansi(false)
1555 .with_timer(MockTime)
1556 .with_span_events(FmtSpan::CLOSE)
1557 .finish();
1558
1559 with_default(subscriber, || {
1560 let span1 = tracing::info_span!("writer1_span", x = 42);
1561 let _e = span1.enter();
1562 tracing::info!(target: "writer2", "hello writer2!");
1563 let span2 = tracing::info_span!(target: "writer2", "writer2_span");
1564 let _e = span2.enter();
1565 tracing::warn!(target: "writer1", "hello writer1!");
1566 });
1567
1568 let actual = sanitize_timings(make_writer1.get_string());
1569 assert_eq!(
1570 "fake time writer1_span{x=42}:writer2_span: hello writer1!\n\
1571 fake time writer1_span{x=42}: close timing timing\n",
1572 actual.as_str()
1573 );
1574 let actual = sanitize_timings(make_writer2.get_string());
1575 assert_eq!(
1576 "fake time writer1_span{x=42}: hello writer2!\n\
1577 fake time writer1_span{x=42}:writer2_span: close timing timing\n",
1578 actual.as_str()
1579 );
1580 }
1581
1582 #[cfg(feature = "ansi")]
1585 #[test]
1586 fn layer_no_color() {
1587 const NO_COLOR: &str = "NO_COLOR";
1588
1589 struct RestoreEnvVar(Result<String, env::VarError>);
1596 impl Drop for RestoreEnvVar {
1597 fn drop(&mut self) {
1598 match self.0 {
1599 Ok(ref var) => env::set_var(NO_COLOR, var),
1600 Err(_) => env::remove_var(NO_COLOR),
1601 }
1602 }
1603 }
1604
1605 let _saved_no_color = RestoreEnvVar(env::var(NO_COLOR));
1606
1607 let cases: Vec<(Option<&str>, bool)> = vec![
1608 (Some("0"), false), (Some("off"), false), (Some("1"), false),
1611 (Some(""), true), (None, true),
1613 ];
1614
1615 for (var, ansi) in cases {
1616 if let Some(value) = var {
1617 env::set_var(NO_COLOR, value);
1618 } else {
1619 env::remove_var(NO_COLOR);
1620 }
1621
1622 let layer: Layer<()> = fmt::Layer::default();
1623 assert_eq!(
1624 layer.is_ansi, ansi,
1625 "NO_COLOR={:?}; Layer::default().is_ansi should be {}",
1626 var, ansi
1627 );
1628
1629 let layer: Layer<()> = fmt::Layer::default().with_ansi(true);
1631 assert!(
1632 layer.is_ansi,
1633 "NO_COLOR={:?}; Layer::default().with_ansi(true).is_ansi should be true",
1634 var
1635 );
1636
1637 let mut layer: Layer<()> = fmt::Layer::default();
1639 layer.set_ansi(true);
1640 assert!(
1641 layer.is_ansi,
1642 "NO_COLOR={:?}; layer.set_ansi(true); layer.is_ansi should be true",
1643 var
1644 );
1645 }
1646
1647 }
1650
1651 #[test]
1653 fn modify_span_events() {
1654 let make_writer = MockMakeWriter::default();
1655
1656 let inner_layer = fmt::Layer::default()
1657 .with_writer(make_writer.clone())
1658 .with_level(false)
1659 .with_ansi(false)
1660 .with_timer(MockTime)
1661 .with_span_events(FmtSpan::ACTIVE);
1662
1663 let (reloadable_layer, reload_handle) = crate::reload::Layer::new(inner_layer);
1664 let reload = reloadable_layer.with_subscriber(Registry::default());
1665
1666 with_default(reload, || {
1667 {
1668 let span1 = tracing::info_span!("span1", x = 42);
1669 let _e = span1.enter();
1670 }
1671
1672 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::NONE));
1673
1674 {
1676 let span2 = tracing::info_span!("span2", x = 100);
1677 let _e = span2.enter();
1678 }
1679
1680 {
1681 let span3 = tracing::info_span!("span3", x = 42);
1682 let _e = span3.enter();
1683
1684 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::ACTIVE));
1687 }
1688 });
1689 let actual = sanitize_timings(make_writer.get_string());
1690 assert_eq!(
1691 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1692 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\
1693 fake time span3{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n",
1694 actual.as_str()
1695 );
1696 }
1697
1698 #[test]
1699 fn buf_capacity_limit_does_not_break_formatting() {
1700 let make_writer = MockMakeWriter::default();
1703 let subscriber = crate::fmt::Subscriber::builder()
1704 .with_writer(make_writer.clone())
1705 .with_level(false)
1706 .with_ansi(false)
1707 .with_timer(MockTime)
1708 .with_buf_capacity_limit(256)
1709 .finish();
1710
1711 with_default(subscriber, || {
1712 let big = "x".repeat(1024);
1714 tracing::info!(big_field = big.as_str(), "large event");
1715
1716 tracing::info!("small event");
1719 });
1720
1721 let actual = make_writer.get_string();
1722 assert!(
1723 actual.contains("large event"),
1724 "large event should have been written, got: {}",
1725 actual
1726 );
1727 assert!(
1728 actual.contains("small event"),
1729 "small event should have been written after buf shrink, got: {}",
1730 actual
1731 );
1732 }
1733}