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 ansi_sanitization: bool,
76 log_internal_errors: bool,
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 ansi_sanitization: self.ansi_sanitization,
127 log_internal_errors: self.log_internal_errors,
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 ansi_sanitization: self.ansi_sanitization,
158 log_internal_errors: self.log_internal_errors,
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 ansi_sanitization: self.ansi_sanitization,
192 log_internal_errors: self.log_internal_errors,
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 ansi_sanitization: self.ansi_sanitization,
298 log_internal_errors: self.log_internal_errors,
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 with_ansi_sanitization(self, ansi_sanitization: bool) -> Self {
355 Self {
356 ansi_sanitization,
357 ..self
358 }
359 }
360
361 pub fn log_internal_errors(self, log_internal_errors: bool) -> Self {
373 Self {
374 log_internal_errors,
375 ..self
376 }
377 }
378
379 pub fn map_writer<W2>(self, f: impl FnOnce(W) -> W2) -> Layer<S, N, E, W2>
399 where
400 W2: for<'writer> MakeWriter<'writer> + 'static,
401 {
402 Layer {
403 fmt_fields: self.fmt_fields,
404 fmt_event: self.fmt_event,
405 fmt_span: self.fmt_span,
406 is_ansi: self.is_ansi,
407 ansi_sanitization: self.ansi_sanitization,
408 log_internal_errors: self.log_internal_errors,
409 make_writer: f(self.make_writer),
410 _inner: self._inner,
411 }
412 }
413}
414
415impl<S, N, L, T, W> Layer<S, N, format::Format<L, T>, W>
416where
417 N: for<'writer> FormatFields<'writer> + 'static,
418{
419 pub fn with_timer<T2>(self, timer: T2) -> Layer<S, N, format::Format<L, T2>, W> {
434 Layer {
435 fmt_event: self.fmt_event.with_timer(timer),
436 fmt_fields: self.fmt_fields,
437 fmt_span: self.fmt_span,
438 make_writer: self.make_writer,
439 is_ansi: self.is_ansi,
440 ansi_sanitization: self.ansi_sanitization,
441 log_internal_errors: self.log_internal_errors,
442 _inner: self._inner,
443 }
444 }
445
446 pub fn without_time(self) -> Layer<S, N, format::Format<L, ()>, W> {
448 Layer {
449 fmt_event: self.fmt_event.without_time(),
450 fmt_fields: self.fmt_fields,
451 fmt_span: self.fmt_span.without_time(),
452 make_writer: self.make_writer,
453 is_ansi: self.is_ansi,
454 ansi_sanitization: self.ansi_sanitization,
455 log_internal_errors: self.log_internal_errors,
456 _inner: self._inner,
457 }
458 }
459
460 pub fn with_span_events(self, kind: FmtSpan) -> Self {
502 Layer {
503 fmt_span: self.fmt_span.with_kind(kind),
504 ..self
505 }
506 }
507
508 pub fn with_target(self, display_target: bool) -> Layer<S, N, format::Format<L, T>, W> {
510 Layer {
511 fmt_event: self.fmt_event.with_target(display_target),
512 ..self
513 }
514 }
515 pub fn with_file(self, display_filename: bool) -> Layer<S, N, format::Format<L, T>, W> {
520 Layer {
521 fmt_event: self.fmt_event.with_file(display_filename),
522 ..self
523 }
524 }
525
526 pub fn with_line_number(
531 self,
532 display_line_number: bool,
533 ) -> Layer<S, N, format::Format<L, T>, W> {
534 Layer {
535 fmt_event: self.fmt_event.with_line_number(display_line_number),
536 ..self
537 }
538 }
539
540 pub fn with_level(self, display_level: bool) -> Layer<S, N, format::Format<L, T>, W> {
542 Layer {
543 fmt_event: self.fmt_event.with_level(display_level),
544 ..self
545 }
546 }
547
548 pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W> {
553 Layer {
554 fmt_event: self.fmt_event.with_thread_ids(display_thread_ids),
555 ..self
556 }
557 }
558
559 pub fn with_thread_names(
564 self,
565 display_thread_names: bool,
566 ) -> Layer<S, N, format::Format<L, T>, W> {
567 Layer {
568 fmt_event: self.fmt_event.with_thread_names(display_thread_names),
569 ..self
570 }
571 }
572
573 pub fn compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W>
575 where
576 N: for<'writer> FormatFields<'writer> + 'static,
577 {
578 Layer {
579 fmt_event: self.fmt_event.compact(),
580 fmt_fields: self.fmt_fields,
581 fmt_span: self.fmt_span,
582 make_writer: self.make_writer,
583 is_ansi: self.is_ansi,
584 ansi_sanitization: self.ansi_sanitization,
585 log_internal_errors: self.log_internal_errors,
586 _inner: self._inner,
587 }
588 }
589
590 #[cfg(feature = "ansi")]
592 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
593 pub fn pretty(self) -> Layer<S, format::Pretty, format::Format<format::Pretty, T>, W> {
594 Layer {
595 fmt_event: self.fmt_event.pretty(),
596 fmt_fields: format::Pretty::default(),
597 fmt_span: self.fmt_span,
598 make_writer: self.make_writer,
599 is_ansi: self.is_ansi,
600 ansi_sanitization: self.ansi_sanitization,
601 log_internal_errors: self.log_internal_errors,
602 _inner: self._inner,
603 }
604 }
605
606 #[cfg(feature = "json")]
623 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
624 pub fn json(self) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
625 Layer {
626 fmt_event: self.fmt_event.json(),
627 fmt_fields: format::JsonFields::new(),
628 fmt_span: self.fmt_span,
629 make_writer: self.make_writer,
630 is_ansi: false,
632 ansi_sanitization: self.ansi_sanitization,
633 log_internal_errors: self.log_internal_errors,
634 _inner: self._inner,
635 }
636 }
637}
638
639#[cfg(feature = "json")]
640#[cfg_attr(docsrs, doc(cfg(feature = "json")))]
641impl<S, T, W> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
642 pub fn flatten_event(
646 self,
647 flatten_event: bool,
648 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
649 Layer {
650 fmt_event: self.fmt_event.flatten_event(flatten_event),
651 fmt_fields: format::JsonFields::new(),
652 ..self
653 }
654 }
655
656 pub fn with_current_span(
661 self,
662 display_current_span: bool,
663 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
664 Layer {
665 fmt_event: self.fmt_event.with_current_span(display_current_span),
666 fmt_fields: format::JsonFields::new(),
667 ..self
668 }
669 }
670
671 pub fn with_span_list(
676 self,
677 display_span_list: bool,
678 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
679 Layer {
680 fmt_event: self.fmt_event.with_span_list(display_span_list),
681 fmt_fields: format::JsonFields::new(),
682 ..self
683 }
684 }
685}
686
687impl<S, N, E, W> Layer<S, N, E, W> {
688 pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Layer<S, N2, E, W>
691 where
692 N2: for<'writer> FormatFields<'writer> + 'static,
693 {
694 Layer {
695 fmt_event: self.fmt_event,
696 fmt_fields,
697 fmt_span: self.fmt_span,
698 make_writer: self.make_writer,
699 is_ansi: self.is_ansi,
700 ansi_sanitization: self.ansi_sanitization,
701 log_internal_errors: self.log_internal_errors,
702 _inner: self._inner,
703 }
704 }
705
706 pub fn map_fmt_fields<N2>(self, f: impl FnOnce(N) -> N2) -> Layer<S, N2, E, W>
723 where
724 N2: for<'writer> FormatFields<'writer> + 'static,
725 {
726 Layer {
727 fmt_event: self.fmt_event,
728 fmt_fields: f(self.fmt_fields),
729 fmt_span: self.fmt_span,
730 make_writer: self.make_writer,
731 is_ansi: self.is_ansi,
732 ansi_sanitization: self.ansi_sanitization,
733 log_internal_errors: self.log_internal_errors,
734 _inner: self._inner,
735 }
736 }
737}
738
739impl<S> Default for Layer<S> {
740 fn default() -> Self {
741 let ansi = cfg!(feature = "ansi") && env::var("NO_COLOR").map_or(true, |v| v.is_empty());
744
745 Layer {
746 fmt_fields: format::DefaultFields::default(),
747 fmt_event: format::Format::default(),
748 fmt_span: format::FmtSpanConfig::default(),
749 make_writer: io::stdout,
750 is_ansi: ansi,
751 ansi_sanitization: true,
752 log_internal_errors: false,
753 _inner: PhantomData,
754 }
755 }
756}
757
758impl<S, N, E, W> Layer<S, N, E, W>
759where
760 S: Subscriber + for<'a> LookupSpan<'a>,
761 N: for<'writer> FormatFields<'writer> + 'static,
762 E: FormatEvent<S, N> + 'static,
763 W: for<'writer> MakeWriter<'writer> + 'static,
764{
765 #[inline]
766 fn make_ctx<'a>(&'a self, ctx: Context<'a, S>, event: &'a Event<'a>) -> FmtContext<'a, S, N> {
767 FmtContext {
768 ctx,
769 fmt_fields: &self.fmt_fields,
770 event,
771 }
772 }
773}
774
775pub struct FormattedFields<E: ?Sized> {
785 _format_fields: PhantomData<fn(E)>,
786 was_ansi: bool,
787 was_ansi_sanitized: bool,
788 pub fields: String,
790}
791
792impl<E: ?Sized> Default for FormattedFields<E> {
793 fn default() -> Self {
794 Self {
795 _format_fields: Default::default(),
796 was_ansi: Default::default(),
797 was_ansi_sanitized: true,
798 fields: Default::default(),
799 }
800 }
801}
802
803impl<E: ?Sized> FormattedFields<E> {
804 pub fn new(fields: String) -> Self {
806 Self {
807 fields,
808 was_ansi: false,
809 was_ansi_sanitized: true,
810 _format_fields: PhantomData,
811 }
812 }
813
814 pub fn as_writer(&mut self) -> format::Writer<'_> {
819 format::Writer::new(&mut self.fields)
820 .with_ansi(self.was_ansi)
821 .with_ansi_sanitization(self.was_ansi_sanitized)
822 }
823}
824
825impl<E: ?Sized> fmt::Debug for FormattedFields<E> {
826 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
827 f.debug_struct("FormattedFields")
828 .field("fields", &self.fields)
829 .field("formatter", &format_args!("{}", std::any::type_name::<E>()))
830 .field("was_ansi", &self.was_ansi)
831 .field("was_ansi_sanitized", &self.was_ansi_sanitized)
832 .finish()
833 }
834}
835
836impl<E: ?Sized> fmt::Display for FormattedFields<E> {
837 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
838 fmt::Display::fmt(&self.fields, f)
839 }
840}
841
842impl<E: ?Sized> Deref for FormattedFields<E> {
843 type Target = String;
844 fn deref(&self) -> &Self::Target {
845 &self.fields
846 }
847}
848
849macro_rules! with_event_from_span {
852 ($id:ident, $span:ident, $($field:literal = $value:expr),*, |$event:ident| $code:block) => {
853 let meta = $span.metadata();
854 let cs = meta.callsite();
855 let fs = field::FieldSet::new(&[$($field),*], cs);
856 #[allow(unused)]
857 let mut iter = fs.iter();
858 let v = [$(
859 (&iter.next().unwrap(), ::core::option::Option::Some(&$value as &dyn field::Value)),
860 )*];
861 let vs = fs.value_set(&v);
862 let $event = Event::new_child_of($id, meta, &vs);
863 $code
864 };
865}
866
867impl<S, N, E, W> layer::Layer<S> for Layer<S, N, E, W>
868where
869 S: Subscriber + for<'a> LookupSpan<'a>,
870 N: for<'writer> FormatFields<'writer> + 'static,
871 E: FormatEvent<S, N> + 'static,
872 W: for<'writer> MakeWriter<'writer> + 'static,
873{
874 fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
875 let span = ctx.span(id).expect("Span not found, this is a bug");
876 let mut extensions = span.extensions_mut();
877
878 if extensions.get_mut::<FormattedFields<N>>().is_none() {
879 let mut fields = FormattedFields::<N>::new(String::new());
880 fields.was_ansi = self.is_ansi;
881 fields.was_ansi_sanitized = self.ansi_sanitization;
882 if self
883 .fmt_fields
884 .format_fields(fields.as_writer(), attrs)
885 .is_ok()
886 {
887 extensions.insert(fields);
888 } else {
889 eprintln!(
890 "[tracing-subscriber] Unable to format the following event, ignoring: {:?}",
891 attrs
892 );
893 }
894 }
895
896 if self.fmt_span.fmt_timing
897 && self.fmt_span.trace_close()
898 && extensions.get_mut::<Timings>().is_none()
899 {
900 extensions.insert(Timings::new());
901 }
902
903 if self.fmt_span.trace_new() {
904 with_event_from_span!(id, span, "message" = "new", |event| {
905 drop(extensions);
906 drop(span);
907 self.on_event(&event, ctx);
908 });
909 }
910 }
911
912 fn on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>) {
913 let span = ctx.span(id).expect("Span not found, this is a bug");
914 let mut extensions = span.extensions_mut();
915 if let Some(fields) = extensions.get_mut::<FormattedFields<N>>() {
916 let _ = self.fmt_fields.add_fields(fields, values);
917 return;
918 }
919
920 let mut fields = FormattedFields::<N>::new(String::new());
921 fields.was_ansi = self.is_ansi;
922 fields.was_ansi_sanitized = self.ansi_sanitization;
923 if self
924 .fmt_fields
925 .format_fields(fields.as_writer(), values)
926 .is_ok()
927 {
928 extensions.insert(fields);
929 }
930 }
931
932 fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
933 if self.fmt_span.trace_enter() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
934 let span = ctx.span(id).expect("Span not found, this is a bug");
935 let mut extensions = span.extensions_mut();
936 if let Some(timings) = extensions.get_mut::<Timings>() {
937 if timings.entered_count == 0 {
938 let now = Instant::now();
939 timings.idle += (now - timings.last).as_nanos() as u64;
940 timings.last = now;
941 }
942 timings.entered_count += 1;
943 }
944
945 if self.fmt_span.trace_enter() {
946 with_event_from_span!(id, span, "message" = "enter", |event| {
947 drop(extensions);
948 drop(span);
949 self.on_event(&event, ctx);
950 });
951 }
952 }
953 }
954
955 fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
956 if self.fmt_span.trace_exit() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
957 let span = ctx.span(id).expect("Span not found, this is a bug");
958 let mut extensions = span.extensions_mut();
959 if let Some(timings) = extensions.get_mut::<Timings>() {
960 timings.entered_count -= 1;
961 if timings.entered_count == 0 {
962 let now = Instant::now();
963 timings.busy += (now - timings.last).as_nanos() as u64;
964 timings.last = now;
965 }
966 }
967
968 if self.fmt_span.trace_exit() {
969 with_event_from_span!(id, span, "message" = "exit", |event| {
970 drop(extensions);
971 drop(span);
972 self.on_event(&event, ctx);
973 });
974 }
975 }
976 }
977
978 fn on_close(&self, id: Id, ctx: Context<'_, S>) {
979 if self.fmt_span.trace_close() {
980 let span = ctx.span(&id).expect("Span not found, this is a bug");
981 let extensions = span.extensions();
982 if let Some(timing) = extensions.get::<Timings>() {
983 let Timings {
984 busy,
985 mut idle,
986 last,
987 entered_count,
988 } = *timing;
989 debug_assert_eq!(entered_count, 0);
990 idle += (Instant::now() - last).as_nanos() as u64;
991
992 let t_idle = field::display(TimingDisplay(idle));
993 let t_busy = field::display(TimingDisplay(busy));
994
995 with_event_from_span!(
996 id,
997 span,
998 "message" = "close",
999 "time.busy" = t_busy,
1000 "time.idle" = t_idle,
1001 |event| {
1002 drop(extensions);
1003 drop(span);
1004 self.on_event(&event, ctx);
1005 }
1006 );
1007 } else {
1008 with_event_from_span!(id, span, "message" = "close", |event| {
1009 drop(extensions);
1010 drop(span);
1011 self.on_event(&event, ctx);
1012 });
1013 }
1014 }
1015 }
1016
1017 fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
1018 thread_local! {
1019 static BUF: RefCell<String> = const { RefCell::new(String::new()) };
1020 }
1021
1022 BUF.with(|buf| {
1023 let borrow = buf.try_borrow_mut();
1024 let mut a;
1025 let mut b;
1026 let mut buf = match borrow {
1027 Ok(buf) => {
1028 a = buf;
1029 &mut *a
1030 }
1031 _ => {
1032 b = String::new();
1033 &mut b
1034 }
1035 };
1036
1037 let ctx = self.make_ctx(ctx, event);
1038 if self
1039 .fmt_event
1040 .format_event(
1041 &ctx,
1042 format::Writer::new(&mut buf)
1043 .with_ansi(self.is_ansi)
1044 .with_ansi_sanitization(self.ansi_sanitization),
1045 event,
1046 )
1047 .is_ok()
1048 {
1049 let mut writer = self.make_writer.make_writer_for(event.metadata());
1050 let res = io::Write::write_all(&mut writer, buf.as_bytes());
1051 if self.log_internal_errors {
1052 if let Err(e) = res {
1053 eprintln!("[tracing-subscriber] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e);
1054 }
1055 }
1056 } else if self.log_internal_errors {
1057 let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n",
1058 event.metadata().name(), event.fields());
1059 let mut writer = self.make_writer.make_writer_for(event.metadata());
1060 let res = io::Write::write_all(&mut writer, err_msg.as_bytes());
1061 if let Err(e) = res {
1062 eprintln!("[tracing-subscriber] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e);
1063 }
1064 }
1065
1066 buf.clear();
1067 });
1068 }
1069
1070 unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
1071 match () {
1076 _ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()),
1077 _ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()),
1078 _ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()),
1079 _ if id == TypeId::of::<W>() => Some(&self.make_writer as *const W as *const ()),
1080 _ => None,
1081 }
1082 }
1083}
1084
1085pub struct FmtContext<'a, S, N> {
1087 pub(crate) ctx: Context<'a, S>,
1088 pub(crate) fmt_fields: &'a N,
1089 pub(crate) event: &'a Event<'a>,
1090}
1091
1092impl<S, N> fmt::Debug for FmtContext<'_, S, N> {
1093 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1094 f.debug_struct("FmtContext").finish()
1095 }
1096}
1097
1098impl<'writer, S, N> FormatFields<'writer> for FmtContext<'_, S, N>
1099where
1100 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1101 N: FormatFields<'writer> + 'static,
1102{
1103 fn format_fields<R: RecordFields>(
1104 &self,
1105 writer: format::Writer<'writer>,
1106 fields: R,
1107 ) -> fmt::Result {
1108 self.fmt_fields.format_fields(writer, fields)
1109 }
1110}
1111
1112impl<S, N> FmtContext<'_, S, N>
1113where
1114 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1115 N: for<'writer> FormatFields<'writer> + 'static,
1116{
1117 pub fn visit_spans<E, F>(&self, mut f: F) -> Result<(), E>
1123 where
1124 F: FnMut(&SpanRef<'_, S>) -> Result<(), E>,
1125 {
1126 if let Some(scope) = self.event_scope() {
1128 for span in scope.from_root() {
1129 f(&span)?;
1130 }
1131 }
1132 Ok(())
1133 }
1134
1135 #[inline]
1140 pub fn metadata(&self, id: &Id) -> Option<&'static Metadata<'static>>
1141 where
1142 S: for<'lookup> LookupSpan<'lookup>,
1143 {
1144 self.ctx.metadata(id)
1145 }
1146
1147 #[inline]
1154 pub fn span(&self, id: &Id) -> Option<SpanRef<'_, S>>
1155 where
1156 S: for<'lookup> LookupSpan<'lookup>,
1157 {
1158 self.ctx.span(id)
1159 }
1160
1161 #[inline]
1163 pub fn exists(&self, id: &Id) -> bool
1164 where
1165 S: for<'lookup> LookupSpan<'lookup>,
1166 {
1167 self.ctx.exists(id)
1168 }
1169
1170 #[inline]
1177 pub fn lookup_current(&self) -> Option<SpanRef<'_, S>>
1178 where
1179 S: for<'lookup> LookupSpan<'lookup>,
1180 {
1181 self.ctx.lookup_current()
1182 }
1183
1184 pub fn current_span(&self) -> Current {
1186 self.ctx.current_span()
1187 }
1188
1189 pub fn parent_span(&self) -> Option<SpanRef<'_, S>> {
1198 self.ctx.event_span(self.event)
1199 }
1200
1201 pub fn span_scope(&self, id: &Id) -> Option<registry::Scope<'_, S>>
1228 where
1229 S: for<'lookup> LookupSpan<'lookup>,
1230 {
1231 self.ctx.span_scope(id)
1232 }
1233
1234 pub fn event_scope(&self) -> Option<registry::Scope<'_, S>>
1259 where
1260 S: for<'lookup> registry::LookupSpan<'lookup>,
1261 {
1262 self.ctx.event_scope(self.event)
1263 }
1264
1265 pub fn field_format(&self) -> &N {
1273 self.fmt_fields
1274 }
1275}
1276
1277struct Timings {
1278 idle: u64,
1279 busy: u64,
1280 last: Instant,
1281 entered_count: u64,
1282}
1283
1284impl Timings {
1285 fn new() -> Self {
1286 Self {
1287 idle: 0,
1288 busy: 0,
1289 last: Instant::now(),
1290 entered_count: 0,
1291 }
1292 }
1293}
1294
1295#[cfg(test)]
1296mod test {
1297 use super::*;
1298 use crate::fmt::{
1299 self,
1300 format::{self, test::MockTime, Format},
1301 layer::Layer as _,
1302 test::{MockMakeWriter, MockWriter},
1303 time,
1304 };
1305 use crate::Registry;
1306 use alloc::{string::ToString, vec, vec::Vec};
1307 use format::FmtSpan;
1308 use regex::Regex;
1309 use tracing::subscriber::with_default;
1310 use tracing_core::dispatcher::Dispatch;
1311
1312 #[test]
1313 fn impls() {
1314 let f = Format::default().with_timer(time::Uptime::default());
1315 let fmt = fmt::Layer::default().event_format(f);
1316 let subscriber = fmt.with_subscriber(Registry::default());
1317 let _dispatch = Dispatch::new(subscriber);
1318
1319 let f = format::Format::default();
1320 let fmt = fmt::Layer::default().event_format(f);
1321 let subscriber = fmt.with_subscriber(Registry::default());
1322 let _dispatch = Dispatch::new(subscriber);
1323
1324 let f = format::Format::default().compact();
1325 let fmt = fmt::Layer::default().event_format(f);
1326 let subscriber = fmt.with_subscriber(Registry::default());
1327 let _dispatch = Dispatch::new(subscriber);
1328 }
1329
1330 #[test]
1331 fn fmt_layer_downcasts() {
1332 let f = format::Format::default();
1333 let fmt = fmt::Layer::default().event_format(f);
1334 let subscriber = fmt.with_subscriber(Registry::default());
1335
1336 let dispatch = Dispatch::new(subscriber);
1337 assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some());
1338 }
1339
1340 #[test]
1341 fn fmt_layer_downcasts_to_parts() {
1342 let f = format::Format::default();
1343 let fmt = fmt::Layer::default().event_format(f);
1344 let subscriber = fmt.with_subscriber(Registry::default());
1345 let dispatch = Dispatch::new(subscriber);
1346 assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
1347 assert!(dispatch.downcast_ref::<format::Format>().is_some())
1348 }
1349
1350 #[test]
1351 fn is_lookup_span() {
1352 fn assert_lookup_span<T: for<'a> crate::registry::LookupSpan<'a>>(_: T) {}
1353 let fmt = fmt::Layer::default();
1354 let subscriber = fmt.with_subscriber(Registry::default());
1355 assert_lookup_span(subscriber)
1356 }
1357
1358 fn sanitize_timings(s: String) -> String {
1359 let re = Regex::new("time\\.(idle|busy)=([0-9.]+)[mµn]s").unwrap();
1360 re.replace_all(s.as_str(), "timing").to_string()
1361 }
1362
1363 #[test]
1364 fn format_error_print_to_stderr() {
1365 struct AlwaysError;
1366
1367 impl std::fmt::Debug for AlwaysError {
1368 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1369 Err(std::fmt::Error)
1370 }
1371 }
1372
1373 let make_writer = MockMakeWriter::default();
1374 let subscriber = crate::fmt::Subscriber::builder()
1375 .with_writer(make_writer.clone())
1376 .with_level(false)
1377 .with_ansi(false)
1378 .with_timer(MockTime)
1379 .finish();
1380
1381 with_default(subscriber, || {
1382 tracing::info!(?AlwaysError);
1383 });
1384 let actual = sanitize_timings(make_writer.get_string());
1385
1386 let expected = concat!(
1388 "Unable to format the following event. Name: event ",
1389 file!(),
1390 ":"
1391 );
1392 assert!(
1393 actual.as_str().starts_with(expected),
1394 "\nactual = {}\nshould start with expected = {}\n",
1395 actual,
1396 expected
1397 );
1398 }
1399
1400 #[test]
1401 fn format_error_ignore_if_log_internal_errors_is_false() {
1402 struct AlwaysError;
1403
1404 impl std::fmt::Debug for AlwaysError {
1405 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1406 Err(std::fmt::Error)
1407 }
1408 }
1409
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 .log_internal_errors(false)
1417 .finish();
1418
1419 with_default(subscriber, || {
1420 tracing::info!(?AlwaysError);
1421 });
1422 let actual = sanitize_timings(make_writer.get_string());
1423 assert_eq!("", actual.as_str());
1424 }
1425
1426 #[test]
1427 fn synthesize_span_none() {
1428 let make_writer = MockMakeWriter::default();
1429 let subscriber = crate::fmt::Subscriber::builder()
1430 .with_writer(make_writer.clone())
1431 .with_level(false)
1432 .with_ansi(false)
1433 .with_timer(MockTime)
1434 .finish();
1436
1437 with_default(subscriber, || {
1438 let span1 = tracing::info_span!("span1", x = 42);
1439 let _e = span1.enter();
1440 });
1441 let actual = sanitize_timings(make_writer.get_string());
1442 assert_eq!("", actual.as_str());
1443 }
1444
1445 #[test]
1446 fn synthesize_span_active() {
1447 let make_writer = MockMakeWriter::default();
1448 let subscriber = crate::fmt::Subscriber::builder()
1449 .with_writer(make_writer.clone())
1450 .with_level(false)
1451 .with_ansi(false)
1452 .with_timer(MockTime)
1453 .with_span_events(FmtSpan::ACTIVE)
1454 .finish();
1455
1456 with_default(subscriber, || {
1457 let span1 = tracing::info_span!("span1", x = 42);
1458 let _e = span1.enter();
1459 });
1460 let actual = sanitize_timings(make_writer.get_string());
1461 assert_eq!(
1462 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1463 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n",
1464 actual.as_str()
1465 );
1466 }
1467
1468 #[test]
1469 fn synthesize_span_close() {
1470 let make_writer = MockMakeWriter::default();
1471 let subscriber = crate::fmt::Subscriber::builder()
1472 .with_writer(make_writer.clone())
1473 .with_level(false)
1474 .with_ansi(false)
1475 .with_timer(MockTime)
1476 .with_span_events(FmtSpan::CLOSE)
1477 .finish();
1478
1479 with_default(subscriber, || {
1480 let span1 = tracing::info_span!("span1", x = 42);
1481 let _e = span1.enter();
1482 });
1483 let actual = sanitize_timings(make_writer.get_string());
1484 assert_eq!(
1485 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1486 actual.as_str()
1487 );
1488 }
1489
1490 #[test]
1491 fn synthesize_span_close_no_timing() {
1492 let make_writer = MockMakeWriter::default();
1493 let subscriber = crate::fmt::Subscriber::builder()
1494 .with_writer(make_writer.clone())
1495 .with_level(false)
1496 .with_ansi(false)
1497 .with_timer(MockTime)
1498 .without_time()
1499 .with_span_events(FmtSpan::CLOSE)
1500 .finish();
1501
1502 with_default(subscriber, || {
1503 let span1 = tracing::info_span!("span1", x = 42);
1504 let _e = span1.enter();
1505 });
1506 let actual = sanitize_timings(make_writer.get_string());
1507 assert_eq!(
1508 "span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close\n",
1509 actual.as_str()
1510 );
1511 }
1512
1513 #[test]
1514 fn synthesize_span_full() {
1515 let make_writer = MockMakeWriter::default();
1516 let subscriber = crate::fmt::Subscriber::builder()
1517 .with_writer(make_writer.clone())
1518 .with_level(false)
1519 .with_ansi(false)
1520 .with_timer(MockTime)
1521 .with_span_events(FmtSpan::FULL)
1522 .finish();
1523
1524 with_default(subscriber, || {
1525 let span1 = tracing::info_span!("span1", x = 42);
1526 let _e = span1.enter();
1527 });
1528 let actual = sanitize_timings(make_writer.get_string());
1529 assert_eq!(
1530 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: new\n\
1531 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1532 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\
1533 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: close timing timing\n",
1534 actual.as_str()
1535 );
1536 }
1537
1538 #[test]
1539 fn make_writer_based_on_meta() {
1540 struct MakeByTarget {
1541 make_writer1: MockMakeWriter,
1542 make_writer2: MockMakeWriter,
1543 }
1544
1545 impl<'a> MakeWriter<'a> for MakeByTarget {
1546 type Writer = MockWriter;
1547
1548 fn make_writer(&'a self) -> Self::Writer {
1549 self.make_writer1.make_writer()
1550 }
1551
1552 fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer {
1553 if meta.target() == "writer2" {
1554 return self.make_writer2.make_writer();
1555 }
1556 self.make_writer()
1557 }
1558 }
1559
1560 let make_writer1 = MockMakeWriter::default();
1561 let make_writer2 = MockMakeWriter::default();
1562
1563 let make_writer = MakeByTarget {
1564 make_writer1: make_writer1.clone(),
1565 make_writer2: make_writer2.clone(),
1566 };
1567
1568 let subscriber = crate::fmt::Subscriber::builder()
1569 .with_writer(make_writer)
1570 .with_level(false)
1571 .with_target(false)
1572 .with_ansi(false)
1573 .with_timer(MockTime)
1574 .with_span_events(FmtSpan::CLOSE)
1575 .finish();
1576
1577 with_default(subscriber, || {
1578 let span1 = tracing::info_span!("writer1_span", x = 42);
1579 let _e = span1.enter();
1580 tracing::info!(target: "writer2", "hello writer2!");
1581 let span2 = tracing::info_span!(target: "writer2", "writer2_span");
1582 let _e = span2.enter();
1583 tracing::warn!(target: "writer1", "hello writer1!");
1584 });
1585
1586 let actual = sanitize_timings(make_writer1.get_string());
1587 assert_eq!(
1588 "fake time writer1_span{x=42}:writer2_span: hello writer1!\n\
1589 fake time writer1_span{x=42}: close timing timing\n",
1590 actual.as_str()
1591 );
1592 let actual = sanitize_timings(make_writer2.get_string());
1593 assert_eq!(
1594 "fake time writer1_span{x=42}: hello writer2!\n\
1595 fake time writer1_span{x=42}:writer2_span: close timing timing\n",
1596 actual.as_str()
1597 );
1598 }
1599
1600 #[cfg(feature = "ansi")]
1603 #[test]
1604 fn layer_no_color() {
1605 const NO_COLOR: &str = "NO_COLOR";
1606
1607 struct RestoreEnvVar(Result<String, env::VarError>);
1614 impl Drop for RestoreEnvVar {
1615 fn drop(&mut self) {
1616 match self.0 {
1617 Ok(ref var) => env::set_var(NO_COLOR, var),
1618 Err(_) => env::remove_var(NO_COLOR),
1619 }
1620 }
1621 }
1622
1623 let _saved_no_color = RestoreEnvVar(env::var(NO_COLOR));
1624
1625 let cases: Vec<(Option<&str>, bool)> = vec![
1626 (Some("0"), false), (Some("off"), false), (Some("1"), false),
1629 (Some(""), true), (None, true),
1631 ];
1632
1633 for (var, ansi) in cases {
1634 if let Some(value) = var {
1635 env::set_var(NO_COLOR, value);
1636 } else {
1637 env::remove_var(NO_COLOR);
1638 }
1639
1640 let layer: Layer<()> = fmt::Layer::default();
1641 assert_eq!(
1642 layer.is_ansi, ansi,
1643 "NO_COLOR={:?}; Layer::default().is_ansi should be {}",
1644 var, ansi
1645 );
1646
1647 let layer: Layer<()> = fmt::Layer::default().with_ansi(true);
1649 assert!(
1650 layer.is_ansi,
1651 "NO_COLOR={:?}; Layer::default().with_ansi(true).is_ansi should be true",
1652 var
1653 );
1654
1655 let mut layer: Layer<()> = fmt::Layer::default();
1657 layer.set_ansi(true);
1658 assert!(
1659 layer.is_ansi,
1660 "NO_COLOR={:?}; layer.set_ansi(true); layer.is_ansi should be true",
1661 var
1662 );
1663 }
1664
1665 }
1668
1669 #[test]
1671 fn modify_span_events() {
1672 let make_writer = MockMakeWriter::default();
1673
1674 let inner_layer = fmt::Layer::default()
1675 .with_writer(make_writer.clone())
1676 .with_level(false)
1677 .with_ansi(false)
1678 .with_timer(MockTime)
1679 .with_span_events(FmtSpan::ACTIVE);
1680
1681 let (reloadable_layer, reload_handle) = crate::reload::Layer::new(inner_layer);
1682 let reload = reloadable_layer.with_subscriber(Registry::default());
1683
1684 with_default(reload, || {
1685 {
1686 let span1 = tracing::info_span!("span1", x = 42);
1687 let _e = span1.enter();
1688 }
1689
1690 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::NONE));
1691
1692 {
1694 let span2 = tracing::info_span!("span2", x = 100);
1695 let _e = span2.enter();
1696 }
1697
1698 {
1699 let span3 = tracing::info_span!("span3", x = 42);
1700 let _e = span3.enter();
1701
1702 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::ACTIVE));
1705 }
1706 });
1707 let actual = sanitize_timings(make_writer.get_string());
1708 assert_eq!(
1709 "fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: enter\n\
1710 fake time span1{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n\
1711 fake time span3{x=42}: tracing_subscriber::fmt::fmt_layer::test: exit\n",
1712 actual.as_str()
1713 );
1714 }
1715}