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

archivist_lib/logs/
mod.rs
