]> git.proxmox.com Git - rustc.git/blame - vendor/tracing-subscriber/src/fmt/format/json.rs
New upstream version 1.57.0+dfsg1
[rustc.git] / vendor / tracing-subscriber / src / fmt / format / json.rs
CommitLineData
f035d41b
XL
1use super::{Format, FormatEvent, FormatFields, FormatTime};
2use crate::{
3 field::{RecordFields, VisitOutput},
4 fmt::fmt_layer::{FmtContext, FormattedFields},
5 registry::LookupSpan,
6};
7use serde::ser::{SerializeMap, Serializer as _};
8use serde_json::Serializer;
9use std::{
10 collections::BTreeMap,
11 fmt::{self, Write},
12 io,
13};
14use tracing_core::{
15 field::{self, Field},
16 span::Record,
17 Event, Subscriber,
18};
19use tracing_serde::AsSerde;
20
21#[cfg(feature = "tracing-log")]
22use tracing_log::NormalizeEvent;
23
c295e0f8 24/// Marker for `Format` that indicates that the verbose JSON log format should be used.
f035d41b
XL
25///
26/// The full format includes fields from all entered spans.
27///
28/// # Example Output
29///
c295e0f8 30/// ```json
3dfed10e
XL
31/// {
32/// "timestamp":"Feb 20 11:28:15.096",
33/// "level":"INFO",
3dfed10e 34/// "fields":{"message":"some message","key":"value"}
29967ef6
XL
35/// "target":"mycrate",
36/// "span":{name":"leaf"},
37/// "spans":[{"name":"root"},{"name":"leaf"}],
3dfed10e 38/// }
f035d41b
XL
39/// ```
40///
41/// # Options
42///
3dfed10e
XL
43/// - [`Json::flatten_event`] can be used to enable flattening event fields into
44/// the root
45/// - [`Json::with_current_span`] can be used to control logging of the current
46/// span
47/// - [`Json::with_span_list`] can be used to control logging of the span list
f035d41b
XL
48/// object.
49///
3dfed10e
XL
50/// By default, event fields are not flattened, and both current span and span
51/// list are logged.
52///
f035d41b 53/// [`Json::flatten_event`]: #method.flatten_event
3dfed10e
XL
54/// [`Json::with_current_span`]: #method.with_current_span
55/// [`Json::with_span_list`]: #method.with_span_list
f035d41b
XL
56#[derive(Debug, Copy, Clone, Eq, PartialEq)]
57pub struct Json {
58 pub(crate) flatten_event: bool,
3dfed10e
XL
59 pub(crate) display_current_span: bool,
60 pub(crate) display_span_list: bool,
f035d41b
XL
61}
62
63impl Json {
64 /// If set to `true` event metadata will be flattened into the root object.
65 pub fn flatten_event(&mut self, flatten_event: bool) {
66 self.flatten_event = flatten_event;
67 }
3dfed10e
XL
68
69 /// If set to `false`, formatted events won't contain a field for the current span.
70 pub fn with_current_span(&mut self, display_current_span: bool) {
71 self.display_current_span = display_current_span;
72 }
73
74 /// If set to `false`, formatted events won't contain a list of all currently
75 /// entered spans. Spans are logged in a list from root to leaf.
76 pub fn with_span_list(&mut self, display_span_list: bool) {
77 self.display_span_list = display_span_list;
78 }
79}
80
81struct SerializableContext<'a, 'b, Span, N>(
82 &'b crate::layer::Context<'a, Span>,
83 std::marker::PhantomData<N>,
84)
85where
86 Span: Subscriber + for<'lookup> crate::registry::LookupSpan<'lookup>,
87 N: for<'writer> FormatFields<'writer> + 'static;
88
89impl<'a, 'b, Span, N> serde::ser::Serialize for SerializableContext<'a, 'b, Span, N>
90where
91 Span: Subscriber + for<'lookup> crate::registry::LookupSpan<'lookup>,
92 N: for<'writer> FormatFields<'writer> + 'static,
93{
94 fn serialize<Ser>(&self, serializer_o: Ser) -> Result<Ser::Ok, Ser::Error>
95 where
96 Ser: serde::ser::Serializer,
97 {
98 use serde::ser::SerializeSeq;
99 let mut serializer = serializer_o.serialize_seq(None)?;
100
136023e0
XL
101 if let Some(leaf_span) = self.0.lookup_current() {
102 for span in leaf_span.scope().from_root() {
103 serializer.serialize_element(&SerializableSpan(&span, self.1))?;
104 }
3dfed10e
XL
105 }
106
107 serializer.end()
108 }
109}
110
111struct SerializableSpan<'a, 'b, Span, N>(
112 &'b crate::registry::SpanRef<'a, Span>,
113 std::marker::PhantomData<N>,
114)
115where
116 Span: for<'lookup> crate::registry::LookupSpan<'lookup>,
117 N: for<'writer> FormatFields<'writer> + 'static;
118
119impl<'a, 'b, Span, N> serde::ser::Serialize for SerializableSpan<'a, 'b, Span, N>
120where
121 Span: for<'lookup> crate::registry::LookupSpan<'lookup>,
122 N: for<'writer> FormatFields<'writer> + 'static,
123{
124 fn serialize<Ser>(&self, serializer: Ser) -> Result<Ser::Ok, Ser::Error>
125 where
126 Ser: serde::ser::Serializer,
127 {
128 let mut serializer = serializer.serialize_map(None)?;
129
130 let ext = self.0.extensions();
131 let data = ext
132 .get::<FormattedFields<N>>()
133 .expect("Unable to find FormattedFields in extensions; this is a bug");
134
135 // TODO: let's _not_ do this, but this resolves
136 // https://github.com/tokio-rs/tracing/issues/391.
137 // We should probably rework this to use a `serde_json::Value` or something
138 // similar in a JSON-specific layer, but I'd (david)
139 // rather have a uglier fix now rather than shipping broken JSON.
c295e0f8 140 match serde_json::from_str::<serde_json::Value>(data) {
3dfed10e
XL
141 Ok(serde_json::Value::Object(fields)) => {
142 for field in fields {
143 serializer.serialize_entry(&field.0, &field.1)?;
144 }
145 }
146 // We have fields for this span which are valid JSON but not an object.
147 // This is probably a bug, so panic if we're in debug mode
148 Ok(_) if cfg!(debug_assertions) => panic!(
149 "span '{}' had malformed fields! this is a bug.\n error: invalid JSON object\n fields: {:?}",
150 self.0.metadata().name(),
151 data
152 ),
153 // If we *aren't* in debug mode, it's probably best not to
154 // crash the program, let's log the field found but also an
155 // message saying it's type is invalid
156 Ok(value) => {
157 serializer.serialize_entry("field", &value)?;
158 serializer.serialize_entry("field_error", "field was no a valid object")?
159 }
160 // We have previously recorded fields for this span
161 // should be valid JSON. However, they appear to *not*
162 // be valid JSON. This is almost certainly a bug, so
163 // panic if we're in debug mode
164 Err(e) if cfg!(debug_assertions) => panic!(
165 "span '{}' had malformed fields! this is a bug.\n error: {}\n fields: {:?}",
166 self.0.metadata().name(),
167 e,
168 data
169 ),
170 // If we *aren't* in debug mode, it's probably best not
171 // crash the program, but let's at least make sure it's clear
172 // that the fields are not supposed to be missing.
173 Err(e) => serializer.serialize_entry("field_error", &format!("{}", e))?,
174 };
175 serializer.serialize_entry("name", self.0.metadata().name())?;
176 serializer.end()
177 }
f035d41b
XL
178}
179
180impl<S, N, T> FormatEvent<S, N> for Format<Json, T>
181where
182 S: Subscriber + for<'lookup> LookupSpan<'lookup>,
183 N: for<'writer> FormatFields<'writer> + 'static,
184 T: FormatTime,
185{
186 fn format_event(
187 &self,
188 ctx: &FmtContext<'_, S, N>,
189 writer: &mut dyn fmt::Write,
190 event: &Event<'_>,
191 ) -> fmt::Result
192 where
193 S: Subscriber + for<'a> LookupSpan<'a>,
194 {
f035d41b
XL
195 let mut timestamp = String::new();
196 self.timer.format_time(&mut timestamp)?;
197
198 #[cfg(feature = "tracing-log")]
199 let normalized_meta = event.normalized_metadata();
200 #[cfg(feature = "tracing-log")]
201 let meta = normalized_meta.as_ref().unwrap_or_else(|| event.metadata());
202 #[cfg(not(feature = "tracing-log"))]
203 let meta = event.metadata();
204
f035d41b
XL
205 let mut visit = || {
206 let mut serializer = Serializer::new(WriteAdaptor::new(writer));
207
208 let mut serializer = serializer.serialize_map(None)?;
209
c295e0f8
XL
210 if self.display_timestamp {
211 serializer.serialize_entry("timestamp", &timestamp)?;
212 }
213
214 if self.display_level {
215 serializer.serialize_entry("level", &meta.level().as_serde())?;
216 }
f035d41b 217
3dfed10e
XL
218 let format_field_marker: std::marker::PhantomData<N> = std::marker::PhantomData;
219
220 let current_span = if self.format.display_current_span || self.format.display_span_list
221 {
17df50a5
XL
222 event
223 .parent()
224 .and_then(|id| ctx.span(id))
225 .or_else(|| ctx.lookup_current())
3dfed10e
XL
226 } else {
227 None
228 };
229
29967ef6
XL
230 if self.format.flatten_event {
231 let mut visitor = tracing_serde::SerdeMapVisitor::new(serializer);
232 event.record(&mut visitor);
233
234 serializer = visitor.take_serializer()?;
235 } else {
236 use tracing_serde::fields::AsMap;
237 serializer.serialize_entry("fields", &event.field_map())?;
238 };
239
240 if self.display_target {
241 serializer.serialize_entry("target", meta.target())?;
3dfed10e
XL
242 }
243
244 if self.format.display_current_span {
29967ef6 245 if let Some(ref span) = current_span {
3dfed10e 246 serializer
29967ef6 247 .serialize_entry("span", &SerializableSpan(span, format_field_marker))
3dfed10e 248 .unwrap_or(());
f035d41b
XL
249 }
250 }
251
29967ef6
XL
252 if self.format.display_span_list && current_span.is_some() {
253 serializer.serialize_entry(
254 "spans",
255 &SerializableContext(&ctx.ctx, format_field_marker),
256 )?;
f035d41b
XL
257 }
258
3dfed10e
XL
259 if self.display_thread_name {
260 let current_thread = std::thread::current();
261 match current_thread.name() {
262 Some(name) => {
263 serializer.serialize_entry("threadName", name)?;
264 }
265 // fall-back to thread id when name is absent and ids are not enabled
266 None if !self.display_thread_id => {
267 serializer
268 .serialize_entry("threadName", &format!("{:?}", current_thread.id()))?;
269 }
270 _ => {}
271 }
272 }
273
274 if self.display_thread_id {
275 serializer
276 .serialize_entry("threadId", &format!("{:?}", std::thread::current().id()))?;
277 }
278
29967ef6 279 serializer.end()
f035d41b
XL
280 };
281
282 visit().map_err(|_| fmt::Error)?;
283 writeln!(writer)
284 }
285}
286
287impl Default for Json {
288 fn default() -> Json {
289 Json {
290 flatten_event: false,
3dfed10e
XL
291 display_current_span: true,
292 display_span_list: true,
f035d41b
XL
293 }
294 }
295}
296
297/// The JSON [`FormatFields`] implementation.
298///
299/// [`FormatFields`]: trait.FormatFields.html
300#[derive(Debug)]
301pub struct JsonFields {
302 // reserve the ability to add fields to this without causing a breaking
303 // change in the future.
304 _private: (),
305}
306
307impl JsonFields {
308 /// Returns a new JSON [`FormatFields`] implementation.
309 ///
310 /// [`FormatFields`]: trait.FormatFields.html
311 pub fn new() -> Self {
312 Self { _private: () }
313 }
314}
315
316impl Default for JsonFields {
317 fn default() -> Self {
318 Self::new()
319 }
320}
321
322impl<'a> FormatFields<'a> for JsonFields {
323 /// Format the provided `fields` to the provided `writer`, returning a result.
324 fn format_fields<R: RecordFields>(
325 &self,
326 writer: &'a mut dyn fmt::Write,
327 fields: R,
328 ) -> fmt::Result {
329 let mut v = JsonVisitor::new(writer);
330 fields.record(&mut v);
331 v.finish()
332 }
333
334 /// Record additional field(s) on an existing span.
335 ///
336 /// By default, this appends a space to the current set of fields if it is
337 /// non-empty, and then calls `self.format_fields`. If different behavior is
338 /// required, the default implementation of this method can be overridden.
339 fn add_fields(&self, current: &'a mut String, fields: &Record<'_>) -> fmt::Result {
340 if !current.is_empty() {
341 // If fields were previously recorded on this span, we need to parse
342 // the current set of fields as JSON, add the new fields, and
343 // re-serialize them. Otherwise, if we just appended the new fields
344 // to a previously serialized JSON object, we would end up with
345 // malformed JSON.
346 //
347 // XXX(eliza): this is far from efficient, but unfortunately, it is
348 // necessary as long as the JSON formatter is implemented on top of
349 // an interface that stores all formatted fields as strings.
350 //
351 // We should consider reimplementing the JSON formatter as a
352 // separate layer, rather than a formatter for the `fmt` layer —
353 // then, we could store fields as JSON values, and add to them
354 // without having to parse and re-serialize.
355 let mut new = String::new();
356 let map: BTreeMap<&'_ str, serde_json::Value> =
357 serde_json::from_str(current).map_err(|_| fmt::Error)?;
358 let mut v = JsonVisitor::new(&mut new);
359 v.values = map;
360 fields.record(&mut v);
361 v.finish()?;
362 *current = new;
363 } else {
364 // If there are no previously recorded fields, we can just reuse the
365 // existing string.
366 let mut v = JsonVisitor::new(current);
367 fields.record(&mut v);
368 v.finish()?;
369 }
370
371 Ok(())
372 }
373}
374
375/// The [visitor] produced by [`JsonFields`]'s [`MakeVisitor`] implementation.
376///
377/// [visitor]: ../../field/trait.Visit.html
378/// [`JsonFields`]: struct.JsonFields.html
379/// [`MakeVisitor`]: ../../field/trait.MakeVisitor.html
380pub struct JsonVisitor<'a> {
381 values: BTreeMap<&'a str, serde_json::Value>,
382 writer: &'a mut dyn Write,
383}
384
385impl<'a> fmt::Debug for JsonVisitor<'a> {
386 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
387 f.write_fmt(format_args!("JsonVisitor {{ values: {:?} }}", self.values))
388 }
389}
390
391impl<'a> JsonVisitor<'a> {
392 /// Returns a new default visitor that formats to the provided `writer`.
393 ///
394 /// # Arguments
395 /// - `writer`: the writer to format to.
396 /// - `is_empty`: whether or not any fields have been previously written to
397 /// that writer.
398 pub fn new(writer: &'a mut dyn Write) -> Self {
399 Self {
400 values: BTreeMap::new(),
401 writer,
402 }
403 }
404}
405
406impl<'a> crate::field::VisitFmt for JsonVisitor<'a> {
407 fn writer(&mut self) -> &mut dyn fmt::Write {
408 self.writer
409 }
410}
411
412impl<'a> crate::field::VisitOutput<fmt::Result> for JsonVisitor<'a> {
413 fn finish(self) -> fmt::Result {
414 let inner = || {
415 let mut serializer = Serializer::new(WriteAdaptor::new(self.writer));
416 let mut ser_map = serializer.serialize_map(None)?;
417
418 for (k, v) in self.values {
419 ser_map.serialize_entry(k, &v)?;
420 }
421
422 ser_map.end()
423 };
424
425 if inner().is_err() {
426 Err(fmt::Error)
427 } else {
428 Ok(())
429 }
430 }
431}
432
433impl<'a> field::Visit for JsonVisitor<'a> {
c295e0f8
XL
434 /// Visit a double precision floating point value.
435 fn record_f64(&mut self, field: &Field, value: f64) {
436 self.values
437 .insert(field.name(), serde_json::Value::from(value));
438 }
439
f035d41b
XL
440 /// Visit a signed 64-bit integer value.
441 fn record_i64(&mut self, field: &Field, value: i64) {
442 self.values
c295e0f8 443 .insert(field.name(), serde_json::Value::from(value));
f035d41b
XL
444 }
445
446 /// Visit an unsigned 64-bit integer value.
447 fn record_u64(&mut self, field: &Field, value: u64) {
448 self.values
c295e0f8 449 .insert(field.name(), serde_json::Value::from(value));
f035d41b
XL
450 }
451
452 /// Visit a boolean value.
453 fn record_bool(&mut self, field: &Field, value: bool) {
454 self.values
c295e0f8 455 .insert(field.name(), serde_json::Value::from(value));
f035d41b
XL
456 }
457
458 /// Visit a string value.
459 fn record_str(&mut self, field: &Field, value: &str) {
460 self.values
c295e0f8 461 .insert(field.name(), serde_json::Value::from(value));
f035d41b
XL
462 }
463
464 fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
465 match field.name() {
466 // Skip fields that are actually log metadata that have already been handled
467 #[cfg(feature = "tracing-log")]
468 name if name.starts_with("log.") => (),
469 name if name.starts_with("r#") => {
470 self.values
471 .insert(&name[2..], serde_json::Value::from(format!("{:?}", value)));
472 }
473 name => {
474 self.values
475 .insert(name, serde_json::Value::from(format!("{:?}", value)));
476 }
477 };
478 }
479}
480
481/// A bridge between `fmt::Write` and `io::Write`.
482///
483/// This is needed because tracing-subscriber's FormatEvent expects a fmt::Write
484/// while serde_json's Serializer expects an io::Write.
485struct WriteAdaptor<'a> {
486 fmt_write: &'a mut dyn fmt::Write,
487}
488
489impl<'a> WriteAdaptor<'a> {
490 fn new(fmt_write: &'a mut dyn fmt::Write) -> Self {
491 Self { fmt_write }
492 }
493}
494
495impl<'a> io::Write for WriteAdaptor<'a> {
496 fn write(&mut self, buf: &[u8]) -> io::Result<usize> {
497 let s =
498 std::str::from_utf8(buf).map_err(|e| io::Error::new(io::ErrorKind::InvalidData, e))?;
499
500 self.fmt_write
c295e0f8 501 .write_str(s)
f035d41b
XL
502 .map_err(|e| io::Error::new(io::ErrorKind::Other, e))?;
503
504 Ok(s.as_bytes().len())
505 }
506
507 fn flush(&mut self) -> io::Result<()> {
508 Ok(())
509 }
510}
511
512impl<'a> fmt::Debug for WriteAdaptor<'a> {
513 fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
514 f.pad("WriteAdaptor { .. }")
515 }
516}
517
518#[cfg(test)]
519mod test {
17df50a5
XL
520 use super::*;
521 use crate::fmt::{format::FmtSpan, test::MockMakeWriter, time::FormatTime, SubscriberBuilder};
f035d41b 522 use lazy_static::lazy_static;
f035d41b 523 use std::{fmt, sync::Mutex};
17df50a5 524 use tracing::{self, subscriber::with_default};
f035d41b
XL
525
526 struct MockTime;
527 impl FormatTime for MockTime {
528 fn format_time(&self, w: &mut dyn fmt::Write) -> fmt::Result {
529 write!(w, "fake time")
530 }
531 }
532
17df50a5
XL
533 fn subscriber() -> SubscriberBuilder<JsonFields, Format<Json>> {
534 SubscriberBuilder::default().json()
535 }
536
f035d41b
XL
537 #[test]
538 fn json() {
539 lazy_static! {
17df50a5 540 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
f035d41b
XL
541 }
542
f035d41b 543 let expected =
3dfed10e 544 "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"tracing_subscriber::fmt::format::json::test\",\"fields\":{\"message\":\"some json test\"}}\n";
17df50a5
XL
545 let subscriber = subscriber()
546 .flatten_event(false)
547 .with_current_span(true)
548 .with_span_list(true);
549 test_json(expected, subscriber, &BUF, || {
3dfed10e
XL
550 let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
551 let _guard = span.enter();
552 tracing::info!("some json test");
553 });
f035d41b
XL
554 }
555
556 #[test]
557 fn json_flattened_event() {
558 lazy_static! {
17df50a5 559 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
f035d41b
XL
560 }
561
f035d41b 562 let expected =
3dfed10e 563 "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"tracing_subscriber::fmt::format::json::test\",\"message\":\"some json test\"}\n";
17df50a5
XL
564 let subscriber = subscriber()
565 .flatten_event(true)
566 .with_current_span(true)
567 .with_span_list(true);
568 test_json(expected, subscriber, &BUF, || {
3dfed10e
XL
569 let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
570 let _guard = span.enter();
571 tracing::info!("some json test");
572 });
573 }
574
575 #[test]
576 fn json_disabled_current_span_event() {
577 lazy_static! {
17df50a5 578 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
3dfed10e
XL
579 }
580
3dfed10e
XL
581 let expected =
582 "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3}],\"target\":\"tracing_subscriber::fmt::format::json::test\",\"fields\":{\"message\":\"some json test\"}}\n";
17df50a5
XL
583 let subscriber = subscriber()
584 .flatten_event(false)
585 .with_current_span(false)
586 .with_span_list(true);
587 test_json(expected, subscriber, &BUF, || {
3dfed10e
XL
588 let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
589 let _guard = span.enter();
590 tracing::info!("some json test");
591 });
592 }
593
594 #[test]
595 fn json_disabled_span_list_event() {
596 lazy_static! {
17df50a5 597 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
3dfed10e
XL
598 }
599
3dfed10e
XL
600 let expected =
601 "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":42,\"name\":\"json_span\",\"number\":3},\"target\":\"tracing_subscriber::fmt::format::json::test\",\"fields\":{\"message\":\"some json test\"}}\n";
17df50a5
XL
602 let subscriber = subscriber()
603 .flatten_event(false)
604 .with_current_span(true)
605 .with_span_list(false);
606 test_json(expected, subscriber, &BUF, || {
3dfed10e
XL
607 let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
608 let _guard = span.enter();
609 tracing::info!("some json test");
610 });
611 }
612
613 #[test]
614 fn json_nested_span() {
615 lazy_static! {
17df50a5 616 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
3dfed10e
XL
617 }
618
3dfed10e
XL
619 let expected =
620 "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"span\":{\"answer\":43,\"name\":\"nested_json_span\",\"number\":4},\"spans\":[{\"answer\":42,\"name\":\"json_span\",\"number\":3},{\"answer\":43,\"name\":\"nested_json_span\",\"number\":4}],\"target\":\"tracing_subscriber::fmt::format::json::test\",\"fields\":{\"message\":\"some json test\"}}\n";
17df50a5
XL
621 let subscriber = subscriber()
622 .flatten_event(false)
623 .with_current_span(true)
624 .with_span_list(true);
625 test_json(expected, subscriber, &BUF, || {
3dfed10e
XL
626 let span = tracing::span!(tracing::Level::INFO, "json_span", answer = 42, number = 3);
627 let _guard = span.enter();
628 let span = tracing::span!(
629 tracing::Level::INFO,
630 "nested_json_span",
631 answer = 43,
632 number = 4
633 );
634 let _guard = span.enter();
635 tracing::info!("some json test");
636 });
637 }
638
639 #[test]
640 fn json_no_span() {
641 lazy_static! {
17df50a5 642 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
3dfed10e
XL
643 }
644
3dfed10e
XL
645 let expected =
646 "{\"timestamp\":\"fake time\",\"level\":\"INFO\",\"target\":\"tracing_subscriber::fmt::format::json::test\",\"fields\":{\"message\":\"some json test\"}}\n";
17df50a5
XL
647 let subscriber = subscriber()
648 .flatten_event(false)
649 .with_current_span(true)
650 .with_span_list(true);
651 test_json(expected, subscriber, &BUF, || {
3dfed10e
XL
652 tracing::info!("some json test");
653 });
f035d41b
XL
654 }
655
656 #[test]
657 fn record_works() {
658 // This test reproduces issue #707, where using `Span::record` causes
659 // any events inside the span to be ignored.
660 lazy_static! {
17df50a5 661 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
f035d41b
XL
662 }
663
17df50a5
XL
664 let buffer = MockMakeWriter::new(&BUF);
665 let subscriber = crate::fmt().json().with_writer(buffer.clone()).finish();
f035d41b
XL
666
667 with_default(subscriber, || {
668 tracing::info!("an event outside the root span");
669 assert_eq!(
17df50a5 670 parse_as_json(&buffer)["fields"]["message"],
f035d41b
XL
671 "an event outside the root span"
672 );
673
674 let span = tracing::info_span!("the span", na = tracing::field::Empty);
675 span.record("na", &"value");
676 let _enter = span.enter();
677
678 tracing::info!("an event inside the root span");
679 assert_eq!(
17df50a5 680 parse_as_json(&buffer)["fields"]["message"],
f035d41b
XL
681 "an event inside the root span"
682 );
683 });
684 }
685
17df50a5
XL
686 #[test]
687 fn json_span_event_show_correct_context() {
688 lazy_static! {
689 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
690 }
691
692 let buffer = MockMakeWriter::new(&BUF);
693 let subscriber = subscriber()
694 .with_writer(buffer.clone())
695 .flatten_event(false)
696 .with_current_span(true)
697 .with_span_list(false)
698 .with_span_events(FmtSpan::FULL)
699 .finish();
700
701 with_default(subscriber, || {
702 let context = "parent";
703 let parent_span = tracing::info_span!("parent_span", context);
704
705 let event = parse_as_json(&buffer);
706 assert_eq!(event["fields"]["message"], "new");
707 assert_eq!(event["span"]["context"], "parent");
708
709 let _parent_enter = parent_span.enter();
710 let event = parse_as_json(&buffer);
711 assert_eq!(event["fields"]["message"], "enter");
712 assert_eq!(event["span"]["context"], "parent");
713
714 let context = "child";
715 let child_span = tracing::info_span!("child_span", context);
716 let event = parse_as_json(&buffer);
717 assert_eq!(event["fields"]["message"], "new");
718 assert_eq!(event["span"]["context"], "child");
719
720 let _child_enter = child_span.enter();
721 let event = parse_as_json(&buffer);
722 assert_eq!(event["fields"]["message"], "enter");
723 assert_eq!(event["span"]["context"], "child");
724
725 drop(_child_enter);
726 let event = parse_as_json(&buffer);
727 assert_eq!(event["fields"]["message"], "exit");
728 assert_eq!(event["span"]["context"], "child");
729
730 drop(child_span);
731 let event = parse_as_json(&buffer);
732 assert_eq!(event["fields"]["message"], "close");
733 assert_eq!(event["span"]["context"], "child");
734
735 drop(_parent_enter);
736 let event = parse_as_json(&buffer);
737 assert_eq!(event["fields"]["message"], "exit");
738 assert_eq!(event["span"]["context"], "parent");
739
740 drop(parent_span);
741 let event = parse_as_json(&buffer);
742 assert_eq!(event["fields"]["message"], "close");
743 assert_eq!(event["span"]["context"], "parent");
744 });
745 }
746
747 #[test]
748 fn json_span_event_with_no_fields() {
749 // Check span events serialize correctly.
750 // Discussion: https://github.com/tokio-rs/tracing/issues/829#issuecomment-661984255
751 lazy_static! {
752 static ref BUF: Mutex<Vec<u8>> = Mutex::new(Vec::new());
753 }
754
755 let buffer = MockMakeWriter::new(&BUF);
756 let subscriber = subscriber()
757 .with_writer(buffer.clone())
758 .flatten_event(false)
759 .with_current_span(false)
760 .with_span_list(false)
761 .with_span_events(FmtSpan::FULL)
762 .finish();
763
764 with_default(subscriber, || {
765 let span = tracing::info_span!("valid_json");
766 assert_eq!(parse_as_json(&buffer)["fields"]["message"], "new");
767
768 let _enter = span.enter();
769 assert_eq!(parse_as_json(&buffer)["fields"]["message"], "enter");
770
771 drop(_enter);
772 assert_eq!(parse_as_json(&buffer)["fields"]["message"], "exit");
773
774 drop(span);
775 assert_eq!(parse_as_json(&buffer)["fields"]["message"], "close");
776 });
777 }
778
779 fn parse_as_json(buffer: &MockMakeWriter<'_>) -> serde_json::Value {
780 let buf = String::from_utf8(buffer.buf().to_vec()).unwrap();
781 let json = buf
782 .lines()
783 .last()
784 .expect("expected at least one line to be written!");
c295e0f8 785 match serde_json::from_str(json) {
17df50a5
XL
786 Ok(v) => v,
787 Err(e) => panic!(
788 "assertion failed: JSON shouldn't be malformed\n error: {}\n json: {}",
789 e, json
790 ),
791 }
792 }
793
794 fn test_json<T>(
3dfed10e 795 expected: &str,
17df50a5
XL
796 builder: crate::fmt::SubscriberBuilder<JsonFields, Format<Json>>,
797 buf: &'static Mutex<Vec<u8>>,
798 producer: impl FnOnce() -> T,
799 ) {
c295e0f8 800 let make_writer = MockMakeWriter::new(buf);
17df50a5
XL
801 let subscriber = builder
802 .with_writer(make_writer.clone())
f035d41b
XL
803 .with_timer(MockTime)
804 .finish();
805
3dfed10e 806 with_default(subscriber, producer);
f035d41b 807
17df50a5
XL
808 let buf = make_writer.buf();
809 let actual = std::str::from_utf8(&buf[..]).unwrap();
3dfed10e
XL
810 assert_eq!(
811 serde_json::from_str::<std::collections::HashMap<&str, serde_json::Value>>(expected)
812 .unwrap(),
17df50a5 813 serde_json::from_str(actual).unwrap()
3dfed10e 814 );
f035d41b
XL
815 }
816}