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

archivist_lib/logs/
mod.rs
