archivist_lib/logs/
mod.rs

1// Copyright 2018 The Fuchsia Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5pub mod container;
6pub mod debuglog;
7pub mod error;
8pub mod listener;
9pub mod repository;
10pub mod serial;
11pub mod servers;
12pub mod shared_buffer;
13pub mod stats;
14pub mod stored_message;
15#[cfg(test)]
16pub mod testing;
17
18#[cfg(test)]
19mod tests {
20    use crate::identity::ComponentIdentity;
21    use crate::logs::testing::*;
22    use diagnostics_assertions::{AnyProperty, assert_data_tree};
23    use diagnostics_log_encoding::{Argument, Record};
24    use diagnostics_log_types::Severity;
25    use fidl_fuchsia_logger::{LogFilterOptions, LogLevelFilter, LogMessage};
26    use fuchsia_async as fasync;
27    use moniker::ExtendedMoniker;
28    use std::sync::Arc;
29
30    #[fuchsia::test]
31    async fn test_log_manager() {
32        Box::pin(TestHarness::default().manager_test()).await;
33    }
34
35    #[fuchsia::test]
36    async fn unfiltered_stats() {
37        let first_message = LogMessage {
38            pid: 1,
39            tid: 2,
40            time: zx::BootInstant::get(),
41            dropped_logs: 3,
42            severity: Severity::Warn as i32,
43            msg: String::from("BBBBB"),
44            tags: vec![String::from("AAAAA")],
45        };
46        let first_packet = to_record(&first_message);
47
48        let mut second_message = first_message.clone();
49        second_message.pid = 0;
50        let second_packet = to_record(&second_message);
51
52        let mut third_message = second_message.clone();
53        third_message.severity = Severity::Info as i32;
54        let third_packet = to_record(&third_message);
55
56        let (fourth_packet, fourth_message) = (third_packet.clone(), third_message.clone());
57
58        let mut fifth_message = fourth_message.clone();
59        fifth_message.severity = Severity::Error as i32;
60        let fifth_packet = to_record(&fifth_message);
61
62        let mut harness = TestHarness::default();
63        let mut stream = harness.create_structured_stream(Arc::new(ComponentIdentity::unknown()));
64        stream.write_packets(vec![
65            first_packet,
66            second_packet,
67            third_packet,
68            fourth_packet,
69            fifth_packet,
70        ]);
71        drop(stream);
72
73        let log_stats_tree = harness
74            .filter_test(
75                vec![first_message, second_message, third_message, fourth_message, fifth_message],
76                None,
77            )
78            .await;
79
80        assert_data_tree!(
81            log_stats_tree,
82            root: contains {
83                log_sources: {
84                    "UNKNOWN": {
85                        url: "fuchsia-pkg://UNKNOWN",
86                        last_timestamp: AnyProperty,
87                        sockets_closed: 1u64,
88                        sockets_opened: 1u64,
89                        invalid: {
90                            number: 0u64,
91                            bytes: 0u64,
92                        },
93                        total: {
94                            number: 5u64,
95                            bytes: AnyProperty,
96                        },
97                        rolled_out: {
98                            number: 0u64,
99                            bytes: 0u64,
100                        },
101                        trace: {
102                            number: 0u64,
103                            bytes: 0u64,
104                        },
105                        debug: {
106                            number: 0u64,
107                            bytes: 0u64,
108                        },
109                        info: {
110                            number: 2u64,
111                            bytes: AnyProperty,
112                        },
113                        warn: {
114                            number: 2u64,
115                            bytes: AnyProperty,
116                        },
117                        error: {
118                            number: 1u64,
119                            bytes: AnyProperty,
120                        },
121                        fatal: {
122                            number: 0u64,
123                            bytes: 0u64,
124                        },
125                    },
126                }
127            }
128        );
129    }
130
131    macro_rules! attributed_inspect_two_streams_different_identities_by_reader {
132        (
133            $harness:ident,
134            $log_reader1:ident @ $foo_moniker:literal,
135            $log_reader2:ident @ $bar_moniker:literal,
136        ) => {{
137            let message = LogMessage {
138                pid: 1,
139                tid: 2,
140                time: zx::BootInstant::get(),
141                dropped_logs: 3,
142                severity: Severity::Warn as i32,
143                msg: String::from("BBBBB"),
144                tags: vec![String::from("AAAAA")],
145            };
146            let packet = to_record(&message);
147
148            let mut message2 = message.clone();
149            message2.severity = Severity::Error as i32;
150            let packet2 = to_record(&message2);
151
152            let mut foo_stream = $harness.create_stream_from_log_reader($log_reader1);
153            foo_stream.write_packet(packet);
154
155            let mut bar_stream = $harness.create_stream_from_log_reader($log_reader2);
156            bar_stream.write_packet(packet2);
157            drop((foo_stream, bar_stream));
158
159            let log_stats_tree = $harness.filter_test(vec![message, message2], None).await;
160
161            assert_data_tree!(
162                log_stats_tree,
163                root: contains {
164                    log_sources: {
165                        $foo_moniker: {
166                            url: "http://foo.com",
167                            last_timestamp: AnyProperty,
168                            sockets_closed: 1u64,
169                            sockets_opened: 1u64,
170                            invalid: {
171                                number: 0u64,
172                                bytes: 0u64,
173                            },
174                            total: {
175                                number: 1u64,
176                                bytes: AnyProperty,
177                            },
178                            rolled_out: {
179                                number: 0u64,
180                                bytes: 0u64,
181                            },
182                            trace: {
183                                number: 0u64,
184                                bytes: 0u64,
185                            },
186                            debug: {
187                                number: 0u64,
188                                bytes: 0u64,
189                            },
190                            info: {
191                                number: 0u64,
192                                bytes: 0u64,
193                            },
194                            warn: {
195                                number: 1u64,
196                                bytes: AnyProperty,
197                            },
198                            error: {
199                                number: 0u64,
200                                bytes: 0u64,
201                            },
202                            fatal: {
203                                number: 0u64,
204                                bytes: 0u64,
205                            },
206                        },
207                        $bar_moniker: {
208                            url: "http://bar.com",
209                            last_timestamp: AnyProperty,
210                            sockets_closed: 1u64,
211                            sockets_opened: 1u64,
212                            invalid: {
213                                number: 0u64,
214                                bytes: 0u64,
215                            },
216                            total: {
217                                number: 1u64,
218                                bytes: AnyProperty,
219                            },
220                            rolled_out: {
221                                number: 0u64,
222                                bytes: 0u64,
223                            },
224                            trace: {
225                                number: 0u64,
226                                bytes: 0u64,
227                            },
228                            debug: {
229                                number: 0u64,
230                                bytes: 0u64,
231                            },
232                            info: {
233                                number: 0u64,
234                                bytes: 0u64,
235                            },
236                            warn: {
237                                number: 0u64,
238                                bytes: 0u64,
239                            },
240                            error: {
241                                number: 1u64,
242                                bytes: AnyProperty,
243                            },
244                            fatal: {
245                                number: 0u64,
246                                bytes: 0u64,
247                            },
248                        },
249                    },
250                }
251            );
252        }}
253    }
254
255    #[fuchsia::test]
256    async fn attributed_inspect_two_streams_different_identities() {
257        let mut harness = TestHarness::with_retained_sinks();
258
259        let log_reader1 = harness.create_default_reader(ComponentIdentity::new(
260            ExtendedMoniker::parse_str("./foo").unwrap(),
261            "http://foo.com",
262        ));
263
264        let log_reader2 = harness.create_default_reader(ComponentIdentity::new(
265            ExtendedMoniker::parse_str("./bar").unwrap(),
266            "http://bar.com",
267        ));
268
269        attributed_inspect_two_streams_different_identities_by_reader!(
270            harness,
271            log_reader1 @ "foo",
272            log_reader2 @ "bar",
273        );
274    }
275
276    #[fuchsia::test]
277    async fn attributed_inspect_two_v2_streams_different_identities() {
278        let mut harness = TestHarness::with_retained_sinks();
279        let log_reader1 = harness.create_event_stream_reader("./foo", "http://foo.com");
280        let log_reader2 = harness.create_event_stream_reader("./bar", "http://bar.com");
281
282        attributed_inspect_two_streams_different_identities_by_reader!(
283            harness,
284            log_reader1 @ "foo",
285            log_reader2 @ "bar",
286        );
287    }
288
289    #[fuchsia::test]
290    async fn attributed_inspect_two_mixed_streams_different_identities() {
291        let mut harness = TestHarness::with_retained_sinks();
292        let log_reader1 = harness.create_event_stream_reader("./foo", "http://foo.com");
293        let log_reader2 = harness.create_default_reader(ComponentIdentity::new(
294            ExtendedMoniker::parse_str("./bar").unwrap(),
295            "http://bar.com",
296        ));
297
298        attributed_inspect_two_streams_different_identities_by_reader!(
299            harness,
300            log_reader1 @ "foo",
301            log_reader2 @ "bar",
302        );
303    }
304
305    #[fuchsia::test]
306    async fn test_filter_by_pid() {
307        let lm = LogMessage {
308            pid: 1,
309            tid: 2,
310            time: zx::BootInstant::get(),
311            dropped_logs: 3,
312            severity: Severity::Info as i32,
313            msg: String::from("BBBBB"),
314            tags: vec![String::from("AAAAA")],
315        };
316        let p = to_record(&lm);
317        let lm2 = LogMessage { pid: 11, ..lm.clone() };
318        let p2 = to_record(&lm2);
319        let options = LogFilterOptions {
320            filter_by_pid: true,
321            pid: 1,
322            filter_by_tid: false,
323            tid: 0,
324            min_severity: LogLevelFilter::None,
325            verbosity: 0,
326            tags: vec![],
327        };
328
329        let mut harness = TestHarness::default();
330        let mut stream = harness.create_structured_stream(Arc::new(ComponentIdentity::unknown()));
331        stream.write_packets(vec![p, p2]);
332        drop(stream);
333        harness.filter_test(vec![lm], Some(options)).await;
334    }
335
336    #[fuchsia::test]
337    async fn test_filter_by_tid() {
338        let lm = LogMessage {
339            pid: 1,
340            tid: 2,
341            time: zx::BootInstant::get(),
342            dropped_logs: 3,
343            severity: Severity::Info as i32,
344            msg: String::from("BBBBB"),
345            tags: vec![String::from("AAAAA")],
346        };
347        let p = to_record(&lm);
348        let lm2 = LogMessage { tid: 12, ..lm.clone() };
349        let p2 = to_record(&lm2);
350        let options = LogFilterOptions {
351            filter_by_pid: false,
352            pid: 1,
353            filter_by_tid: true,
354            tid: 2,
355            min_severity: LogLevelFilter::None,
356            verbosity: 0,
357            tags: vec![],
358        };
359
360        let mut harness = TestHarness::default();
361        let mut stream = harness.create_structured_stream(Arc::new(ComponentIdentity::unknown()));
362        stream.write_packets(vec![p, p2]);
363        drop(stream);
364        harness.filter_test(vec![lm], Some(options)).await;
365    }
366
367    #[fuchsia::test]
368    async fn test_filter_by_min_severity() {
369        let lm = LogMessage {
370            pid: 0,
371            tid: 0,
372            time: zx::BootInstant::get(),
373            dropped_logs: 2,
374            severity: Severity::Error as i32,
375            msg: String::from("BBBBB"),
376            tags: vec![String::from("AAAAA")],
377        };
378        let p = to_record(&LogMessage { severity: Severity::Warn as i32, ..lm.clone() });
379        let p2 = to_record(&lm);
380        let p3 = to_record(&LogMessage { severity: Severity::Info as i32, ..lm.clone() });
381        let p4 = to_record(&LogMessage { severity: 0x70, ..lm.clone() });
382        let p5 = to_record(&LogMessage { severity: Severity::Fatal as i32, ..lm.clone() });
383
384        let options = LogFilterOptions {
385            filter_by_pid: false,
386            pid: 1,
387            filter_by_tid: false,
388            tid: 1,
389            min_severity: LogLevelFilter::Error,
390            verbosity: 0,
391            tags: vec![],
392        };
393
394        let mut harness = TestHarness::default();
395        let mut stream = harness.create_structured_stream(Arc::new(ComponentIdentity::unknown()));
396        stream.write_packets(vec![p, p2, p3, p4, p5]);
397        drop(stream);
398        harness.filter_test(vec![lm], Some(options)).await;
399    }
400
401    #[fuchsia::test]
402    async fn test_filter_by_combination() {
403        let lm = LogMessage {
404            pid: 0,
405            tid: 0,
406            time: zx::BootInstant::get(),
407            dropped_logs: 2,
408            severity: Severity::Error as i32,
409            msg: String::from("BBBBB"),
410            tags: vec![String::from("AAAAA")],
411        };
412        let p = to_record(&LogMessage { severity: Severity::Warn as i32, ..lm.clone() });
413        let p2 = to_record(&lm);
414        let p3 = to_record(&LogMessage { pid: 1, ..lm.clone() });
415        let options = LogFilterOptions {
416            filter_by_pid: true,
417            pid: 0,
418            filter_by_tid: false,
419            tid: 1,
420            min_severity: LogLevelFilter::Error,
421            verbosity: 0,
422            tags: vec![],
423        };
424
425        let mut harness = TestHarness::default();
426        let mut stream = harness.create_structured_stream(Arc::new(ComponentIdentity::unknown()));
427        stream.write_packets(vec![p, p2, p3]);
428        drop(stream);
429        harness.filter_test(vec![lm], Some(options)).await;
430    }
431
432    #[fuchsia::test]
433    async fn test_filter_by_tags() {
434        let lm1 = LogMessage {
435            pid: 1,
436            tid: 1,
437            time: zx::BootInstant::get(),
438            dropped_logs: 2,
439            severity: Severity::Warn as i32,
440            msg: String::from("BBBBB"),
441            tags: vec![String::from("DDDDD")],
442        };
443        let p = to_record(&lm1);
444
445        let lm2 = LogMessage {
446            pid: 0,
447            tid: 0,
448            time: zx::BootInstant::get(),
449            dropped_logs: 2,
450            severity: Severity::Warn as i32,
451            msg: String::from("CCCCC"),
452            tags: vec![String::from("AAAAA"), String::from("BBBBB")],
453        };
454        let p2 = to_record(&lm2);
455
456        let options = LogFilterOptions {
457            filter_by_pid: false,
458            pid: 1,
459            filter_by_tid: false,
460            tid: 1,
461            min_severity: LogLevelFilter::None,
462            verbosity: 0,
463            tags: vec![String::from("BBBBB"), String::from("DDDDD")],
464        };
465
466        let mut harness = TestHarness::default();
467        let mut stream = harness.create_structured_stream(Arc::new(ComponentIdentity::unknown()));
468        stream.write_packets(vec![p, p2]);
469        drop(stream);
470        harness.filter_test(vec![lm1, lm2], Some(options)).await;
471    }
472
473    #[fuchsia::test]
474    async fn test_structured_log() {
475        let logs = vec![
476            Record {
477                timestamp: zx::BootInstant::from_nanos(6),
478                severity: Severity::Info as u8,
479                arguments: vec![Argument::message("hi")],
480            },
481            Record {
482                timestamp: zx::BootInstant::from_nanos(13),
483                severity: Severity::Error as u8,
484                arguments: vec![],
485            },
486            Record {
487                timestamp: zx::BootInstant::from_nanos(19),
488                severity: Severity::Warn as u8,
489                arguments: vec![
490                    Argument::pid(zx::Koid::from_raw(0x1d1)),
491                    Argument::tid(zx::Koid::from_raw(0x1d2)),
492                    Argument::dropped(23),
493                    Argument::tag("tag"),
494                    Argument::message("message"),
495                ],
496            },
497            Record {
498                timestamp: zx::BootInstant::from_nanos(21),
499                severity: Severity::Warn as u8,
500                arguments: vec![Argument::tag("tag-1"), Argument::tag("tag-2")],
501            },
502        ];
503
504        let expected_logs = vec![
505            LogMessage {
506                pid: zx::sys::ZX_KOID_INVALID,
507                tid: zx::sys::ZX_KOID_INVALID,
508                time: zx::BootInstant::from_nanos(6),
509                severity: LogLevelFilter::Info as i32,
510                dropped_logs: 0,
511                msg: String::from("hi"),
512                tags: vec!["UNKNOWN".to_owned()],
513            },
514            LogMessage {
515                pid: zx::sys::ZX_KOID_INVALID,
516                tid: zx::sys::ZX_KOID_INVALID,
517                time: zx::BootInstant::from_nanos(14),
518                severity: LogLevelFilter::Error as i32,
519                dropped_logs: 0,
520                msg: String::from(""),
521                tags: vec!["UNKNOWN".to_owned()],
522            },
523            LogMessage {
524                pid: 0x1d1,
525                tid: 0x1d2,
526                time: zx::BootInstant::from_nanos(19),
527                severity: LogLevelFilter::Warn as i32,
528                dropped_logs: 23,
529                msg: String::from("message"),
530                tags: vec![String::from("tag")],
531            },
532            LogMessage {
533                pid: zx::sys::ZX_KOID_INVALID,
534                tid: zx::sys::ZX_KOID_INVALID,
535                time: zx::BootInstant::from_nanos(21),
536                severity: LogLevelFilter::Warn as i32,
537                dropped_logs: 0,
538                msg: String::from(""),
539                tags: vec![String::from("tag-1"), String::from("tag-2")],
540            },
541        ];
542        let mut harness = TestHarness::default();
543        let mut stream = harness.create_structured_stream(Arc::new(ComponentIdentity::unknown()));
544        stream.write_packets(logs);
545        drop(stream);
546        harness.filter_test(expected_logs, None).await;
547    }
548
549    #[fuchsia::test]
550    async fn test_debuglog_drainer() {
551        let log1 = TestDebugEntry::new("log1".as_bytes());
552        let log2 = TestDebugEntry::new("log2".as_bytes());
553        let log3 = TestDebugEntry::new("log3".as_bytes());
554
555        let klog_reader = TestDebugLog::default();
556        klog_reader.enqueue_read_entry(&log1);
557        klog_reader.enqueue_read_entry(&log2);
558        // logs received after kernel indicates no logs should be read
559        klog_reader.enqueue_read_fail(zx::Status::SHOULD_WAIT);
560        klog_reader.enqueue_read_entry(&log3);
561        klog_reader.enqueue_read_fail(zx::Status::SHOULD_WAIT);
562
563        let expected_logs = vec![
564            LogMessage {
565                pid: log1.record.pid.raw_koid(),
566                tid: log1.record.tid.raw_koid(),
567                time: log1.record.timestamp,
568                dropped_logs: 0,
569                severity: LogLevelFilter::Info as i32,
570                msg: String::from("log1"),
571                tags: vec![String::from("klog")],
572            },
573            LogMessage {
574                pid: log2.record.pid.raw_koid(),
575                tid: log2.record.tid.raw_koid(),
576                time: log2.record.timestamp,
577                dropped_logs: 0,
578                severity: LogLevelFilter::Info as i32,
579                msg: String::from("log2"),
580                tags: vec![String::from("klog")],
581            },
582            LogMessage {
583                pid: log3.record.pid.raw_koid(),
584                tid: log3.record.tid.raw_koid(),
585                time: log3.record.timestamp,
586                dropped_logs: 0,
587                severity: LogLevelFilter::Info as i32,
588                msg: String::from("log3"),
589                tags: vec![String::from("klog")],
590            },
591        ];
592
593        let scope = fasync::Scope::new();
594        let klog_stats_tree = debuglog_test(expected_logs, klog_reader, scope.new_child()).await;
595        assert_data_tree!(
596            klog_stats_tree,
597            root: contains {
598                log_sources: {
599                    "klog": {
600                        url: "fuchsia-boot://kernel",
601                        last_timestamp: AnyProperty,
602                        sockets_closed: 0u64,
603                        sockets_opened: 0u64,
604                        invalid: {
605                            number: 0u64,
606                            bytes: 0u64,
607                        },
608                        total: {
609                            number: 3u64,
610                            bytes: AnyProperty,
611                        },
612                        rolled_out: {
613                            number: 0u64,
614                            bytes: 0u64,
615                        },
616                        trace: {
617                            number: 0u64,
618                            bytes: 0u64,
619                        },
620                        debug: {
621                            number: 0u64,
622                            bytes: 0u64,
623                        },
624                        info: {
625                            number: 3u64,
626                            bytes: AnyProperty,
627                        },
628                        warn: {
629                            number: 0u64,
630                            bytes: 0u64,
631                        },
632                        error: {
633                            number: 0u64,
634                            bytes: 0u64,
635                        },
636                        fatal: {
637                            number: 0u64,
638                            bytes: 0u64,
639                        },
640                    },
641                }
642            }
643        );
644    }
645}
archivist_lib/logs/mod.rs

archivist_lib/logs/
mod.rs
