run_test_suite_lib/
diagnostics.rs

1// Copyright 2021 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
5use crate::trace::duration;
6use anyhow::Error;
7use diagnostics_data::{LogTextDisplayOptions, LogTextPresenter, LogsData, Severity};
8use fidl_fuchsia_diagnostics::LogInterestSelector;
9use fidl_fuchsia_test_manager::LogsIteratorOption;
10use futures::{Stream, TryStreamExt};
11use selectors::SelectorExt;
12use std::io::Write;
13
14/// Configuration for display of text-based (unstructured)
15/// logs.
16#[derive(Clone, Default)]
17pub(crate) struct LogDisplayConfiguration {
18    /// The minimum severity log to display.
19    pub interest: Vec<LogInterestSelector>,
20
21    /// How to format messages as text.
22    pub text_options: LogTextDisplayOptions,
23}
24
25// TODO(https://fxbug.dev/42131693, https://fxbug.dev/42149841): deprecate this when implementing metadata selectors for
26// logs or when we support automatically sending interest updates to all test components on startup.
27// We currently don't have a way of setting the interest of a test realm before creating that realm.
28#[derive(Clone, Default)]
29pub(crate) struct LogCollectionOptions {
30    /// The maximum allowed severity for logs.
31    pub max_severity: Option<Severity>,
32
33    /// Log display options for unstructured logs.
34    pub format: LogDisplayConfiguration,
35}
36
37impl LogCollectionOptions {
38    fn is_restricted_log(&self, log: &LogsData) -> bool {
39        let severity = log.metadata.severity;
40        matches!(self.max_severity, Some(max) if severity > max)
41    }
42
43    fn should_display(&self, log: &LogsData) -> bool {
44        if self.format.interest.is_empty() {
45            return true;
46        }
47        let mut found_matching_selector = false;
48        for LogInterestSelector { interest, selector } in &self.format.interest {
49            let Some(min_severity) = interest.min_severity.as_ref() else {
50                continue;
51            };
52            // The selector should already be validated so in practice this will never happen.
53            if log.moniker.matches_component_selector(&selector).unwrap_or(false) {
54                found_matching_selector = true;
55                if log.severity() >= *min_severity {
56                    return true;
57                }
58            }
59        }
60        !found_matching_selector
61    }
62}
63
64#[derive(Debug, PartialEq, Eq)]
65pub enum LogCollectionOutcome {
66    Error { restricted_logs: Vec<String> },
67    Passed,
68}
69
70impl From<Vec<String>> for LogCollectionOutcome {
71    fn from(restricted_logs: Vec<String>) -> Self {
72        if restricted_logs.is_empty() {
73            LogCollectionOutcome::Passed
74        } else {
75            LogCollectionOutcome::Error { restricted_logs }
76        }
77    }
78}
79
80/// Collects logs from |stream|, filters out low severity logs, and stores the results
81/// in |log_artifact|. Returns any high severity restricted logs that are encountered.
82pub(crate) async fn collect_logs<S, W>(
83    mut stream: S,
84    mut log_artifact: W,
85    options: LogCollectionOptions,
86) -> Result<LogCollectionOutcome, Error>
87where
88    S: Stream<Item = Result<LogsData, Error>> + Unpin,
89    W: Write,
90{
91    duration!(c"collect_logs");
92    let mut restricted_logs = vec![];
93    while let Some(log) = stream.try_next().await? {
94        duration!(c"process_single_log");
95        let is_restricted = options.is_restricted_log(&log);
96        let should_display = options.should_display(&log);
97        if !should_display && !is_restricted {
98            continue;
99        }
100
101        let log_repr = format!("{}", LogTextPresenter::new(&log, options.format.text_options));
102
103        if should_display {
104            writeln!(log_artifact, "{}", log_repr)?;
105        }
106
107        if is_restricted {
108            restricted_logs.push(log_repr);
109        }
110    }
111    Ok(restricted_logs.into())
112}
113
114#[cfg(target_os = "fuchsia")]
115pub fn get_type() -> LogsIteratorOption {
116    LogsIteratorOption::BatchIterator
117}
118
119#[cfg(not(target_os = "fuchsia"))]
120pub fn get_type() -> LogsIteratorOption {
121    LogsIteratorOption::SocketBatchIterator
122}
123
124#[cfg(test)]
125mod test {
126    use super::*;
127    use diagnostics_data::{BuilderArgs, LogsDataBuilder, Timestamp};
128    use moniker::Moniker;
129
130    #[fuchsia::test]
131    async fn filter_low_severity() {
132        let input_logs = vec![
133            LogsDataBuilder::new(BuilderArgs {
134                moniker: Moniker::root().into(),
135                timestamp: Timestamp::from_nanos(0),
136                component_url: Some("test-root-url".into()),
137                severity: Severity::Info,
138            })
139            .set_message("my info log")
140            .build(),
141            LogsDataBuilder::new(BuilderArgs {
142                moniker: "child".try_into().unwrap(),
143                timestamp: Timestamp::from_nanos(1000),
144                component_url: Some("test-child-url".into()),
145                severity: Severity::Warn,
146            })
147            .set_message("my info log")
148            .build(),
149        ];
150        let displayed_logs = vec![LogsDataBuilder::new(BuilderArgs {
151            moniker: "child".try_into().unwrap(),
152            timestamp: Timestamp::from_nanos(1000),
153            component_url: Some("test-child-url".into()),
154            severity: Severity::Warn,
155        })
156        .set_message("my info log")
157        .build()];
158
159        let mut log_artifact = vec![];
160        assert_eq!(
161            collect_logs(
162                futures::stream::iter(input_logs.into_iter().map(Ok)),
163                &mut log_artifact,
164                LogCollectionOptions {
165                    max_severity: None,
166                    format: LogDisplayConfiguration {
167                        text_options: LogTextDisplayOptions {
168                            show_full_moniker: true,
169                            ..Default::default()
170                        },
171                        interest: vec![
172                            selectors::parse_log_interest_selector_or_severity("WARN").unwrap()
173                        ],
174                    }
175                },
176            )
177            .await
178            .unwrap(),
179            LogCollectionOutcome::Passed
180        );
181        assert_eq!(
182            String::from_utf8(log_artifact).unwrap(),
183            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
184        );
185    }
186
187    #[fuchsia::test]
188    async fn filter_log_severity_by_component() {
189        let a_info_log = LogsDataBuilder::new(BuilderArgs {
190            moniker: "a".try_into().unwrap(),
191            timestamp: Timestamp::from_nanos(0),
192            component_url: Some("test-root-url".into()),
193            severity: Severity::Info,
194        })
195        .set_message("A's info log")
196        .build();
197        let a_warn_log = LogsDataBuilder::new(BuilderArgs {
198            moniker: "a".try_into().unwrap(),
199            timestamp: Timestamp::from_nanos(0),
200            component_url: Some("test-root-url".into()),
201            severity: Severity::Warn,
202        })
203        .set_message("A's warn log")
204        .build();
205        let b_info_log = LogsDataBuilder::new(BuilderArgs {
206            moniker: "b".try_into().unwrap(),
207            timestamp: Timestamp::from_nanos(0),
208            component_url: Some("test-root-url".into()),
209            severity: Severity::Info,
210        })
211        .set_message("B's info log")
212        .build();
213        let b_warn_log = LogsDataBuilder::new(BuilderArgs {
214            moniker: "b".try_into().unwrap(),
215            timestamp: Timestamp::from_nanos(0),
216            component_url: Some("test-root-url".into()),
217            severity: Severity::Warn,
218        })
219        .set_message("B's warn log")
220        .build();
221        let c_info_log = LogsDataBuilder::new(BuilderArgs {
222            moniker: "c".try_into().unwrap(),
223            timestamp: Timestamp::from_nanos(0),
224            component_url: Some("test-root-url".into()),
225            severity: Severity::Info,
226        })
227        .set_message("C's info log")
228        .build();
229
230        let input_logs = vec![
231            a_info_log,
232            a_warn_log.clone(),
233            b_info_log,
234            b_warn_log.clone(),
235            c_info_log.clone(),
236        ];
237        let displayed_logs = vec![a_warn_log, b_warn_log, c_info_log];
238
239        let mut log_artifact = vec![];
240        assert_eq!(
241            collect_logs(
242                futures::stream::iter(input_logs.into_iter().map(Ok)),
243                &mut log_artifact,
244                LogCollectionOptions {
245                    max_severity: None,
246                    format: LogDisplayConfiguration {
247                        text_options: LogTextDisplayOptions {
248                            show_full_moniker: true,
249                            ..Default::default()
250                        },
251                        interest: vec![
252                            selectors::parse_log_interest_selector_or_severity("a#WARN").unwrap(),
253                            selectors::parse_log_interest_selector_or_severity("b#WARN").unwrap(),
254                        ],
255                    }
256                },
257            )
258            .await
259            .unwrap(),
260            LogCollectionOutcome::Passed
261        );
262        assert_eq!(
263            String::from_utf8(log_artifact).unwrap(),
264            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
265        );
266    }
267
268    #[fuchsia::test]
269    async fn filter_log_severity_by_component_multiple_matches() {
270        let a_info_log = LogsDataBuilder::new(BuilderArgs {
271            moniker: "a".try_into().unwrap(),
272            timestamp: Timestamp::from_nanos(0),
273            component_url: Some("test-root-url".into()),
274            severity: Severity::Info,
275        })
276        .set_message("A's info log")
277        .build();
278        let a_warn_log = LogsDataBuilder::new(BuilderArgs {
279            moniker: "a".try_into().unwrap(),
280            timestamp: Timestamp::from_nanos(0),
281            component_url: Some("test-root-url".into()),
282            severity: Severity::Warn,
283        })
284        .set_message("A's warn log")
285        .build();
286        let b_info_log = LogsDataBuilder::new(BuilderArgs {
287            moniker: "b".try_into().unwrap(),
288            timestamp: Timestamp::from_nanos(0),
289            component_url: Some("test-root-url".into()),
290            severity: Severity::Info,
291        })
292        .set_message("B's info log")
293        .build();
294        let b_fatal_log = LogsDataBuilder::new(BuilderArgs {
295            moniker: "b".try_into().unwrap(),
296            timestamp: Timestamp::from_nanos(0),
297            component_url: Some("test-root-url".into()),
298            severity: Severity::Fatal,
299        })
300        .set_message("B's fatal log")
301        .build();
302
303        let input_logs = vec![a_info_log, a_warn_log.clone(), b_info_log, b_fatal_log.clone()];
304        let displayed_logs = vec![a_warn_log, b_fatal_log];
305
306        let mut log_artifact = vec![];
307        assert_eq!(
308            collect_logs(
309                futures::stream::iter(input_logs.into_iter().map(Ok)),
310                &mut log_artifact,
311                LogCollectionOptions {
312                    max_severity: None,
313                    format: LogDisplayConfiguration {
314                        text_options: LogTextDisplayOptions {
315                            show_full_moniker: true,
316                            ..Default::default()
317                        },
318                        interest: vec![
319                            selectors::parse_log_interest_selector_or_severity("**#FATAL").unwrap(),
320                            selectors::parse_log_interest_selector_or_severity("a#WARN").unwrap(),
321                        ],
322                    }
323                },
324            )
325            .await
326            .unwrap(),
327            LogCollectionOutcome::Passed
328        );
329        assert_eq!(
330            String::from_utf8(log_artifact).unwrap(),
331            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
332        );
333    }
334
335    #[fuchsia::test]
336    async fn filter_log_moniker() {
337        let unaltered_logs = vec![
338            LogsDataBuilder::new(BuilderArgs {
339                moniker: Moniker::root().into(),
340                timestamp: Timestamp::from_nanos(0),
341                component_url: Some("test-root-url".into()),
342                severity: Severity::Info,
343            })
344            .set_message("my info log")
345            .build(),
346            LogsDataBuilder::new(BuilderArgs {
347                moniker: "child/a".try_into().unwrap(),
348                timestamp: Timestamp::from_nanos(1000),
349                component_url: Some("test-child-url".into()),
350                severity: Severity::Warn,
351            })
352            .set_message("my warn log")
353            .build(),
354        ];
355        let altered_moniker_logs = vec![
356            LogsDataBuilder::new(BuilderArgs {
357                moniker: Moniker::root().into(),
358                timestamp: Timestamp::from_nanos(0),
359                component_url: Some("test-root-url".into()),
360                severity: Severity::Info,
361            })
362            .set_message("my info log")
363            .build(),
364            LogsDataBuilder::new(BuilderArgs {
365                moniker: "a".try_into().unwrap(),
366                timestamp: Timestamp::from_nanos(1000),
367                component_url: Some("test-child-url".into()),
368                severity: Severity::Warn,
369            })
370            .set_message("my warn log")
371            .build(),
372        ];
373
374        let mut log_artifact = vec![];
375        assert_eq!(
376            collect_logs(
377                futures::stream::iter(unaltered_logs.into_iter().map(Ok)),
378                &mut log_artifact,
379                LogCollectionOptions {
380                    max_severity: None,
381                    format: LogDisplayConfiguration {
382                        text_options: LogTextDisplayOptions {
383                            show_full_moniker: false,
384                            ..Default::default()
385                        },
386                        interest: vec![]
387                    }
388                }
389            )
390            .await
391            .unwrap(),
392            LogCollectionOutcome::Passed
393        );
394        assert_eq!(
395            String::from_utf8(log_artifact).unwrap(),
396            altered_moniker_logs
397                .iter()
398                .map(|log| format!("{}\n", LogTextPresenter::new(log, Default::default())))
399                .collect::<Vec<_>>()
400                .concat()
401        );
402    }
403
404    #[fuchsia::test]
405    async fn no_filter_log_moniker() {
406        let unaltered_logs = vec![
407            LogsDataBuilder::new(BuilderArgs {
408                moniker: ".".try_into().unwrap(),
409                timestamp: Timestamp::from_nanos(0),
410                component_url: Some("test-root-url".into()),
411                severity: Severity::Info,
412            })
413            .set_message("my info log")
414            .build(),
415            LogsDataBuilder::new(BuilderArgs {
416                moniker: "child/a".try_into().unwrap(),
417                timestamp: Timestamp::from_nanos(1000),
418                component_url: Some("test-child-url".into()),
419                severity: Severity::Warn,
420            })
421            .set_message("my warn log")
422            .build(),
423        ];
424        let altered_moniker_logs = vec![
425            LogsDataBuilder::new(BuilderArgs {
426                moniker: ".".try_into().unwrap(),
427                timestamp: Timestamp::from_nanos(0),
428                component_url: Some("test-root-url".into()),
429                severity: Severity::Info,
430            })
431            .set_message("my info log")
432            .build(),
433            LogsDataBuilder::new(BuilderArgs {
434                moniker: "child/a".try_into().unwrap(),
435                timestamp: Timestamp::from_nanos(1000),
436                component_url: Some("test-child-url".into()),
437                severity: Severity::Warn,
438            })
439            .set_message("my warn log")
440            .build(),
441        ];
442
443        let mut log_artifact = vec![];
444        assert_eq!(
445            collect_logs(
446                futures::stream::iter(unaltered_logs.into_iter().map(Ok)),
447                &mut log_artifact,
448                LogCollectionOptions {
449                    max_severity: None,
450                    format: LogDisplayConfiguration {
451                        text_options: LogTextDisplayOptions {
452                            show_full_moniker: true,
453                            ..Default::default()
454                        },
455                        interest: vec![],
456                    }
457                }
458            )
459            .await
460            .unwrap(),
461            LogCollectionOutcome::Passed
462        );
463        assert_eq!(
464            String::from_utf8(log_artifact).unwrap(),
465            altered_moniker_logs
466                .iter()
467                .map(|log| format!("{}\n", log))
468                .collect::<Vec<_>>()
469                .concat()
470        );
471    }
472
473    #[fuchsia::test]
474    async fn display_restricted_logs() {
475        let input_logs = vec![
476            LogsDataBuilder::new(BuilderArgs {
477                moniker: Moniker::root().into(),
478                timestamp: Timestamp::from_nanos(0),
479                component_url: Some("test-root-url".into()),
480                severity: Severity::Info,
481            })
482            .set_message("my info log")
483            .build(),
484            LogsDataBuilder::new(BuilderArgs {
485                moniker: "child".try_into().unwrap(),
486                timestamp: Timestamp::from_nanos(1000),
487                component_url: Some("test-child-url".into()),
488                severity: Severity::Error,
489            })
490            .set_message("my error log")
491            .build(),
492        ];
493        let displayed_logs = vec![
494            LogsDataBuilder::new(BuilderArgs {
495                moniker: Moniker::root().into(),
496                timestamp: Timestamp::from_nanos(0),
497                component_url: Some("test-root-url".into()),
498                severity: Severity::Info,
499            })
500            .set_message("my info log")
501            .build(),
502            LogsDataBuilder::new(BuilderArgs {
503                moniker: "child".try_into().unwrap(),
504                timestamp: Timestamp::from_nanos(1000),
505                component_url: Some("test-child-url".into()),
506                severity: Severity::Error,
507            })
508            .set_message("my error log")
509            .build(),
510        ];
511
512        let mut log_artifact = vec![];
513        assert_eq!(
514            collect_logs(
515                futures::stream::iter(input_logs.into_iter().map(Ok)),
516                &mut log_artifact,
517                LogCollectionOptions {
518                    max_severity: Severity::Warn.into(),
519                    format: LogDisplayConfiguration {
520                        text_options: LogTextDisplayOptions {
521                            show_full_moniker: true,
522                            ..Default::default()
523                        },
524                        interest: vec![]
525                    }
526                }
527            )
528            .await
529            .unwrap(),
530            LogCollectionOutcome::Error { restricted_logs: vec![format!("{}", displayed_logs[1])] }
531        );
532        assert_eq!(
533            String::from_utf8(log_artifact).unwrap(),
534            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
535        );
536    }
537}
run_test_suite_lib/diagnostics.rs

run_test_suite_lib/
diagnostics.rs
