diagnostics_log_encoding/
lib.rs

1// Copyright 2019 The Fuchsia Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be found in the LICENSE file.
3
4//! This crate provides an implementation of Fuchsia Diagnostic Streams, often referred to as
5//! "logs."
6
7#![warn(missing_docs)]
8
9use bitfield::bitfield;
10use std::borrow::{Borrow, Cow};
11use zerocopy::{FromBytes, Immutable, IntoBytes, KnownLayout};
12
13mod constants;
14pub mod encode;
15pub mod parse;
16
17#[cfg(target_os = "fuchsia")]
18pub use zx;
19
20#[cfg(not(target_os = "fuchsia"))]
21/// Implementation of the `zx` crate for host platforms.
22pub mod zx {
23    use zerocopy::{FromBytes, Immutable, IntoBytes, KnownLayout};
24
25    /// Mock `sys` types for host platforms.
26    pub mod sys {
27        #[allow(non_camel_case_types)]
28        /// Raw koid type.
29        pub type zx_koid_t = u64;
30
31        #[allow(non_camel_case_types)]
32        /// Raw time type.
33        pub type zx_time_t = i64;
34    }
35
36    /// A timestamp from the boot clock.
37    #[derive(
38        Clone,
39        Copy,
40        Debug,
41        Default,
42        Eq,
43        Hash,
44        Ord,
45        PartialEq,
46        PartialOrd,
47        FromBytes,
48        IntoBytes,
49        Immutable,
50        KnownLayout,
51    )]
52    #[repr(transparent)]
53    pub struct BootInstant(i64);
54
55    impl BootInstant {
56        /// A `BootInstant` representing timestamp 0.
57        pub const ZERO: Self = Self(0);
58
59        /// Return a strongly-typed `BootInstant` from a raw number of nanoseconds.
60        pub const fn from_nanos(nanos: i64) -> Self {
61            Self(nanos)
62        }
63
64        /// Returns the number of nanoseconds contained by this `BootInstant`.
65        pub const fn into_nanos(self) -> i64 {
66            self.0
67        }
68
69        /// Get the current boot time.
70        pub fn get() -> Self {
71            let nanos = match std::time::SystemTime::now().duration_since(std::time::UNIX_EPOCH) {
72                Ok(d) => d.as_nanos() as i64,
73                Err(e) => -(e.duration().as_nanos() as i64),
74            };
75            Self::from_nanos(nanos)
76        }
77    }
78
79    /// The unique id assigned by kernel to the object referenced by a handle.
80    #[derive(
81        Clone,
82        Copy,
83        Debug,
84        Default,
85        Eq,
86        Hash,
87        Ord,
88        PartialEq,
89        PartialOrd,
90        FromBytes,
91        IntoBytes,
92        Immutable,
93        KnownLayout,
94    )]
95    #[repr(transparent)]
96    pub struct Koid(u64);
97
98    impl Koid {
99        /// Creates a `Koid` from a raw u64.
100        pub const fn from_raw(raw: u64) -> Self {
101            Self(raw)
102        }
103
104        /// Returns the raw u64 koid value.
105        pub const fn raw_koid(&self) -> u64 {
106            self.0
107        }
108    }
109}
110
111pub use constants::*;
112
113/// A raw severity.
114pub type RawSeverity = u8;
115
116/// A log record.
117#[derive(Clone, Debug, PartialEq)]
118pub struct Record<'a> {
119    /// Time at which the log was emitted.
120    pub timestamp: zx::BootInstant,
121    /// The severity of the log.
122    pub severity: RawSeverity,
123    /// Arguments associated with the log.
124    pub arguments: Vec<Argument<'a>>,
125}
126
127impl Record<'_> {
128    /// Consumes the current value and returns one in the static lifetime.
129    pub fn into_owned(self) -> Record<'static> {
130        Record {
131            timestamp: self.timestamp,
132            severity: self.severity,
133            arguments: self.arguments.into_iter().map(|arg| arg.into_owned()).collect(),
134        }
135    }
136}
137
138/// An argument of the log record identified by a name and with an associated value.
139#[derive(Clone, Debug, PartialEq)]
140pub enum Argument<'a> {
141    /// Process ID
142    Pid(zx::Koid),
143    /// Thread ID
144    Tid(zx::Koid),
145    /// A log tag
146    Tag(Cow<'a, str>),
147    /// Number of dropped logs
148    Dropped(u64),
149    /// A filename
150    File(Cow<'a, str>),
151    /// A log message
152    Message(Cow<'a, str>),
153    /// A line number in a file
154    Line(u64),
155    /// A custom argument with a given name and value
156    Other {
157        /// The name of the argument.
158        name: Cow<'a, str>,
159        /// The value of the argument.
160        value: Value<'a>,
161    },
162}
163
164impl<'a> Argument<'a> {
165    /// Creates a new argument given its name and a value.
166    pub fn new(name: impl Into<Cow<'a, str>>, value: impl Into<Value<'a>>) -> Self {
167        let name: Cow<'a, str> = name.into();
168        match (name.as_ref(), value.into()) {
169            (constants::PID, Value::UnsignedInt(pid)) => Self::pid(zx::Koid::from_raw(pid)),
170            (constants::TID, Value::UnsignedInt(pid)) => Self::tid(zx::Koid::from_raw(pid)),
171            (constants::TAG, Value::Text(tag)) => Self::tag(tag),
172            (constants::NUM_DROPPED, Value::UnsignedInt(dropped)) => Self::dropped(dropped),
173            (constants::FILE, Value::Text(file)) => Self::file(file),
174            (constants::LINE, Value::UnsignedInt(line)) => Self::line(line),
175            (constants::MESSAGE, Value::Text(msg)) => Self::message(msg),
176            (_, value) => Self::other(name, value),
177        }
178    }
179
180    #[inline]
181    /// Creates a new argument for a process id.
182    pub fn pid(koid: zx::Koid) -> Self {
183        Argument::Pid(koid)
184    }
185
186    #[inline]
187    /// Creates a new argument for a thread id.
188    pub fn tid(koid: zx::Koid) -> Self {
189        Argument::Tid(koid)
190    }
191
192    #[inline]
193    /// Creates a new argument for a log message.
194    pub fn message(message: impl Into<Cow<'a, str>>) -> Self {
195        Argument::Message(message.into())
196    }
197
198    #[inline]
199    /// Creates a new argument for a tag.
200    pub fn tag(value: impl Into<Cow<'a, str>>) -> Self {
201        Argument::Tag(value.into())
202    }
203
204    #[inline]
205    /// Creates a new argument for the number of dropped logs.
206    pub fn dropped(value: u64) -> Self {
207        Argument::Dropped(value)
208    }
209
210    #[inline]
211    /// Creates a new argument for a file.
212    pub fn file(value: impl Into<Cow<'a, str>>) -> Self {
213        Argument::File(value.into())
214    }
215
216    #[inline]
217    /// Creates a new argument for a line number.
218    pub fn line(value: u64) -> Self {
219        Argument::Line(value)
220    }
221
222    #[inline]
223    /// Creates a new key-value argument.
224    pub fn other(name: impl Into<Cow<'a, str>>, value: impl Into<Value<'a>>) -> Self {
225        Argument::Other { name: name.into(), value: value.into() }
226    }
227
228    /// Consumes the current value and returns one in the static lifetime.
229    pub fn into_owned(self) -> Argument<'static> {
230        match self {
231            Self::Pid(pid) => Argument::Pid(pid),
232            Self::Tid(tid) => Argument::Tid(tid),
233            Self::Tag(tag) => Argument::Tag(Cow::Owned(tag.into_owned())),
234            Self::Dropped(dropped) => Argument::Dropped(dropped),
235            Self::File(file) => Argument::File(Cow::Owned(file.into_owned())),
236            Self::Line(line) => Argument::Line(line),
237            Self::Message(msg) => Argument::Message(Cow::Owned(msg.into_owned())),
238            Self::Other { name, value } => {
239                Argument::Other { name: Cow::Owned(name.into_owned()), value: value.into_owned() }
240            }
241        }
242    }
243
244    /// Returns the name of the argument.
245    pub fn name(&self) -> &str {
246        match self {
247            Self::Pid(_) => constants::PID,
248            Self::Tid(_) => constants::TID,
249            Self::Tag(_) => constants::TAG,
250            Self::Dropped(_) => constants::NUM_DROPPED,
251            Self::File(_) => constants::FILE,
252            Self::Line(_) => constants::LINE,
253            Self::Message(_) => constants::MESSAGE,
254            Self::Other { name, .. } => name.borrow(),
255        }
256    }
257
258    /// Returns the value of the argument.
259    pub fn value(&'a self) -> Value<'a> {
260        match self {
261            Self::Pid(pid) => Value::UnsignedInt(pid.raw_koid()),
262            Self::Tid(tid) => Value::UnsignedInt(tid.raw_koid()),
263            Self::Tag(tag) => Value::Text(Cow::Borrowed(tag.as_ref())),
264            Self::Dropped(num_dropped) => Value::UnsignedInt(*num_dropped),
265            Self::File(file) => Value::Text(Cow::Borrowed(file.as_ref())),
266            Self::Message(msg) => Value::Text(Cow::Borrowed(msg.as_ref())),
267            Self::Line(line) => Value::UnsignedInt(*line),
268            Self::Other { value, .. } => value.clone_borrowed(),
269        }
270    }
271}
272
273/// The value of a logging argument.
274#[derive(Clone, Debug, PartialEq)]
275pub enum Value<'a> {
276    /// A signed integer value for a logging argument.
277    SignedInt(i64),
278    /// An unsigned integer value for a logging argument.
279    UnsignedInt(u64),
280    /// A floating point value for a logging argument.
281    Floating(f64),
282    /// A boolean value for a logging argument.
283    Boolean(bool),
284    /// A string value for a logging argument.
285    Text(Cow<'a, str>),
286}
287
288impl<'a> Value<'a> {
289    fn into_owned(self) -> Value<'static> {
290        match self {
291            Self::Text(s) => Value::Text(Cow::Owned(s.into_owned())),
292            Self::SignedInt(n) => Value::SignedInt(n),
293            Self::UnsignedInt(n) => Value::UnsignedInt(n),
294            Self::Floating(n) => Value::Floating(n),
295            Self::Boolean(n) => Value::Boolean(n),
296        }
297    }
298
299    fn clone_borrowed(&'a self) -> Value<'a> {
300        match self {
301            Self::Text(s) => Self::Text(Cow::Borrowed(s.as_ref())),
302            Self::SignedInt(n) => Self::SignedInt(*n),
303            Self::UnsignedInt(n) => Self::UnsignedInt(*n),
304            Self::Floating(n) => Self::Floating(*n),
305            Self::Boolean(n) => Self::Boolean(*n),
306        }
307    }
308}
309
310impl From<i32> for Value<'_> {
311    fn from(number: i32) -> Value<'static> {
312        Value::SignedInt(number as i64)
313    }
314}
315
316impl From<i64> for Value<'_> {
317    fn from(number: i64) -> Value<'static> {
318        Value::SignedInt(number)
319    }
320}
321
322impl From<u64> for Value<'_> {
323    fn from(number: u64) -> Value<'static> {
324        Value::UnsignedInt(number)
325    }
326}
327
328impl From<u32> for Value<'_> {
329    fn from(number: u32) -> Value<'static> {
330        Value::UnsignedInt(number as u64)
331    }
332}
333
334impl From<zx::Koid> for Value<'_> {
335    fn from(koid: zx::Koid) -> Value<'static> {
336        Value::UnsignedInt(koid.raw_koid())
337    }
338}
339
340impl From<f64> for Value<'_> {
341    fn from(number: f64) -> Value<'static> {
342        Value::Floating(number)
343    }
344}
345
346impl<'a> From<&'a str> for Value<'a> {
347    fn from(text: &'a str) -> Value<'a> {
348        Value::Text(Cow::Borrowed(text))
349    }
350}
351
352impl From<String> for Value<'static> {
353    fn from(text: String) -> Value<'static> {
354        Value::Text(Cow::Owned(text))
355    }
356}
357
358impl<'a> From<Cow<'a, str>> for Value<'a> {
359    fn from(text: Cow<'a, str>) -> Value<'a> {
360        Value::Text(text)
361    }
362}
363
364impl From<bool> for Value<'static> {
365    fn from(boolean: bool) -> Value<'static> {
366        Value::Boolean(boolean)
367    }
368}
369
370/// The maximum value acceptable for `size_words` below.
371pub const MAX_SIZE_WORDS: u16 = 4095;
372
373/// The bit in the tag that indicates the record is a control message, rather than a FXT record
374/// produced by a component.
375pub const LOG_CONTROL_BIT: u32 = 1 << 31;
376
377bitfield! {
378    /// A header in the tracing format. Expected to precede every Record and Argument.
379    ///
380    /// The tracing format specifies [Record headers] and [Argument headers] as distinct types, but
381    /// their layouts are the same in practice, so we represent both bitfields using the same
382    /// struct.
383    ///
384    /// [Record headers]: https://fuchsia.dev/fuchsia-src/development/tracing/trace-format#record_header
385    /// [Argument headers]: https://fuchsia.dev/fuchsia-src/development/tracing/trace-format#argument_header
386    #[derive(IntoBytes, FromBytes, KnownLayout, Immutable)]
387    pub struct Header(u64);
388    impl Debug;
389
390    /// Record type.
391    pub u8, raw_type, set_type: 3, 0;
392
393    /// Record size as a multiple of 8 bytes.
394    pub u16, size_words, set_size_words: 15, 4;
395
396    /// String ref for the associated name, if any.
397    u16, name_ref, set_name_ref: 31, 16;
398
399    /// Boolean value, if any.
400    bool, bool_val, set_bool_val: 32;
401
402    /// Reserved for record-type-specific data.
403    u16, value_ref, set_value_ref: 47, 32;
404
405    /// Tag for the record, if any.
406    pub u32, tag, set_tag: 47, 16;
407
408    /// Severity of the record, if any.
409    pub u8, severity, set_severity: 63, 56;
410}
411
412impl Header {
413    /// Sets the length of the item the header refers to. Panics if not 8-byte aligned.
414    pub fn set_len(&mut self, new_len: usize) {
415        assert_eq!(new_len % 8, 0, "encoded message must be 8-byte aligned");
416        self.set_size_words((new_len / 8) as u16 + u16::from(!new_len.is_multiple_of(8)))
417    }
418}
419
420/// Tag derived from metadata.
421///
422/// Unlike tags, metatags are not represented as strings and instead must be resolved from event
423/// metadata. This means that they may resolve to different text for different events.
424#[derive(Clone, Copy, Debug, Eq, Hash, PartialEq)]
425pub enum Metatag {
426    /// The location of a span or event.
427    ///
428    /// The target is typically a module path, but this can be configured by a particular span or
429    /// event when it is constructed.
430    Target,
431}
432
433/// These literal values are specified by the tracing format:
434///
435/// https://fuchsia.dev/fuchsia-src/development/tracing/trace-format#argument_header
436#[repr(u8)]
437enum ArgType {
438    Null = 0,
439    I32 = 1,
440    U32 = 2,
441    I64 = 3,
442    U64 = 4,
443    F64 = 5,
444    String = 6,
445    Pointer = 7,
446    Koid = 8,
447    Bool = 9,
448}
449
450impl TryFrom<u8> for ArgType {
451    type Error = parse::ParseError;
452    fn try_from(b: u8) -> Result<Self, Self::Error> {
453        Ok(match b {
454            0 => ArgType::Null,
455            1 => ArgType::I32,
456            2 => ArgType::U32,
457            3 => ArgType::I64,
458            4 => ArgType::U64,
459            5 => ArgType::F64,
460            6 => ArgType::String,
461            7 => ArgType::Pointer,
462            8 => ArgType::Koid,
463            9 => ArgType::Bool,
464            _ => return Err(parse::ParseError::ValueOutOfValidRange),
465        })
466    }
467}
468
469#[cfg(test)]
470mod tests {
471    use super::*;
472    use crate::encode::{Encoder, EncoderOpts, EncodingError, MutableBuffer};
473    use fidl_fuchsia_diagnostics_types::Severity;
474    use std::fmt::Debug;
475    use std::io::Cursor;
476
477    fn parse_argument(bytes: &[u8]) -> (&[u8], Argument<'static>) {
478        let (decoded_from_full, remaining) = crate::parse::parse_argument(bytes).unwrap();
479        (remaining, decoded_from_full.into_owned())
480    }
481
482    fn parse_record(bytes: &[u8]) -> (&[u8], Record<'static>) {
483        let (decoded_from_full, remaining) = crate::parse::parse_record(bytes).unwrap();
484        (remaining, decoded_from_full.into_owned())
485    }
486
487    const BUF_LEN: usize = 1024;
488
489    pub(crate) fn assert_roundtrips<T, F>(
490        val: T,
491        encoder_method: impl Fn(&mut Encoder<Cursor<Vec<u8>>>, &T) -> Result<(), EncodingError>,
492        parser: F,
493        canonical: Option<&[u8]>,
494    ) where
495        T: Debug + PartialEq,
496        F: Fn(&[u8]) -> (&[u8], T),
497    {
498        let mut encoder = Encoder::new(Cursor::new(vec![0; BUF_LEN]), EncoderOpts::default());
499        encoder_method(&mut encoder, &val).unwrap();
500
501        // next we'll parse the record out of a buf with padding after the record
502        let (_, decoded_from_full) = parser(encoder.buf.get_ref());
503        assert_eq!(val, decoded_from_full, "decoded version with trailing padding must match");
504
505        if let Some(canonical) = canonical {
506            let recorded = encoder.buf.get_ref().split_at(canonical.len()).0;
507            assert_eq!(canonical, recorded, "encoded repr must match the canonical value provided");
508
509            let (zero_buf, decoded) = parser(recorded);
510            assert_eq!(val, decoded, "decoded version must match what we tried to encode");
511            assert_eq!(zero_buf.len(), 0, "must parse record exactly out of provided buffer");
512        }
513    }
514
515    /// Bit pattern for the log record type, severity info, and a record of two words: one header,
516    /// one timestamp.
517    const MINIMAL_LOG_HEADER: u64 = 0x3000000000000029;
518
519    #[fuchsia::test]
520    fn minimal_header() {
521        let mut poked = Header(0);
522        poked.set_type(TRACING_FORMAT_LOG_RECORD_TYPE);
523        poked.set_size_words(2);
524        poked.set_severity(Severity::Info.into_primitive());
525
526        assert_eq!(
527            poked.0, MINIMAL_LOG_HEADER,
528            "minimal log header should only describe type, size, and severity"
529        );
530    }
531
532    #[fuchsia::test]
533    fn no_args_roundtrip() {
534        let mut expected_record = MINIMAL_LOG_HEADER.to_le_bytes().to_vec();
535        let timestamp = zx::BootInstant::from_nanos(5_000_000i64);
536        expected_record.extend(timestamp.into_nanos().to_le_bytes());
537
538        assert_roundtrips(
539            Record { timestamp, severity: Severity::Info.into_primitive(), arguments: vec![] },
540            |encoder, val| encoder.write_record(val),
541            parse_record,
542            Some(&expected_record),
543        );
544    }
545
546    #[fuchsia::test]
547    fn signed_arg_roundtrip() {
548        assert_roundtrips(
549            Argument::other("signed", -1999),
550            |encoder, val| encoder.write_argument(val),
551            parse_argument,
552            None,
553        );
554    }
555
556    #[fuchsia::test]
557    fn unsigned_arg_roundtrip() {
558        assert_roundtrips(
559            Argument::other("unsigned", 42),
560            |encoder, val| encoder.write_argument(val),
561            parse_argument,
562            None,
563        );
564    }
565
566    #[fuchsia::test]
567    fn text_arg_roundtrip() {
568        assert_roundtrips(
569            Argument::other("stringarg", "owo"),
570            |encoder, val| encoder.write_argument(val),
571            parse_argument,
572            None,
573        );
574    }
575
576    #[fuchsia::test]
577    fn float_arg_roundtrip() {
578        assert_roundtrips(
579            Argument::other("float", 3.25),
580            |encoder, val| encoder.write_argument(val),
581            parse_argument,
582            None,
583        );
584    }
585
586    #[fuchsia::test]
587    fn bool_arg_roundtrip() {
588        assert_roundtrips(
589            Argument::other("bool", false),
590            |encoder, val| encoder.write_argument(val),
591            parse_argument,
592            None,
593        );
594    }
595
596    #[fuchsia::test]
597    fn arg_of_each_type_roundtrips() {
598        assert_roundtrips(
599            Record {
600                timestamp: zx::BootInstant::get(),
601                severity: Severity::Warn.into_primitive(),
602                arguments: vec![
603                    Argument::other("signed", -10),
604                    Argument::other("unsigned", 7),
605                    Argument::other("float", 3.25),
606                    Argument::other("bool", true),
607                    Argument::other("msg", "test message one"),
608                ],
609            },
610            |encoder, val| encoder.write_record(val),
611            parse_record,
612            None,
613        );
614    }
615
616    #[fuchsia::test]
617    fn multiple_string_args() {
618        assert_roundtrips(
619            Record {
620                timestamp: zx::BootInstant::get(),
621                severity: Severity::Trace.into_primitive(),
622                arguments: vec![
623                    Argument::other("msg", "test message one"),
624                    Argument::other("msg", "test message two"),
625                    Argument::other("msg", "test message three"),
626                ],
627            },
628            |encoder, val| encoder.write_record(val),
629            parse_record,
630            None,
631        );
632    }
633
634    #[fuchsia::test]
635    fn invalid_records() {
636        // invalid word size
637        let mut encoder = Encoder::new(Cursor::new(vec![0; BUF_LEN]), EncoderOpts::default());
638        let mut header = Header(0);
639        header.set_type(TRACING_FORMAT_LOG_RECORD_TYPE);
640        header.set_size_words(0); // invalid, should be at least 2 as header and time are included
641        encoder.buf.put_u64_le(header.0).unwrap();
642        encoder.buf.put_i64_le(zx::BootInstant::get().into_nanos()).unwrap();
643        encoder.write_argument(Argument::other("msg", "test message one")).unwrap();
644        assert!(crate::parse::parse_record(encoder.buf.get_ref()).is_err());
645    }
646}
diagnostics_log_encoding/lib.rs

diagnostics_log_encoding/
lib.rs
