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::LogsIteratorType;
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!("collect_logs");
92    let mut restricted_logs = vec![];
93    while let Some(log) = stream.try_next().await? {
94        duration!("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_logs_iterator_type() -> LogsIteratorType {
116    LogsIteratorType::Batch
117}
118
119#[cfg(not(target_os = "fuchsia"))]
120pub fn get_logs_iterator_type() -> LogsIteratorType {
121    LogsIteratorType::Socket
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![
151            LogsDataBuilder::new(BuilderArgs {
152                moniker: "child".try_into().unwrap(),
153                timestamp: Timestamp::from_nanos(1000),
154                component_url: Some("test-child-url".into()),
155                severity: Severity::Warn,
156            })
157            .set_message("my info log")
158            .build(),
159        ];
160
161        let mut log_artifact = vec![];
162        assert_eq!(
163            collect_logs(
164                futures::stream::iter(input_logs.into_iter().map(Ok)),
165                &mut log_artifact,
166                LogCollectionOptions {
167                    max_severity: None,
168                    format: LogDisplayConfiguration {
169                        text_options: LogTextDisplayOptions {
170                            show_full_moniker: true,
171                            ..Default::default()
172                        },
173                        interest: vec![
174                            selectors::parse_log_interest_selector_or_severity("WARN").unwrap()
175                        ],
176                    }
177                },
178            )
179            .await
180            .unwrap(),
181            LogCollectionOutcome::Passed
182        );
183        assert_eq!(
184            String::from_utf8(log_artifact).unwrap(),
185            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
186        );
187    }
188
189    #[fuchsia::test]
190    async fn filter_log_severity_by_component() {
191        let a_info_log = LogsDataBuilder::new(BuilderArgs {
192            moniker: "a".try_into().unwrap(),
193            timestamp: Timestamp::from_nanos(0),
194            component_url: Some("test-root-url".into()),
195            severity: Severity::Info,
196        })
197        .set_message("A's info log")
198        .build();
199        let a_warn_log = LogsDataBuilder::new(BuilderArgs {
200            moniker: "a".try_into().unwrap(),
201            timestamp: Timestamp::from_nanos(0),
202            component_url: Some("test-root-url".into()),
203            severity: Severity::Warn,
204        })
205        .set_message("A's warn log")
206        .build();
207        let b_info_log = LogsDataBuilder::new(BuilderArgs {
208            moniker: "b".try_into().unwrap(),
209            timestamp: Timestamp::from_nanos(0),
210            component_url: Some("test-root-url".into()),
211            severity: Severity::Info,
212        })
213        .set_message("B's info log")
214        .build();
215        let b_warn_log = LogsDataBuilder::new(BuilderArgs {
216            moniker: "b".try_into().unwrap(),
217            timestamp: Timestamp::from_nanos(0),
218            component_url: Some("test-root-url".into()),
219            severity: Severity::Warn,
220        })
221        .set_message("B's warn log")
222        .build();
223        let c_info_log = LogsDataBuilder::new(BuilderArgs {
224            moniker: "c".try_into().unwrap(),
225            timestamp: Timestamp::from_nanos(0),
226            component_url: Some("test-root-url".into()),
227            severity: Severity::Info,
228        })
229        .set_message("C's info log")
230        .build();
231
232        let input_logs = vec![
233            a_info_log,
234            a_warn_log.clone(),
235            b_info_log,
236            b_warn_log.clone(),
237            c_info_log.clone(),
238        ];
239        let displayed_logs = vec![a_warn_log, b_warn_log, c_info_log];
240
241        let mut log_artifact = vec![];
242        assert_eq!(
243            collect_logs(
244                futures::stream::iter(input_logs.into_iter().map(Ok)),
245                &mut log_artifact,
246                LogCollectionOptions {
247                    max_severity: None,
248                    format: LogDisplayConfiguration {
249                        text_options: LogTextDisplayOptions {
250                            show_full_moniker: true,
251                            ..Default::default()
252                        },
253                        interest: vec![
254                            selectors::parse_log_interest_selector_or_severity("a#WARN").unwrap(),
255                            selectors::parse_log_interest_selector_or_severity("b#WARN").unwrap(),
256                        ],
257                    }
258                },
259            )
260            .await
261            .unwrap(),
262            LogCollectionOutcome::Passed
263        );
264        assert_eq!(
265            String::from_utf8(log_artifact).unwrap(),
266            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
267        );
268    }
269
270    #[fuchsia::test]
271    async fn filter_log_severity_by_component_multiple_matches() {
272        let a_info_log = LogsDataBuilder::new(BuilderArgs {
273            moniker: "a".try_into().unwrap(),
274            timestamp: Timestamp::from_nanos(0),
275            component_url: Some("test-root-url".into()),
276            severity: Severity::Info,
277        })
278        .set_message("A's info log")
279        .build();
280        let a_warn_log = LogsDataBuilder::new(BuilderArgs {
281            moniker: "a".try_into().unwrap(),
282            timestamp: Timestamp::from_nanos(0),
283            component_url: Some("test-root-url".into()),
284            severity: Severity::Warn,
285        })
286        .set_message("A's warn log")
287        .build();
288        let b_info_log = LogsDataBuilder::new(BuilderArgs {
289            moniker: "b".try_into().unwrap(),
290            timestamp: Timestamp::from_nanos(0),
291            component_url: Some("test-root-url".into()),
292            severity: Severity::Info,
293        })
294        .set_message("B's info log")
295        .build();
296        let b_fatal_log = LogsDataBuilder::new(BuilderArgs {
297            moniker: "b".try_into().unwrap(),
298            timestamp: Timestamp::from_nanos(0),
299            component_url: Some("test-root-url".into()),
300            severity: Severity::Fatal,
301        })
302        .set_message("B's fatal log")
303        .build();
304
305        let input_logs = vec![a_info_log, a_warn_log.clone(), b_info_log, b_fatal_log.clone()];
306        let displayed_logs = vec![a_warn_log, b_fatal_log];
307
308        let mut log_artifact = vec![];
309        assert_eq!(
310            collect_logs(
311                futures::stream::iter(input_logs.into_iter().map(Ok)),
312                &mut log_artifact,
313                LogCollectionOptions {
314                    max_severity: None,
315                    format: LogDisplayConfiguration {
316                        text_options: LogTextDisplayOptions {
317                            show_full_moniker: true,
318                            ..Default::default()
319                        },
320                        interest: vec![
321                            selectors::parse_log_interest_selector_or_severity("**#FATAL").unwrap(),
322                            selectors::parse_log_interest_selector_or_severity("a#WARN").unwrap(),
323                        ],
324                    }
325                },
326            )
327            .await
328            .unwrap(),
329            LogCollectionOutcome::Passed
330        );
331        assert_eq!(
332            String::from_utf8(log_artifact).unwrap(),
333            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
334        );
335    }
336
337    #[fuchsia::test]
338    async fn filter_log_moniker() {
339        let unaltered_logs = vec![
340            LogsDataBuilder::new(BuilderArgs {
341                moniker: Moniker::root().into(),
342                timestamp: Timestamp::from_nanos(0),
343                component_url: Some("test-root-url".into()),
344                severity: Severity::Info,
345            })
346            .set_message("my info log")
347            .build(),
348            LogsDataBuilder::new(BuilderArgs {
349                moniker: "child/a".try_into().unwrap(),
350                timestamp: Timestamp::from_nanos(1000),
351                component_url: Some("test-child-url".into()),
352                severity: Severity::Warn,
353            })
354            .set_message("my warn log")
355            .build(),
356        ];
357        let altered_moniker_logs = vec![
358            LogsDataBuilder::new(BuilderArgs {
359                moniker: Moniker::root().into(),
360                timestamp: Timestamp::from_nanos(0),
361                component_url: Some("test-root-url".into()),
362                severity: Severity::Info,
363            })
364            .set_message("my info log")
365            .build(),
366            LogsDataBuilder::new(BuilderArgs {
367                moniker: "a".try_into().unwrap(),
368                timestamp: Timestamp::from_nanos(1000),
369                component_url: Some("test-child-url".into()),
370                severity: Severity::Warn,
371            })
372            .set_message("my warn log")
373            .build(),
374        ];
375
376        let mut log_artifact = vec![];
377        assert_eq!(
378            collect_logs(
379                futures::stream::iter(unaltered_logs.into_iter().map(Ok)),
380                &mut log_artifact,
381                LogCollectionOptions {
382                    max_severity: None,
383                    format: LogDisplayConfiguration {
384                        text_options: LogTextDisplayOptions {
385                            show_full_moniker: false,
386                            ..Default::default()
387                        },
388                        interest: vec![]
389                    }
390                }
391            )
392            .await
393            .unwrap(),
394            LogCollectionOutcome::Passed
395        );
396        assert_eq!(
397            String::from_utf8(log_artifact).unwrap(),
398            altered_moniker_logs
399                .iter()
400                .map(|log| format!(
401                    "{}\n",
402                    LogTextPresenter::new(
403                        log,
404                        LogTextDisplayOptions { show_full_moniker: false, ..Default::default() }
405                    )
406                ))
407                .collect::<Vec<_>>()
408                .concat()
409        );
410    }
411
412    #[fuchsia::test]
413    async fn no_filter_log_moniker() {
414        let unaltered_logs = vec![
415            LogsDataBuilder::new(BuilderArgs {
416                moniker: ".".try_into().unwrap(),
417                timestamp: Timestamp::from_nanos(0),
418                component_url: Some("test-root-url".into()),
419                severity: Severity::Info,
420            })
421            .set_message("my info log")
422            .build(),
423            LogsDataBuilder::new(BuilderArgs {
424                moniker: "child/a".try_into().unwrap(),
425                timestamp: Timestamp::from_nanos(1000),
426                component_url: Some("test-child-url".into()),
427                severity: Severity::Warn,
428            })
429            .set_message("my warn log")
430            .build(),
431        ];
432        let altered_moniker_logs = vec![
433            LogsDataBuilder::new(BuilderArgs {
434                moniker: ".".try_into().unwrap(),
435                timestamp: Timestamp::from_nanos(0),
436                component_url: Some("test-root-url".into()),
437                severity: Severity::Info,
438            })
439            .set_message("my info log")
440            .build(),
441            LogsDataBuilder::new(BuilderArgs {
442                moniker: "child/a".try_into().unwrap(),
443                timestamp: Timestamp::from_nanos(1000),
444                component_url: Some("test-child-url".into()),
445                severity: Severity::Warn,
446            })
447            .set_message("my warn log")
448            .build(),
449        ];
450
451        let mut log_artifact = vec![];
452        assert_eq!(
453            collect_logs(
454                futures::stream::iter(unaltered_logs.into_iter().map(Ok)),
455                &mut log_artifact,
456                LogCollectionOptions {
457                    max_severity: None,
458                    format: LogDisplayConfiguration {
459                        text_options: LogTextDisplayOptions {
460                            show_full_moniker: true,
461                            ..Default::default()
462                        },
463                        interest: vec![],
464                    }
465                }
466            )
467            .await
468            .unwrap(),
469            LogCollectionOutcome::Passed
470        );
471        assert_eq!(
472            String::from_utf8(log_artifact).unwrap(),
473            altered_moniker_logs
474                .iter()
475                .map(|log| format!("{}\n", log))
476                .collect::<Vec<_>>()
477                .concat()
478        );
479    }
480
481    #[fuchsia::test]
482    async fn display_restricted_logs() {
483        let input_logs = vec![
484            LogsDataBuilder::new(BuilderArgs {
485                moniker: Moniker::root().into(),
486                timestamp: Timestamp::from_nanos(0),
487                component_url: Some("test-root-url".into()),
488                severity: Severity::Info,
489            })
490            .set_message("my info log")
491            .build(),
492            LogsDataBuilder::new(BuilderArgs {
493                moniker: "child".try_into().unwrap(),
494                timestamp: Timestamp::from_nanos(1000),
495                component_url: Some("test-child-url".into()),
496                severity: Severity::Error,
497            })
498            .set_message("my error log")
499            .build(),
500        ];
501        let displayed_logs = vec![
502            LogsDataBuilder::new(BuilderArgs {
503                moniker: Moniker::root().into(),
504                timestamp: Timestamp::from_nanos(0),
505                component_url: Some("test-root-url".into()),
506                severity: Severity::Info,
507            })
508            .set_message("my info log")
509            .build(),
510            LogsDataBuilder::new(BuilderArgs {
511                moniker: "child".try_into().unwrap(),
512                timestamp: Timestamp::from_nanos(1000),
513                component_url: Some("test-child-url".into()),
514                severity: Severity::Error,
515            })
516            .set_message("my error log")
517            .build(),
518        ];
519
520        let mut log_artifact = vec![];
521        assert_eq!(
522            collect_logs(
523                futures::stream::iter(input_logs.into_iter().map(Ok)),
524                &mut log_artifact,
525                LogCollectionOptions {
526                    max_severity: Severity::Warn.into(),
527                    format: LogDisplayConfiguration {
528                        text_options: LogTextDisplayOptions {
529                            show_full_moniker: true,
530                            ..Default::default()
531                        },
532                        interest: vec![]
533                    }
534                }
535            )
536            .await
537            .unwrap(),
538            LogCollectionOutcome::Error { restricted_logs: vec![format!("{}", displayed_logs[1])] }
539        );
540        assert_eq!(
541            String::from_utf8(log_artifact).unwrap(),
542            displayed_logs.iter().map(|log| format!("{}\n", log)).collect::<Vec<_>>().concat()
543        );
544    }
545}
run_test_suite_lib/diagnostics.rs

run_test_suite_lib/
diagnostics.rs
