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]
1312 pub fn lookup_current(&self) -> Option<SpanRef<'_, S>>
1313 where
1314 S: for<'lookup> LookupSpan<'lookup>,
1315 {
1316 if let Some(exiting_span_id) = &self.exiting_span {
1318 self.ctx.span(exiting_span_id)
1319 } else {
1320 self.ctx.lookup_current()
1322 }
1323 }
1324
1325 pub fn scope(&self) -> Option<registry::Scope<'_, S>>
1336 where
1337 S: for<'lookup> LookupSpan<'lookup>,
1338 {
1339 if let Some(exiting_span_id) = &self.exiting_span {
1341 self.span_scope(exiting_span_id)
1342 } else {
1343 self.event_scope()
1345 }
1346 }
1347
1348 pub fn current_span(&self) -> Current {
1350 self.ctx.current_span()
1351 }
1352
1353 pub fn parent_span(&self) -> Option<SpanRef<'_, S>> {
1362 self.ctx.event_span(self.event)
1363 }
1364
1365 pub fn span_scope(&self, id: &Id) -> Option<registry::Scope<'_, S>>
1392 where
1393 S: for<'lookup> LookupSpan<'lookup>,
1394 {
1395 self.ctx.span_scope(id)
1396 }
1397
1398 pub fn event_scope(&self) -> Option<registry::Scope<'_, S>>
1423 where
1424 S: for<'lookup> registry::LookupSpan<'lookup>,
1425 {
1426 self.ctx.event_scope(self.event)
1427 }
1428
1429 pub fn field_format(&self) -> &N {
1437 self.fmt_fields
1438 }
1439}
1440
1441struct Timings {
1442 idle: u64,
1443 busy: u64,
1444 last: Instant,
1445 entered_count: u64,
1446}
1447
1448impl Timings {
1449 fn new() -> Self {
1450 Self {
1451 idle: 0,
1452 busy: 0,
1453 last: Instant::now(),
1454 entered_count: 0,
1455 }
1456 }
1457}
1458
1459#[cfg(test)]
1460mod test {
1461 use super::*;
1462 use crate::fmt::{
1463 self,
1464 format::{self, test::MockTime, Format},
1465 layer::Layer as _,
1466 test::{MockMakeWriter, MockWriter},
1467 time,
1468 };
1469 use crate::Registry;
1470 use format::FmtSpan;
1471 use regex::Regex;
1472 use tracing::subscriber::with_default;
1473 use tracing_core::dispatcher::Dispatch;
1474
1475 #[test]
1476 fn impls() {
1477 let f = Format::default().with_timer(time::Uptime::default());
1478 let fmt = fmt::Layer::default().event_format(f);
1479 let subscriber = fmt.with_subscriber(Registry::default());
1480 let _dispatch = Dispatch::new(subscriber);
1481
1482 let f = format::Format::default();
1483 let fmt = fmt::Layer::default().event_format(f);
1484 let subscriber = fmt.with_subscriber(Registry::default());
1485 let _dispatch = Dispatch::new(subscriber);
1486
1487 let f = format::Format::default().compact();
1488 let fmt = fmt::Layer::default().event_format(f);
1489 let subscriber = fmt.with_subscriber(Registry::default());
1490 let _dispatch = Dispatch::new(subscriber);
1491 }
1492
1493 #[test]
1494 fn fmt_layer_downcasts() {
1495 let f = format::Format::default();
1496 let fmt = fmt::Layer::default().event_format(f);
1497 let subscriber = fmt.with_subscriber(Registry::default());
1498
1499 let dispatch = Dispatch::new(subscriber);
1500 assert!(dispatch.downcast_ref::<fmt::Layer<Registry>>().is_some());
1501 }
1502
1503 #[test]
1504 fn fmt_layer_downcasts_to_parts() {
1505 let f = format::Format::default();
1506 let fmt = fmt::Layer::default().event_format(f);
1507 let subscriber = fmt.with_subscriber(Registry::default());
1508 let dispatch = Dispatch::new(subscriber);
1509 assert!(dispatch.downcast_ref::<format::DefaultFields>().is_some());
1510 assert!(dispatch.downcast_ref::<format::Format>().is_some())
1511 }
1512
1513 #[test]
1514 fn is_lookup_span() {
1515 fn assert_lookup_span<T: for<'a> crate::registry::LookupSpan<'a>>(_: T) {}
1516 let fmt = fmt::Layer::default();
1517 let subscriber = fmt.with_subscriber(Registry::default());
1518 assert_lookup_span(subscriber)
1519 }
1520
1521 fn sanitize_timings(s: String) -> String {
1522 let re = Regex::new("time\\.(idle|busy)=([0-9.]+)[mµn]s").unwrap();
1523 re.replace_all(s.as_str(), "timing").to_string()
1524 }
1525
1526 #[test]
1527 fn format_error_print_to_stderr() {
1528 struct AlwaysError;
1529
1530 impl std::fmt::Debug for AlwaysError {
1531 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1532 Err(std::fmt::Error)
1533 }
1534 }
1535
1536 let make_writer = MockMakeWriter::default();
1537 let subscriber = crate::fmt::Subscriber::builder()
1538 .with_writer(make_writer.clone())
1539 .with_level(false)
1540 .with_ansi(false)
1541 .with_timer(MockTime)
1542 .finish();
1543
1544 with_default(subscriber, || {
1545 tracing::info!(?AlwaysError);
1546 });
1547 let actual = sanitize_timings(make_writer.get_string());
1548
1549 let expected = concat!(
1551 "Unable to format the following event. Name: event ",
1552 file!(),
1553 ":"
1554 );
1555 assert!(
1556 actual.as_str().starts_with(expected),
1557 "\nactual = {}\nshould start with expected = {}\n",
1558 actual,
1559 expected
1560 );
1561 }
1562
1563 #[test]
1564 fn format_error_ignore_if_log_internal_errors_is_false() {
1565 struct AlwaysError;
1566
1567 impl std::fmt::Debug for AlwaysError {
1568 fn fmt(&self, _f: &mut core::fmt::Formatter<'_>) -> core::fmt::Result {
1569 Err(std::fmt::Error)
1570 }
1571 }
1572
1573 let make_writer = MockMakeWriter::default();
1574 let subscriber = crate::fmt::Subscriber::builder()
1575 .with_writer(make_writer.clone())
1576 .with_level(false)
1577 .with_ansi(false)
1578 .with_timer(MockTime)
1579 .log_internal_errors(false)
1580 .finish();
1581
1582 with_default(subscriber, || {
1583 tracing::info!(?AlwaysError);
1584 });
1585 let actual = sanitize_timings(make_writer.get_string());
1586 assert_eq!("", actual.as_str());
1587 }
1588
1589 #[test]
1590 fn synthesize_span_none() {
1591 let make_writer = MockMakeWriter::default();
1592 let subscriber = crate::fmt::Subscriber::builder()
1593 .with_writer(make_writer.clone())
1594 .with_level(false)
1595 .with_ansi(false)
1596 .with_timer(MockTime)
1597 .finish();
1599
1600 with_default(subscriber, || {
1601 let span1 = tracing::info_span!("span1", x = 42);
1602 let _e = span1.enter();
1603 });
1604 let actual = sanitize_timings(make_writer.get_string());
1605 assert_eq!("", actual.as_str());
1606 }
1607
1608 #[test]
1609 fn synthesize_span_active() {
1610 let make_writer = MockMakeWriter::default();
1611 let subscriber = crate::fmt::Subscriber::builder()
1612 .with_writer(make_writer.clone())
1613 .with_level(false)
1614 .with_ansi(false)
1615 .with_timer(MockTime)
1616 .with_span_events(FmtSpan::ACTIVE)
1617 .finish();
1618
1619 with_default(subscriber, || {
1620 let span1 = tracing::info_span!("span1", x = 42);
1621 let _e = span1.enter();
1622 });
1623 let actual = sanitize_timings(make_writer.get_string());
1624 assert_eq!(
1625 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: enter\n\
1626 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: exit\n",
1627 actual.as_str()
1628 );
1629 }
1630
1631 #[test]
1632 fn synthesize_span_close() {
1633 let make_writer = MockMakeWriter::default();
1634 let subscriber = crate::fmt::Subscriber::builder()
1635 .with_writer(make_writer.clone())
1636 .with_level(false)
1637 .with_ansi(false)
1638 .with_timer(MockTime)
1639 .with_span_events(FmtSpan::CLOSE)
1640 .finish();
1641
1642 with_default(subscriber, || {
1643 let span1 = tracing::info_span!("span1", x = 42);
1644 let _e = span1.enter();
1645 });
1646 let actual = sanitize_timings(make_writer.get_string());
1647 assert_eq!(
1648 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: close timing timing\n",
1649 actual.as_str()
1650 );
1651 }
1652
1653 #[test]
1654 fn synthesize_span_close_no_timing() {
1655 let make_writer = MockMakeWriter::default();
1656 let subscriber = crate::fmt::Subscriber::builder()
1657 .with_writer(make_writer.clone())
1658 .with_level(false)
1659 .with_ansi(false)
1660 .with_timer(MockTime)
1661 .without_time()
1662 .with_span_events(FmtSpan::CLOSE)
1663 .finish();
1664
1665 with_default(subscriber, || {
1666 let span1 = tracing::info_span!("span1", x = 42);
1667 let _e = span1.enter();
1668 });
1669 let actual = sanitize_timings(make_writer.get_string());
1670 assert_eq!(
1671 "span1{x=42}: better_tracing::fmt::fmt_layer::test: close\n",
1672 actual.as_str()
1673 );
1674 }
1675
1676 #[test]
1677 fn synthesize_span_full() {
1678 let make_writer = MockMakeWriter::default();
1679 let subscriber = crate::fmt::Subscriber::builder()
1680 .with_writer(make_writer.clone())
1681 .with_level(false)
1682 .with_ansi(false)
1683 .with_timer(MockTime)
1684 .with_span_events(FmtSpan::FULL)
1685 .finish();
1686
1687 with_default(subscriber, || {
1688 let span1 = tracing::info_span!("span1", x = 42);
1689 let _e = span1.enter();
1690 });
1691 let actual = sanitize_timings(make_writer.get_string());
1692 assert_eq!(
1693 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: new\n\
1694 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: enter\n\
1695 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: exit\n\
1696 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: close timing timing\n",
1697 actual.as_str()
1698 );
1699 }
1700
1701 #[test]
1702 fn make_writer_based_on_meta() {
1703 struct MakeByTarget {
1704 make_writer1: MockMakeWriter,
1705 make_writer2: MockMakeWriter,
1706 }
1707
1708 impl<'a> MakeWriter<'a> for MakeByTarget {
1709 type Writer = MockWriter;
1710
1711 fn make_writer(&'a self) -> Self::Writer {
1712 self.make_writer1.make_writer()
1713 }
1714
1715 fn make_writer_for(&'a self, meta: &Metadata<'_>) -> Self::Writer {
1716 if meta.target() == "writer2" {
1717 return self.make_writer2.make_writer();
1718 }
1719 self.make_writer()
1720 }
1721 }
1722
1723 let make_writer1 = MockMakeWriter::default();
1724 let make_writer2 = MockMakeWriter::default();
1725
1726 let make_writer = MakeByTarget {
1727 make_writer1: make_writer1.clone(),
1728 make_writer2: make_writer2.clone(),
1729 };
1730
1731 let subscriber = crate::fmt::Subscriber::builder()
1732 .with_writer(make_writer)
1733 .with_level(false)
1734 .with_target(false)
1735 .with_ansi(false)
1736 .with_timer(MockTime)
1737 .with_span_events(FmtSpan::CLOSE)
1738 .finish();
1739
1740 with_default(subscriber, || {
1741 let span1 = tracing::info_span!("writer1_span", x = 42);
1742 let _e = span1.enter();
1743 tracing::info!(target: "writer2", "hello writer2!");
1744 let span2 = tracing::info_span!(target: "writer2", "writer2_span");
1745 let _e = span2.enter();
1746 tracing::warn!(target: "writer1", "hello writer1!");
1747 });
1748
1749 let actual = sanitize_timings(make_writer1.get_string());
1750 assert_eq!(
1751 "fake time writer1_span{x=42}:writer2_span: hello writer1!\n\
1752 fake time writer1_span{x=42}: close timing timing\n",
1753 actual.as_str()
1754 );
1755 let actual = sanitize_timings(make_writer2.get_string());
1756 assert_eq!(
1757 "fake time writer1_span{x=42}: hello writer2!\n\
1758 fake time writer1_span{x=42}:writer2_span: close timing timing\n",
1759 actual.as_str()
1760 );
1761 }
1762
1763 #[cfg(feature = "ansi")]
1766 #[test]
1767 fn layer_no_color() {
1768 const NO_COLOR: &str = "NO_COLOR";
1769
1770 struct RestoreEnvVar(Result<String, env::VarError>);
1777 impl Drop for RestoreEnvVar {
1778 fn drop(&mut self) {
1779 match self.0 {
1780 Ok(ref var) => env::set_var(NO_COLOR, var),
1781 Err(_) => env::remove_var(NO_COLOR),
1782 }
1783 }
1784 }
1785
1786 let _saved_no_color = RestoreEnvVar(env::var(NO_COLOR));
1787
1788 let cases: Vec<(Option<&str>, bool)> = vec![
1789 (Some("0"), false), (Some("off"), false), (Some("1"), false),
1792 (Some(""), true), (None, true),
1794 ];
1795
1796 for (var, ansi) in cases {
1797 if let Some(value) = var {
1798 env::set_var(NO_COLOR, value);
1799 } else {
1800 env::remove_var(NO_COLOR);
1801 }
1802
1803 let layer: Layer<()> = fmt::Layer::default();
1804 assert_eq!(
1805 layer.is_ansi, ansi,
1806 "NO_COLOR={:?}; Layer::default().is_ansi should be {}",
1807 var, ansi
1808 );
1809
1810 let layer: Layer<()> = fmt::Layer::default().with_ansi(true);
1812 assert!(
1813 layer.is_ansi,
1814 "NO_COLOR={:?}; Layer::default().with_ansi(true).is_ansi should be true",
1815 var
1816 );
1817
1818 let mut layer: Layer<()> = fmt::Layer::default();
1820 layer.set_ansi(true);
1821 assert!(
1822 layer.is_ansi,
1823 "NO_COLOR={:?}; layer.set_ansi(true); layer.is_ansi should be true",
1824 var
1825 );
1826 }
1827
1828 }
1831
1832 #[test]
1834 fn modify_span_events() {
1835 let make_writer = MockMakeWriter::default();
1836
1837 let inner_layer = fmt::Layer::default()
1838 .with_writer(make_writer.clone())
1839 .with_level(false)
1840 .with_ansi(false)
1841 .with_timer(MockTime)
1842 .with_span_events(FmtSpan::ACTIVE);
1843
1844 let (reloadable_layer, reload_handle) = crate::reload::Layer::new(inner_layer);
1845 let reload = reloadable_layer.with_subscriber(Registry::default());
1846
1847 with_default(reload, || {
1848 {
1849 let span1 = tracing::info_span!("span1", x = 42);
1850 let _e = span1.enter();
1851 }
1852
1853 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::NONE));
1854
1855 {
1857 let span2 = tracing::info_span!("span2", x = 100);
1858 let _e = span2.enter();
1859 }
1860
1861 {
1862 let span3 = tracing::info_span!("span3", x = 42);
1863 let _e = span3.enter();
1864
1865 let _ = reload_handle.modify(|s| s.set_span_events(FmtSpan::ACTIVE));
1868 }
1869 });
1870 let actual = sanitize_timings(make_writer.get_string());
1871 assert_eq!(
1872 "fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: enter\n\
1873 fake time span1{x=42}: better_tracing::fmt::fmt_layer::test: exit\n\
1874 fake time span3{x=42}: better_tracing::fmt::fmt_layer::test: exit\n",
1875 actual.as_str()
1876 );
1877 }
1878}