1use crate::{
2 field::RecordFields,
3 fmt::{format, FormatEvent, FormatFields, MakeWriter, TestWriter},
4 layer::{self, Context},
5 registry::{self, LookupSpan, SpanRef},
6};
7use format::{FmtSpan, TimingDisplay};
8use std::{
9 any::TypeId, cell::RefCell, env, fmt, io, marker::PhantomData, ops::Deref, time::Instant,
10};
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 _inner: PhantomData<fn(S)>,
77}
78
79impl<S> Layer<S> {
80 pub fn new() -> Self {
82 Self::default()
83 }
84}
85
86impl<S, N, E, W> Layer<S, N, E, W>
88where
89 S: Subscriber + for<'a> LookupSpan<'a>,
90 N: for<'writer> FormatFields<'writer> + 'static,
91 W: for<'writer> MakeWriter<'writer> + 'static,
92{
93 pub fn event_format<E2>(self, e: E2) -> Layer<S, N, E2, W>
116 where
117 E2: FormatEvent<S, N> + 'static,
118 {
119 Layer {
120 fmt_fields: self.fmt_fields,
121 fmt_event: e,
122 fmt_span: self.fmt_span,
123 make_writer: self.make_writer,
124 is_ansi: self.is_ansi,
125 log_internal_errors: self.log_internal_errors,
126 _inner: self._inner,
127 }
128 }
129
130 pub fn map_event_format<E2>(self, f: impl FnOnce(E) -> E2) -> Layer<S, N, E2, W>
146 where
147 E2: FormatEvent<S, N> + 'static,
148 {
149 Layer {
150 fmt_fields: self.fmt_fields,
151 fmt_event: f(self.fmt_event),
152 fmt_span: self.fmt_span,
153 make_writer: self.make_writer,
154 is_ansi: self.is_ansi,
155 log_internal_errors: self.log_internal_errors,
156 _inner: self._inner,
157 }
158 }
159}
160
161impl<S, N, E, W> Layer<S, N, E, W> {
163 pub fn with_writer<W2>(self, make_writer: W2) -> Layer<S, N, E, W2>
180 where
181 W2: for<'writer> MakeWriter<'writer> + 'static,
182 {
183 Layer {
184 fmt_fields: self.fmt_fields,
185 fmt_event: self.fmt_event,
186 fmt_span: self.fmt_span,
187 is_ansi: self.is_ansi,
188 log_internal_errors: self.log_internal_errors,
189 make_writer,
190 _inner: self._inner,
191 }
192 }
193
194 pub fn writer(&self) -> &W {
198 &self.make_writer
199 }
200
201 pub fn writer_mut(&mut self) -> &mut W {
229 &mut self.make_writer
230 }
231
232 #[cfg(feature = "ansi")]
239 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
240 pub fn set_ansi(&mut self, ansi: bool) {
241 self.is_ansi = ansi;
242 }
243
244 pub fn set_span_events(&mut self, kind: FmtSpan) {
259 self.fmt_span = format::FmtSpanConfig {
260 kind,
261 fmt_timing: self.fmt_span.fmt_timing,
262 }
263 }
264
265 pub fn with_test_writer(self) -> Layer<S, N, E, TestWriter> {
288 Layer {
289 fmt_fields: self.fmt_fields,
290 fmt_event: self.fmt_event,
291 fmt_span: self.fmt_span,
292 is_ansi: self.is_ansi,
293 log_internal_errors: self.log_internal_errors,
294 make_writer: TestWriter::default(),
295 _inner: self._inner,
296 }
297 }
298
299 pub fn with_ansi(self, ansi: bool) -> Self {
327 #[cfg(not(feature = "ansi"))]
328 if ansi {
329 const ERROR: &str =
330 "better-tracing: the `ansi` crate feature is required to enable ANSI terminal colors";
331 #[cfg(debug_assertions)]
332 panic!("{}", ERROR);
333 #[cfg(not(debug_assertions))]
334 eprintln!("{}", ERROR);
335 }
336
337 Self {
338 is_ansi: ansi,
339 ..self
340 }
341 }
342
343 pub fn log_internal_errors(self, log_internal_errors: bool) -> Self {
355 Self {
356 log_internal_errors,
357 ..self
358 }
359 }
360
361 pub fn map_writer<W2>(self, f: impl FnOnce(W) -> W2) -> Layer<S, N, E, W2>
381 where
382 W2: for<'writer> MakeWriter<'writer> + 'static,
383 {
384 Layer {
385 fmt_fields: self.fmt_fields,
386 fmt_event: self.fmt_event,
387 fmt_span: self.fmt_span,
388 is_ansi: self.is_ansi,
389 log_internal_errors: self.log_internal_errors,
390 make_writer: f(self.make_writer),
391 _inner: self._inner,
392 }
393 }
394}
395
396impl<S, N, L, T, W> Layer<S, N, format::Format<L, T>, W>
397where
398 N: for<'writer> FormatFields<'writer> + 'static,
399{
400 pub fn with_timer<T2>(self, timer: T2) -> Layer<S, N, format::Format<L, T2>, W> {
415 Layer {
416 fmt_event: self.fmt_event.with_timer(timer),
417 fmt_fields: self.fmt_fields,
418 fmt_span: self.fmt_span,
419 make_writer: self.make_writer,
420 is_ansi: self.is_ansi,
421 log_internal_errors: self.log_internal_errors,
422 _inner: self._inner,
423 }
424 }
425
426 pub fn without_time(self) -> Layer<S, N, format::Format<L, ()>, W> {
428 Layer {
429 fmt_event: self.fmt_event.without_time(),
430 fmt_fields: self.fmt_fields,
431 fmt_span: self.fmt_span.without_time(),
432 make_writer: self.make_writer,
433 is_ansi: self.is_ansi,
434 log_internal_errors: self.log_internal_errors,
435 _inner: self._inner,
436 }
437 }
438
439 pub fn with_span_events(self, kind: FmtSpan) -> Self {
481 Layer {
482 fmt_span: self.fmt_span.with_kind(kind),
483 ..self
484 }
485 }
486
487 pub fn with_target(self, display_target: bool) -> Layer<S, N, format::Format<L, T>, W> {
489 Layer {
490 fmt_event: self.fmt_event.with_target(display_target),
491 ..self
492 }
493 }
494 pub fn with_file(self, display_filename: bool) -> Layer<S, N, format::Format<L, T>, W> {
499 Layer {
500 fmt_event: self.fmt_event.with_file(display_filename),
501 ..self
502 }
503 }
504
505 pub fn with_line_number(
510 self,
511 display_line_number: bool,
512 ) -> Layer<S, N, format::Format<L, T>, W> {
513 Layer {
514 fmt_event: self.fmt_event.with_line_number(display_line_number),
515 ..self
516 }
517 }
518
519 pub fn with_level(self, display_level: bool) -> Layer<S, N, format::Format<L, T>, W> {
521 Layer {
522 fmt_event: self.fmt_event.with_level(display_level),
523 ..self
524 }
525 }
526
527 pub fn with_thread_ids(self, display_thread_ids: bool) -> Layer<S, N, format::Format<L, T>, W> {
532 Layer {
533 fmt_event: self.fmt_event.with_thread_ids(display_thread_ids),
534 ..self
535 }
536 }
537
538 pub fn with_thread_names(
543 self,
544 display_thread_names: bool,
545 ) -> Layer<S, N, format::Format<L, T>, W> {
546 Layer {
547 fmt_event: self.fmt_event.with_thread_names(display_thread_names),
548 ..self
549 }
550 }
551
552 pub fn compact(self) -> Layer<S, N, format::Format<format::Compact, T>, W>
554 where
555 N: for<'writer> FormatFields<'writer> + 'static,
556 {
557 Layer {
558 fmt_event: self.fmt_event.compact(),
559 fmt_fields: self.fmt_fields,
560 fmt_span: self.fmt_span,
561 make_writer: self.make_writer,
562 is_ansi: self.is_ansi,
563 log_internal_errors: self.log_internal_errors,
564 _inner: self._inner,
565 }
566 }
567
568 #[cfg(feature = "ansi")]
570 #[cfg_attr(docsrs, doc(cfg(feature = "ansi")))]
571 pub fn pretty(self) -> Layer<S, format::Pretty, format::Format<format::Pretty, T>, W> {
572 Layer {
573 fmt_event: self.fmt_event.pretty(),
574 fmt_fields: format::Pretty::default(),
575 fmt_span: self.fmt_span,
576 make_writer: self.make_writer,
577 is_ansi: self.is_ansi,
578 log_internal_errors: self.log_internal_errors,
579 _inner: self._inner,
580 }
581 }
582
583 #[cfg(feature = "json")]
600 #[cfg_attr(docsrs, doc(cfg(feature = "json")))]
601 pub fn json(self) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
602 Layer {
603 fmt_event: self.fmt_event.json(),
604 fmt_fields: format::JsonFields::new(),
605 fmt_span: self.fmt_span,
606 make_writer: self.make_writer,
607 is_ansi: false,
609 log_internal_errors: self.log_internal_errors,
610 _inner: self._inner,
611 }
612 }
613}
614
615#[cfg(feature = "json")]
616#[cfg_attr(docsrs, doc(cfg(feature = "json")))]
617impl<S, T, W> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
618 pub fn flatten_event(
622 self,
623 flatten_event: bool,
624 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
625 Layer {
626 fmt_event: self.fmt_event.flatten_event(flatten_event),
627 fmt_fields: format::JsonFields::new(),
628 ..self
629 }
630 }
631
632 pub fn with_current_span(
637 self,
638 display_current_span: bool,
639 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
640 Layer {
641 fmt_event: self.fmt_event.with_current_span(display_current_span),
642 fmt_fields: format::JsonFields::new(),
643 ..self
644 }
645 }
646
647 pub fn with_span_list(
652 self,
653 display_span_list: bool,
654 ) -> Layer<S, format::JsonFields, format::Format<format::Json, T>, W> {
655 Layer {
656 fmt_event: self.fmt_event.with_span_list(display_span_list),
657 fmt_fields: format::JsonFields::new(),
658 ..self
659 }
660 }
661}
662
663impl<S, N, E, W> Layer<S, N, E, W> {
664 pub fn fmt_fields<N2>(self, fmt_fields: N2) -> Layer<S, N2, E, W>
667 where
668 N2: for<'writer> FormatFields<'writer> + 'static,
669 {
670 Layer {
671 fmt_event: self.fmt_event,
672 fmt_fields,
673 fmt_span: self.fmt_span,
674 make_writer: self.make_writer,
675 is_ansi: self.is_ansi,
676 log_internal_errors: self.log_internal_errors,
677 _inner: self._inner,
678 }
679 }
680
681 pub fn map_fmt_fields<N2>(self, f: impl FnOnce(N) -> N2) -> Layer<S, N2, E, W>
698 where
699 N2: for<'writer> FormatFields<'writer> + 'static,
700 {
701 Layer {
702 fmt_event: self.fmt_event,
703 fmt_fields: f(self.fmt_fields),
704 fmt_span: self.fmt_span,
705 make_writer: self.make_writer,
706 is_ansi: self.is_ansi,
707 log_internal_errors: self.log_internal_errors,
708 _inner: self._inner,
709 }
710 }
711}
712
713impl<S> Default for Layer<S> {
714 fn default() -> Self {
715 let ansi = cfg!(feature = "ansi") && env::var("NO_COLOR").map_or(true, |v| v.is_empty());
718
719 Layer {
720 fmt_fields: format::DefaultFields::default(),
721 fmt_event: format::Format::default(),
722 fmt_span: format::FmtSpanConfig::default(),
723 make_writer: io::stdout,
724 is_ansi: ansi,
725 log_internal_errors: false,
726 _inner: PhantomData,
727 }
728 }
729}
730
731impl<S, N, E, W> Layer<S, N, E, W>
732where
733 S: Subscriber + for<'a> LookupSpan<'a>,
734 N: for<'writer> FormatFields<'writer> + 'static,
735 E: FormatEvent<S, N> + 'static,
736 W: for<'writer> MakeWriter<'writer> + 'static,
737{
738 #[inline]
739 fn make_ctx<'a>(&'a self, ctx: Context<'a, S>, event: &'a Event<'a>) -> FmtContext<'a, S, N> {
740 FmtContext {
741 ctx,
742 fmt_fields: &self.fmt_fields,
743 event,
744 exiting_span: None,
745 }
746 }
747}
748
749#[derive(Default)]
759pub struct FormattedFields<E: ?Sized> {
760 _format_fields: PhantomData<fn(E)>,
761 was_ansi: bool,
762 pub fields: String,
764}
765
766impl<E: ?Sized> FormattedFields<E> {
767 pub fn new(fields: String) -> Self {
769 Self {
770 fields,
771 was_ansi: false,
772 _format_fields: PhantomData,
773 }
774 }
775
776 pub fn as_writer(&mut self) -> format::Writer<'_> {
781 format::Writer::new(&mut self.fields).with_ansi(self.was_ansi)
782 }
783}
784
785impl<E: ?Sized> fmt::Debug for FormattedFields<E> {
786 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
787 f.debug_struct("FormattedFields")
788 .field("fields", &self.fields)
789 .field("formatter", &format_args!("{}", std::any::type_name::<E>()))
790 .field("was_ansi", &self.was_ansi)
791 .finish()
792 }
793}
794
795impl<E: ?Sized> fmt::Display for FormattedFields<E> {
796 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
797 fmt::Display::fmt(&self.fields, f)
798 }
799}
800
801impl<E: ?Sized> Deref for FormattedFields<E> {
802 type Target = String;
803 fn deref(&self) -> &Self::Target {
804 &self.fields
805 }
806}
807
808macro_rules! with_event_from_span {
811 ($id:ident, $span:ident, $($field:literal = $value:expr),*, |$event:ident| $code:block) => {
812 let meta = $span.metadata();
813 let cs = meta.callsite();
814 let fs = field::FieldSet::new(&[$($field),*], cs);
815 #[allow(unused)]
816 let mut iter = fs.iter();
817 let v = [$(
818 (&iter.next().unwrap(), ::core::option::Option::Some(&$value as &dyn field::Value)),
819 )*];
820 let vs = fs.value_set(&v);
821 let $event = Event::new_child_of($id, meta, &vs);
822 $code
823 };
824}
825
826impl<S, N, E, W> layer::Layer<S> for Layer<S, N, E, W>
827where
828 S: Subscriber + for<'a> LookupSpan<'a>,
829 N: for<'writer> FormatFields<'writer> + 'static,
830 E: FormatEvent<S, N> + 'static,
831 W: for<'writer> MakeWriter<'writer> + 'static,
832{
833 fn on_new_span(&self, attrs: &Attributes<'_>, id: &Id, ctx: Context<'_, S>) {
834 let span = ctx.span(id).expect("Span not found, this is a bug");
835 let mut extensions = span.extensions_mut();
836
837 if extensions.get_mut::<FormattedFields<N>>().is_none() {
838 let mut fields = FormattedFields::<N>::new(String::new());
839 if self
840 .fmt_fields
841 .format_fields(fields.as_writer().with_ansi(self.is_ansi), attrs)
842 .is_ok()
843 {
844 fields.was_ansi = self.is_ansi;
845 extensions.insert(fields);
846 } else {
847 eprintln!(
848 "[better-tracing] Unable to format the following event, ignoring: {:?}",
849 attrs
850 );
851 }
852 }
853
854 if self.fmt_span.fmt_timing
855 && self.fmt_span.trace_close()
856 && extensions.get_mut::<Timings>().is_none()
857 {
858 extensions.insert(Timings::new());
859 }
860
861 if self.fmt_span.trace_new() {
862 with_event_from_span!(id, span, "message" = "new", |event| {
863 drop(extensions);
864 drop(span);
865 self.on_event(&event, ctx);
866 });
867 }
868 }
869
870 fn on_record(&self, id: &Id, values: &Record<'_>, ctx: Context<'_, S>) {
871 let span = ctx.span(id).expect("Span not found, this is a bug");
872 let mut extensions = span.extensions_mut();
873 if let Some(fields) = extensions.get_mut::<FormattedFields<N>>() {
874 let _ = self.fmt_fields.add_fields(fields, values);
875 return;
876 }
877
878 let mut fields = FormattedFields::<N>::new(String::new());
879 if self
880 .fmt_fields
881 .format_fields(fields.as_writer().with_ansi(self.is_ansi), values)
882 .is_ok()
883 {
884 fields.was_ansi = self.is_ansi;
885 extensions.insert(fields);
886 }
887 }
888
889 fn on_enter(&self, id: &Id, ctx: Context<'_, S>) {
890 if self.fmt_span.trace_enter() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
891 let span = ctx.span(id).expect("Span not found, this is a bug");
892 let mut extensions = span.extensions_mut();
893 if let Some(timings) = extensions.get_mut::<Timings>() {
894 if timings.entered_count == 0 {
895 let now = Instant::now();
896 timings.idle += (now - timings.last).as_nanos() as u64;
897 timings.last = now;
898 }
899 timings.entered_count += 1;
900 }
901
902 if self.fmt_span.trace_enter() {
903 with_event_from_span!(id, span, "message" = "enter", |event| {
904 drop(extensions);
905 drop(span);
906 self.on_event(&event, ctx);
907 });
908 }
909 }
910 }
911
912 fn on_exit(&self, id: &Id, ctx: Context<'_, S>) {
913 if self.fmt_span.trace_exit() || self.fmt_span.trace_close() && self.fmt_span.fmt_timing {
914 let span = ctx.span(id).expect("Span not found, this is a bug");
915 let mut extensions = span.extensions_mut();
916 if let Some(timings) = extensions.get_mut::<Timings>() {
917 timings.entered_count -= 1;
918 if timings.entered_count == 0 {
919 let now = Instant::now();
920 timings.busy += (now - timings.last).as_nanos() as u64;
921 timings.last = now;
922 }
923 }
924
925 if self.fmt_span.trace_exit() {
926 let span_id = id.clone(); with_event_from_span!(id, span, "message" = "exit", |event| {
928 drop(extensions);
929
930 let fmt_ctx = FmtContext {
933 ctx: ctx.clone(),
934 fmt_fields: &self.fmt_fields,
935 event: &event,
936 exiting_span: Some(span_id), };
938
939 thread_local! {
940 static BUF: RefCell<String> = const { RefCell::new(String::new()) };
941 }
942
943 BUF.with(|buf| {
944 let borrow = buf.try_borrow_mut();
945 let mut a;
946 let mut b;
947 let mut buf = match borrow {
948 Ok(buf) => {
949 a = buf;
950 &mut *a
951 }
952 _ => {
953 b = String::new();
954 &mut b
955 }
956 };
957
958 if self
959 .fmt_event
960 .format_event(
961 &fmt_ctx,
962 format::Writer::new(&mut buf).with_ansi(self.is_ansi),
963 &event,
964 )
965 .is_ok()
966 {
967 let mut writer = self.make_writer.make_writer_for(&event.metadata());
968 let res = io::Write::write_all(&mut writer, buf.as_bytes());
969 if self.log_internal_errors {
970 if let Err(e) = res {
971 eprintln!("[better-tracing] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e);
972 }
973 }
974 } else if self.log_internal_errors {
975 let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n",
976 event.metadata().name(), event.fields());
977 let mut writer = self.make_writer.make_writer_for(&event.metadata());
978 let res = io::Write::write_all(&mut writer, err_msg.as_bytes());
979 if let Err(e) = res {
980 eprintln!("[better-tracing] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e);
981 }
982 }
983
984 buf.clear();
985 });
986 drop(span); });
988 }
989 }
990 }
991
992 fn on_close(&self, id: Id, ctx: Context<'_, S>) {
993 if self.fmt_span.trace_close() {
994 let span = ctx.span(&id).expect("Span not found, this is a bug");
995 let extensions = span.extensions();
996 if let Some(timing) = extensions.get::<Timings>() {
997 let Timings {
998 busy,
999 mut idle,
1000 last,
1001 entered_count,
1002 } = *timing;
1003 debug_assert_eq!(entered_count, 0);
1004 idle += (Instant::now() - last).as_nanos() as u64;
1005
1006 let t_idle = field::display(TimingDisplay(idle));
1007 let t_busy = field::display(TimingDisplay(busy));
1008
1009 let span_id = id.clone(); with_event_from_span!(
1011 id,
1012 span,
1013 "message" = "close",
1014 "time.busy" = t_busy,
1015 "time.idle" = t_idle,
1016 |event| {
1017 drop(extensions);
1018
1019 let fmt_ctx = FmtContext {
1021 ctx: ctx.clone(),
1022 fmt_fields: &self.fmt_fields,
1023 event: &event,
1024 exiting_span: Some(span_id), };
1026
1027 thread_local! {
1028 static BUF: RefCell<String> = const { RefCell::new(String::new()) };
1029 }
1030
1031 BUF.with(|buf| {
1032 let borrow = buf.try_borrow_mut();
1033 let mut a;
1034 let mut b;
1035 let mut buf = match borrow {
1036 Ok(buf) => {
1037 a = buf;
1038 &mut *a
1039 }
1040 _ => {
1041 b = String::new();
1042 &mut b
1043 }
1044 };
1045
1046 if self
1047 .fmt_event
1048 .format_event(
1049 &fmt_ctx,
1050 format::Writer::new(&mut buf).with_ansi(self.is_ansi),
1051 &event,
1052 )
1053 .is_ok()
1054 {
1055 let mut writer = self.make_writer.make_writer_for(&event.metadata());
1056 let res = io::Write::write_all(&mut writer, buf.as_bytes());
1057 if self.log_internal_errors {
1058 if let Err(e) = res {
1059 eprintln!("[better-tracing] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e);
1060 }
1061 }
1062 } else if self.log_internal_errors {
1063 let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n",
1064 event.metadata().name(), event.fields());
1065 let mut writer = self.make_writer.make_writer_for(&event.metadata());
1066 let res = io::Write::write_all(&mut writer, err_msg.as_bytes());
1067 if let Err(e) = res {
1068 eprintln!("[better-tracing] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e);
1069 }
1070 }
1071
1072 buf.clear();
1073 });
1074 drop(span); }
1076 );
1077 } else {
1078 let span_id = id.clone(); with_event_from_span!(id, span, "message" = "close", |event| {
1080 drop(extensions);
1081
1082 let fmt_ctx = FmtContext {
1084 ctx: ctx.clone(),
1085 fmt_fields: &self.fmt_fields,
1086 event: &event,
1087 exiting_span: Some(span_id), };
1089
1090 thread_local! {
1091 static BUF: RefCell<String> = const { RefCell::new(String::new()) };
1092 }
1093
1094 BUF.with(|buf| {
1095 let borrow = buf.try_borrow_mut();
1096 let mut a;
1097 let mut b;
1098 let mut buf = match borrow {
1099 Ok(buf) => {
1100 a = buf;
1101 &mut *a
1102 }
1103 _ => {
1104 b = String::new();
1105 &mut b
1106 }
1107 };
1108
1109 if self
1110 .fmt_event
1111 .format_event(
1112 &fmt_ctx,
1113 format::Writer::new(&mut buf).with_ansi(self.is_ansi),
1114 &event,
1115 )
1116 .is_ok()
1117 {
1118 let mut writer = self.make_writer.make_writer_for(&event.metadata());
1119 let res = io::Write::write_all(&mut writer, buf.as_bytes());
1120 if self.log_internal_errors {
1121 if let Err(e) = res {
1122 eprintln!("[better-tracing] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e);
1123 }
1124 }
1125 } else if self.log_internal_errors {
1126 let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n",
1127 event.metadata().name(), event.fields());
1128 let mut writer = self.make_writer.make_writer_for(&event.metadata());
1129 let res = io::Write::write_all(&mut writer, err_msg.as_bytes());
1130 if let Err(e) = res {
1131 eprintln!("[better-tracing] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e);
1132 }
1133 }
1134
1135 buf.clear();
1136 });
1137 drop(span); });
1139 }
1140 }
1141 }
1142
1143 fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
1144 thread_local! {
1145 static BUF: RefCell<String> = const { RefCell::new(String::new()) };
1146 }
1147
1148 BUF.with(|buf| {
1149 let borrow = buf.try_borrow_mut();
1150 let mut a;
1151 let mut b;
1152 let mut buf = match borrow {
1153 Ok(buf) => {
1154 a = buf;
1155 &mut *a
1156 }
1157 _ => {
1158 b = String::new();
1159 &mut b
1160 }
1161 };
1162
1163 let ctx = self.make_ctx(ctx, event);
1164 if self
1165 .fmt_event
1166 .format_event(
1167 &ctx,
1168 format::Writer::new(&mut buf).with_ansi(self.is_ansi),
1169 event,
1170 )
1171 .is_ok()
1172 {
1173 let mut writer = self.make_writer.make_writer_for(event.metadata());
1174 let res = io::Write::write_all(&mut writer, buf.as_bytes());
1175 if self.log_internal_errors {
1176 if let Err(e) = res {
1177 eprintln!("[better-tracing] Unable to write an event to the Writer for this Subscriber! Error: {}\n", e);
1178 }
1179 }
1180 } else if self.log_internal_errors {
1181 let err_msg = format!("Unable to format the following event. Name: {}; Fields: {:?}\n",
1182 event.metadata().name(), event.fields());
1183 let mut writer = self.make_writer.make_writer_for(event.metadata());
1184 let res = io::Write::write_all(&mut writer, err_msg.as_bytes());
1185 if let Err(e) = res {
1186 eprintln!("[better-tracing] Unable to write an \"event formatting error\" to the Writer for this Subscriber! Error: {}\n", e);
1187 }
1188 }
1189
1190 buf.clear();
1191 });
1192 }
1193
1194 unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> {
1195 match () {
1200 _ if id == TypeId::of::<Self>() => Some(self as *const Self as *const ()),
1201 _ if id == TypeId::of::<E>() => Some(&self.fmt_event as *const E as *const ()),
1202 _ if id == TypeId::of::<N>() => Some(&self.fmt_fields as *const N as *const ()),
1203 _ if id == TypeId::of::<W>() => Some(&self.make_writer as *const W as *const ()),
1204 _ => None,
1205 }
1206 }
1207}
1208
1209pub struct FmtContext<'a, S, N>
1211where
1212 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1213{
1214 pub(crate) ctx: Context<'a, S>,
1215 pub(crate) fmt_fields: &'a N,
1216 pub(crate) event: &'a Event<'a>,
1217 pub(crate) exiting_span: Option<Id>,
1219}
1220
1221impl<S, N> fmt::Debug for FmtContext<'_, S, N>
1222where
1223 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1224{
1225 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
1226 f.debug_struct("FmtContext").finish()
1227 }
1228}
1229
1230impl<'writer, S, N> FormatFields<'writer> for FmtContext<'_, S, N>
1231where
1232 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1233 N: FormatFields<'writer> + 'static,
1234{
1235 fn format_fields<R: RecordFields>(
1236 &self,
1237 writer: format::Writer<'writer>,
1238 fields: R,
1239 ) -> fmt::Result {
1240 self.fmt_fields.format_fields(writer, fields)
1241 }
1242}
1243
1244impl<S, N> FmtContext<'_, S, N>
1245where
1246 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
1247 N: for<'writer> FormatFields<'writer> + 'static,
1248{
1249 pub fn visit_spans<E, F>(&self, mut f: F) -> Result<(), E>
1255 where
1256 F: FnMut(&SpanRef<'_, S>) -> Result<(), E>,
1257 {
1258 if let Some(scope) = self.event_scope() {
1260 for span in scope.from_root() {
1261 f(&span)?;
1262 }
1263 }
1264 Ok(())
1265 }
1266
1267 #[inline]
1272 pub fn metadata(&self, id: &Id) -> Option<&'static Metadata<'static>>
1273 where
1274 S: for<'lookup> LookupSpan<'lookup>,
1275 {
1276 self.ctx.metadata(id)
1277 }
1278
1279 #[inline]
1286 pub fn span(&self, id: &Id) -> Option<SpanRef<'_, S>>
1287 where
1288 S: for<'lookup> LookupSpan<'lookup>,
1289 {
1290 self.ctx.span(id)
1291 }
1292
1293 #[inline]
1295 pub fn exists(&self, id: &Id) -> bool
1296 where
1297 S: for<'lookup> LookupSpan<'lookup>,
1298 {
1299 self.ctx.exists(id)
1300 }
1301
1302 #[inline]
1309 pub fn lookup_current(&self) -> Option<SpanRef<'_, S>>
1310 where
1311 S: for<'lookup> LookupSpan<'lookup>,
1312 {
1313 self.ctx.lookup_current()
1314 }
1315
1316 #[inline]
1326 pub fn lookup_exiting_span(&self) -> Option<SpanRef<'_, S>>
1327 where
1328 S: for<'lookup> LookupSpan<'lookup>,
1329 {
1330 self.exiting_span.as_ref().and_then(|id| self.ctx.span(id))
1331 }
1332
1333 pub fn scope(&self) -> Option<registry::Scope<'_, S>>
1344 where
1345 S: for<'lookup> LookupSpan<'lookup>,
1346 {
1347 if let Some(exiting_span_id) = &self.exiting_span {
1349 self.span_scope(exiting_span_id)
1350 } else {
1351 self.event_scope()
1353 }
1354 }
1355
1356 pub fn current_span(&self) -> Current {
1358 self.ctx.current_span()
1359 }
1360
1361 pub fn parent_span(&self) -> Option<SpanRef<'_, S>> {
1370 self.ctx.event_span(self.event)
1371 }
1372
1373 pub fn span_scope(&self, id: &Id) -> Option<registry::Scope<'_, S>>
1400 where
1401 S: for<'lookup> LookupSpan<'lookup>,
1402 {
1403 self.ctx.span_scope(id)
1404 }
1405
1406 pub fn event_scope(&self) -> Option<registry::Scope<'_, S>>
1431 where
1432 S: for<'lookup> registry::LookupSpan<'lookup>,
1433 {
1434 self.ctx.event_scope(self.event)
1435 }
1436
1437 pub fn field_format(&self) -> &N {
1445 self.fmt_fields
1446 }
1447}
1448
1449struct Timings {
1450 idle: u64,
1451 busy: u64,
1452 last: Instant,
1453 entered_count: u64,
1454}
1455
1456impl Timings {
1457 fn new() -> Self {
1458 Self {
1459 idle: 0,
1460 busy: 0,
1461 last: Instant::now(),
1462 entered_count: 0,
1463 }
1464 }
1465}
1466
1467#[cfg(test)]
1468mod test {
1469 use super::*;
1470 use crate::fmt::{
1471 self,
1472 format::{self, test::MockTime, Format},
1473 layer::Layer as _,
1474 test::{MockMakeWriter, MockWriter},
1475 time,
1476 };
1477 use crate::Registry;
1478 use format::FmtSpan;
1479 use regex::Regex;
1480 use tracing::subscriber::with_default;
1481 use tracing_core::dispatcher::Dispatch;
1482
1483 #[test]
1484 fn impls() {
1485 let f = Format::default().with_timer(time::Uptime::default());
1486 let fmt = fmt::Layer::default().event_format(f);
1487 let subscriber = fmt.with_subscriber(Registry::default());
1488 let _dispatch = Dispatch::new(subscriber);
1489
1490 let f = format::Format::default();
1491 let fmt = fmt::Layer::default().event_format(f);
1492 let subscriber = fmt.with_subscriber(Registry::default());
1493 let _dispatch = Dispatch::new(subscriber);
1494
1495 let f = format::Format::default().compact();
1496 let fmt = fmt::Layer::default().event_format(f);
1497 let subscriber = fmt.with_subscriber(Registry::default());
1498 let _dispatch = Dispatch::new(subscriber);
1499 }
1500
1501 #[test]
1502 fn fmt_layer_downcasts() {
1503 let f = format::Format::default();
1504 let fmt = fmt::Layer::default().event_format(f);
1505 let subscriber = fmt.with_subscriber(Registry::default());
1506
1507 let dispatch = Dispatch::new(subscriber);
1508 assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some());
1509 }
1510
1511 #[test]
1512 fn fmt_layer_downcasts_to_parts() {
1513 let f = format::Format::default();
1514 let fmt = fmt::Layer::default().event_format(f);
1515 let subscriber = fmt.with_subscriber(Registry::default());
1516 let dispatch = Dispatch::new(subscriber);
1517 assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
1518 assert!(dispatch.downcast_ref::<format::Format>().is_some())
1519 }
1520
1521 #[test]
1522 fn is_lookup_span() {
1523 fn assert_lookup_span<T: for<'a> crate::registry::LookupSpan<'a>>(_: T) {}
1524 let fmt = fmt::Layer::default();
1525 let subscriber = fmt.with_subscriber(Registry::default());
1526 assert_lookup_span(subscriber)
1527 }
1528
1529 fn sanitize_timings(s: String) -> String {
1530 let re = Regex::new("time\\.(idle|busy)=([0-9.]+)[mµn]s").unwrap();
1531 re.replace_all(s.as_str(), "timing").to_string()
1532 }
1533
1534 #[test]
1535 fn format_error_print_to_stderr() {
1536 struct AlwaysError;
1537
1538 impl std::fmt::Debug for AlwaysError {
1539 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1540 Err(std::fmt::Error)
1541 }
1542 }
1543
1544 let make_writer = MockMakeWriter::default();
1545 let subscriber = crate::fmt::Subscriber::builder()
1546 .with_writer(make_writer.clone())
1547 .with_level(false)
1548 .with_ansi(false)
1549 .with_timer(MockTime)
1550 .finish();
1551
1552 with_default(subscriber, || {
1553 tracing::info!(?AlwaysError);
1554 });
1555 let actual = sanitize_timings(make_writer.get_string());
1556
1557 let expected = concat!(
1559 "Unable to format the following event. Name: event ",
1560 file!(),
1561 ":"
1562 );
1563 assert!(
1564 actual.as_str().starts_with(expected),
1565 "\nactual = {}\nshould start with expected = {}\n",
1566 actual,
1567 expected
1568 );
1569 }
1570
1571 #[test]
1572 fn format_error_ignore_if_log_internal_errors_is_false() {
1573 struct AlwaysError;
1574
1575 impl std::fmt::Debug for AlwaysError {
1576 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1577 Err(std::fmt::Error)
1578 }
1579 }
1580
1581 let make_writer = MockMakeWriter::default();
1582 let subscriber = crate::fmt::Subscriber::builder()
1583 .with_writer(make_writer.clone())
1584 .with_level(false)
1585 .with_ansi(false)
1586 .with_timer(MockTime)
1587 .log_internal_errors(false)
1588 .finish();
1589
1590 with_default(subscriber, || {
1591 tracing::info!(?AlwaysError);
1592 });
1593 let actual = sanitize_timings(make_writer.get_string());
1594 assert_eq!("", actual.as_str());
1595 }
1596
1597 #[test]
1598 fn synthesize_span_none() {
1599 let make_writer = MockMakeWriter::default();
1600 let subscriber = crate::fmt::Subscriber::builder()
1601 .with_writer(make_writer.clone())
1602 .with_level(false)
1603 .with_ansi(false)
1604 .with_timer(MockTime)
1605 .finish();
1607
1608 with_default(subscriber, || {
1609 let span1 = tracing::info_span!("span1", x = 42);
1610 let _e = span1.enter();
1611 });
1612 let actual = sanitize_timings(make_writer.get_string());
1613 assert_eq!("", actual.as_str());
1614 }
1615
1616 #[test]
1617 fn synthesize_span_active() {
1618 let make_writer = MockMakeWriter::default();
1619 let subscriber = crate::fmt::Subscriber::builder()
1620 .with_writer(make_writer.clone())
1621 .with_level(false)
1622 .with_ansi(false)
1623 .with_timer(MockTime)
1624 .with_span_events(FmtSpan::ACTIVE)
1625 .finish();
1626
1627 with_default(subscriber, || {
1628 let span1 = tracing::info_span!("span1", x = 42);
1629 let _e = span1.enter();
1630 });
1631 let actual = sanitize_timings(make_writer.get_string());
1632 assert_eq!(
1633 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: enter\n\
1634 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: exit\n",
1635 actual.as_str()
1636 );
1637 }
1638
1639 #[test]
1640 fn synthesize_span_close() {
1641 let make_writer = MockMakeWriter::default();
1642 let subscriber = crate::fmt::Subscriber::builder()
1643 .with_writer(make_writer.clone())
1644 .with_level(false)
1645 .with_ansi(false)
1646 .with_timer(MockTime)
1647 .with_span_events(FmtSpan::CLOSE)
1648 .finish();
1649
1650 with_default(subscriber, || {
1651 let span1 = tracing::info_span!("span1", x = 42);
1652 let _e = span1.enter();
1653 });
1654 let actual = sanitize_timings(make_writer.get_string());
1655 assert_eq!(
1656 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: close timing timing\n",
1657 actual.as_str()
1658 );
1659 }
1660
1661 #[test]
1662 fn synthesize_span_close_no_timing() {
1663 let make_writer = MockMakeWriter::default();
1664 let subscriber = crate::fmt::Subscriber::builder()
1665 .with_writer(make_writer.clone())
1666 .with_level(false)
1667 .with_ansi(false)
1668 .with_timer(MockTime)
1669 .without_time()
1670 .with_span_events(FmtSpan::CLOSE)
1671 .finish();
1672
1673 with_default(subscriber, || {
1674 let span1 = tracing::info_span!("span1", x = 42);
1675 let _e = span1.enter();
1676 });
1677 let actual = sanitize_timings(make_writer.get_string());
1678 assert_eq!(
1679 "span1{x=42}: better_tracing::fmt::fmt_layer::test: close\n",
1680 actual.as_str()
1681 );
1682 }
1683
1684 #[test]
1685 fn synthesize_span_full() {
1686 let make_writer = MockMakeWriter::default();
1687 let subscriber = crate::fmt::Subscriber::builder()
1688 .with_writer(make_writer.clone())
1689 .with_level(false)
1690 .with_ansi(false)
1691 .with_timer(MockTime)
1692 .with_span_events(FmtSpan::FULL)
1693 .finish();
1694
1695 with_default(subscriber, || {
1696 let span1 = tracing::info_span!("span1", x = 42);
1697 let _e = span1.enter();
1698 });
1699 let actual = sanitize_timings(make_writer.get_string());
1700 assert_eq!(
1701 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: new\n\
1702 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: enter\n\
1703 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: exit\n\
1704 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: close timing timing\n",
1705 actual.as_str()
1706 );
1707 }
1708
1709 #[test]
1710 fn make_writer_based_on_meta() {
1711 struct MakeByTarget {
1712 make_writer1: MockMakeWriter,
1713 make_writer2: MockMakeWriter,
1714 }
1715
1716 impl<'a> MakeWriter<'a> for MakeByTarget {
1717 type Writer = MockWriter;
1718
1719 fn make_writer(&'a self) -> Self::Writer {
1720 self.make_writer1.make_writer()
1721 }
1722
1723 fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer {
1724 if meta.target() == "writer2" {
1725 return self.make_writer2.make_writer();
1726 }
1727 self.make_writer()
1728 }
1729 }
1730
1731 let make_writer1 = MockMakeWriter::default();
1732 let make_writer2 = MockMakeWriter::default();
1733
1734 let make_writer = MakeByTarget {
1735 make_writer1: make_writer1.clone(),
1736 make_writer2: make_writer2.clone(),
1737 };
1738
1739 let subscriber = crate::fmt::Subscriber::builder()
1740 .with_writer(make_writer)
1741 .with_level(false)
1742 .with_target(false)
1743 .with_ansi(false)
1744 .with_timer(MockTime)
1745 .with_span_events(FmtSpan::CLOSE)
1746 .finish();
1747
1748 with_default(subscriber, || {
1749 let span1 = tracing::info_span!("writer1_span", x = 42);
1750 let _e = span1.enter();
1751 tracing::info!(target: "writer2", "hello writer2!");
1752 let span2 = tracing::info_span!(target: "writer2", "writer2_span");
1753 let _e = span2.enter();
1754 tracing::warn!(target: "writer1", "hello writer1!");
1755 });
1756
1757 let actual = sanitize_timings(make_writer1.get_string());
1758 assert_eq!(
1759 "fake time writer1_span{x=42}:writer2_span: hello writer1!\n\
1760 fake time writer1_span{x=42}: close timing timing\n",
1761 actual.as_str()
1762 );
1763 let actual = sanitize_timings(make_writer2.get_string());
1764 assert_eq!(
1765 "fake time writer1_span{x=42}: hello writer2!\n\
1766 fake time writer1_span{x=42}:writer2_span: close timing timing\n",
1767 actual.as_str()
1768 );
1769 }
1770
1771 #[cfg(feature = "ansi")]
1774 #[test]
1775 fn layer_no_color() {
1776 const NO_COLOR: &str = "NO_COLOR";
1777
1778 struct RestoreEnvVar(Result<String, env::VarError>);
1785 impl Drop for RestoreEnvVar {
1786 fn drop(&mut self) {
1787 match self.0 {
1788 Ok(ref var) => env::set_var(NO_COLOR, var),
1789 Err(_) => env::remove_var(NO_COLOR),
1790 }
1791 }
1792 }
1793
1794 let _saved_no_color = RestoreEnvVar(env::var(NO_COLOR));
1795
1796 let cases: Vec<(Option<&str>, bool)> = vec![
1797 (Some("0"), false), (Some("off"), false), (Some("1"), false),
1800 (Some(""), true), (None, true),
1802 ];
1803
1804 for (var, ansi) in cases {
1805 if let Some(value) = var {
1806 env::set_var(NO_COLOR, value);
1807 } else {
1808 env::remove_var(NO_COLOR);
1809 }
1810
1811 let layer: Layer<()> = fmt::Layer::default();
1812 assert_eq!(
1813 layer.is_ansi, ansi,
1814 "NO_COLOR={:?}; Layer::default().is_ansi should be {}",
1815 var, ansi
1816 );
1817
1818 let layer: Layer<()> = fmt::Layer::default().with_ansi(true);
1820 assert!(
1821 layer.is_ansi,
1822 "NO_COLOR={:?}; Layer::default().with_ansi(true).is_ansi should be true",
1823 var
1824 );
1825
1826 let mut layer: Layer<()> = fmt::Layer::default();
1828 layer.set_ansi(true);
1829 assert!(
1830 layer.is_ansi,
1831 "NO_COLOR={:?}; layer.set_ansi(true); layer.is_ansi should be true",
1832 var
1833 );
1834 }
1835
1836 }
1839
1840 #[test]
1842 fn modify_span_events() {
1843 let make_writer = MockMakeWriter::default();
1844
1845 let inner_layer = fmt::Layer::default()
1846 .with_writer(make_writer.clone())
1847 .with_level(false)
1848 .with_ansi(false)
1849 .with_timer(MockTime)
1850 .with_span_events(FmtSpan::ACTIVE);
1851
1852 let (reloadable_layer, reload_handle) = crate::reload::Layer::new(inner_layer);
1853 let reload = reloadable_layer.with_subscriber(Registry::default());
1854
1855 with_default(reload, || {
1856 {
1857 let span1 = tracing::info_span!("span1", x = 42);
1858 let _e = span1.enter();
1859 }
1860
1861 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::NONE));
1862
1863 {
1865 let span2 = tracing::info_span!("span2", x = 100);
1866 let _e = span2.enter();
1867 }
1868
1869 {
1870 let span3 = tracing::info_span!("span3", x = 42);
1871 let _e = span3.enter();
1872
1873 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::ACTIVE));
1876 }
1877 });
1878 let actual = sanitize_timings(make_writer.get_string());
1879 assert_eq!(
1880 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: enter\n\
1881 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: exit\n\
1882 fake time span3{x=42}: better_tracing::fmt::fmt_layer::test: exit\n",
1883 actual.as_str()
1884 );
1885 }
1886}