log_command/
lib.rs

1// Copyright 2023 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 anyhow::format_err;
6use argh::{ArgsInfo, FromArgs, TopLevelCommand};
7use chrono::{DateTime, Local, Utc};
8use chrono_english::{Dialect, parse_date_string};
9use component_debug::query::get_instances_from_query;
10use diagnostics_data::Severity;
11use errors::{FfxError, ffx_bail};
12use fidl_fuchsia_diagnostics::{LogInterestSelector, LogSettingsProxy};
13use fidl_fuchsia_sys2::RealmQueryProxy;
14pub use log_socket_stream::OneOrMany;
15use moniker::Moniker;
16use selectors::{SelectorExt, sanitize_moniker_for_selectors};
17use std::borrow::Cow;
18use std::io::Write;
19use std::ops::Deref;
20use std::str::FromStr;
21use std::string::FromUtf8Error;
22use std::time::Duration;
23use thiserror::Error;
24mod filter;
25mod log_formatter;
26mod log_socket_stream;
27pub use log_formatter::{
28    BootTimeAccessor, DefaultLogFormatter, FormatterError, LogData, LogEntry, Symbolize,
29    TIMESTAMP_FORMAT, Timestamp, WriterContainer, dump_logs_from_socket,
30};
31pub use log_socket_stream::{JsonDeserializeError, LogsDataStream};
32
33// Subcommand for ffx log (either watch or dump).
34#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug)]
35#[argh(subcommand)]
36pub enum LogSubCommand {
37    Watch(WatchCommand),
38    Dump(DumpCommand),
39    SetSeverity(SetSeverityCommand),
40}
41
42#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug, Default)]
43/// Sets the severity, but doesn't view any logs.
44#[argh(subcommand, name = "set-severity")]
45pub struct SetSeverityCommand {
46    /// if true, doesn't persist the interest setting
47    /// and blocks forever, keeping the connection open.
48    /// Interest settings will be reset when the command exits.
49    #[argh(switch)]
50    pub no_persist: bool,
51
52    /// if enabled, selectors will be passed directly to Archivist without any filtering.
53    /// If disabled and no matching components are found, the user will be prompted to
54    /// either enable this or be given a list of selectors to choose from.
55    #[argh(switch)]
56    pub force: bool,
57
58    /// configure the log settings on the target device for components matching
59    /// the given selector. This modifies the minimum log severity level emitted
60    /// by components during the logging session.
61    /// Specify using the format <component-selector>#<log-level>, with level
62    /// as one of FATAL|ERROR|WARN|INFO|DEBUG|TRACE.
63    /// May be repeated.
64    #[argh(positional, from_str_fn(log_interest_selector))]
65    pub interest_selector: Vec<OneOrMany<LogInterestSelector>>,
66}
67
68#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug)]
69/// Watches for and prints logs from a target. Default if no sub-command is specified.
70#[argh(subcommand, name = "watch")]
71pub struct WatchCommand {}
72
73#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug)]
74/// Dumps all log from a given target's session.
75#[argh(subcommand, name = "dump")]
76pub struct DumpCommand {}
77
78pub fn parse_time(value: &str) -> Result<DetailedDateTime, String> {
79    parse_date_string(value, Local::now(), Dialect::Us)
80        .map(|time| DetailedDateTime { time, is_now: value == "now" })
81        .map_err(|e| format!("invalid date string: {e}"))
82}
83
84/// Parses a time string that defaults to UTC. The time returned will be in the local time zone.
85pub fn parse_utc_time(value: &str) -> Result<DetailedDateTime, String> {
86    parse_date_string(value, Utc::now(), Dialect::Us)
87        .map(|time| DetailedDateTime { time: time.into(), is_now: value == "now" })
88        .map_err(|e| format!("invalid date string: {e}"))
89}
90
91/// Parses a duration from a string. The input is in seconds
92/// and the output is a Rust duration.
93pub fn parse_seconds_string_as_duration(value: &str) -> Result<Duration, String> {
94    Ok(Duration::from_secs(
95        value.parse().map_err(|e| format!("value '{value}' is not a number: {e}"))?,
96    ))
97}
98
99// Time format for displaying logs
100#[derive(Clone, Debug, PartialEq)]
101pub enum TimeFormat {
102    // UTC time
103    Utc,
104    // Local time
105    Local,
106    // Boot time
107    Boot,
108}
109
110impl std::str::FromStr for TimeFormat {
111    type Err = String;
112
113    fn from_str(s: &str) -> Result<Self, Self::Err> {
114        let lower = s.to_ascii_lowercase();
115        match lower.as_str() {
116            "local" => Ok(TimeFormat::Local),
117            "utc" => Ok(TimeFormat::Utc),
118            "boot" => Ok(TimeFormat::Boot),
119            _ => Err(format!("'{s}' is not a valid value: must be one of 'local', 'utc', 'boot'")),
120        }
121    }
122}
123
124/// Date/time structure containing a "now"
125/// field, set if it should be interpreted as the
126/// current time (used to call Subscribe instead of SnapshotThenSubscribe).
127#[derive(PartialEq, Clone, Debug)]
128pub struct DetailedDateTime {
129    /// The absolute timestamp as specified by the user
130    /// or the current timestamp if 'now' is specified.
131    pub time: DateTime<Local>,
132    /// Whether or not the DateTime was "now".
133    /// If the DateTime is "now", logs will be collected in subscribe
134    /// mode, instead of SnapshotThenSubscribe.
135    pub is_now: bool,
136}
137
138impl Deref for DetailedDateTime {
139    type Target = DateTime<Local>;
140
141    fn deref(&self) -> &Self::Target {
142        &self.time
143    }
144}
145
146#[derive(Clone, PartialEq, Debug)]
147pub enum SymbolizeMode {
148    /// Disable all symbolization
149    Off,
150    /// Use prettified symbolization
151    Pretty,
152    /// Use classic (non-prettified) symbolization
153    Classic,
154}
155
156impl SymbolizeMode {
157    pub fn is_prettification_disabled(&self) -> bool {
158        matches!(self, SymbolizeMode::Classic)
159    }
160
161    pub fn is_symbolize_disabled(&self) -> bool {
162        matches!(self, SymbolizeMode::Off)
163    }
164}
165
166#[derive(ArgsInfo, FromArgs, Clone, Debug, PartialEq)]
167#[argh(
168    subcommand,
169    name = "log",
170    description = "Display logs from a target device",
171    note = "Logs are retrieve from the target at the moment this command is called.
172
173You may see some additional information attached to the log line:
174
175- `dropped=N`: this means that N logs attributed to the component were dropped when the component
176  wrote to the log socket. This can happen when archivist cannot keep up with the rate of logs being
177  emitted by the component and the component filled the log socket buffer in the kernel.
178
179- `rolled=N`: this means that N logs rolled out from the archivist buffer and ffx never saw them.
180  This can happen when more logs are being ingested by the archivist across all components and the
181  ffx couldn't retrieve them fast enough.
182
183Symbolization is performed in the background using the symbolizer host tool. You can pass
184additional arguments to the symbolizer tool (for example, to add a remote symbol server) using:
185  $ ffx config set proactive_log.symbolize.extra_args \"--symbol-server gs://some-url/path --symbol-server gs://some-other-url/path ...\"
186
187To learn more about configuring the log viewer, visit https://fuchsia.dev/fuchsia-src/development/tools/ffx/commands/log",
188    example = "\
189Dump the most recent logs and stream new ones as they happen:
190  $ ffx log
191
192Stream new logs starting from the current time, filtering for severity of at least \"WARN\":
193  $ ffx log --severity warn --since now
194
195Stream logs where the source moniker, component url and message do not include \"sys\":
196  $ ffx log --exclude sys
197
198Stream ERROR logs with source moniker, component url or message containing either
199\"netstack\" or \"remote-control.cm\", but not containing \"sys\":
200  $ ffx log --severity error --filter netstack --filter remote-control.cm --exclude sys
201
202Dump all available logs where the source moniker, component url, or message contains
203\"remote-control\":
204  $ ffx log --filter remote-control dump
205
206Dump all logs from the last 30 minutes logged before 5 minutes ago:
207  $ ffx log --since \"30m ago\" --until \"5m ago\" dump
208
209Enable DEBUG logs from the \"core/audio\" component while logs are streaming:
210  $ ffx log --set-severity core/audio#DEBUG"
211)]
212pub struct LogCommand {
213    #[argh(subcommand)]
214    pub sub_command: Option<LogSubCommand>,
215
216    /// filter for a string in either the message, component or url.
217    /// May be repeated.
218    #[argh(option)]
219    pub filter: Vec<String>,
220
221    /// DEPRECATED: use --component
222    #[argh(option)]
223    pub moniker: Vec<String>,
224
225    /// fuzzy search for a component by moniker or url.
226    /// May be repeated.
227    #[argh(option)]
228    pub component: Vec<String>,
229
230    /// exclude a string in either the message, component or url.
231    /// May be repeated.
232    #[argh(option)]
233    pub exclude: Vec<String>,
234
235    /// filter for only logs with a given tag. May be repeated.
236    #[argh(option)]
237    pub tag: Vec<String>,
238
239    /// exclude logs with a given tag. May be repeated.
240    #[argh(option)]
241    pub exclude_tags: Vec<String>,
242
243    /// set the minimum severity. Accepted values (from lower to higher) are: trace, debug, info,
244    /// warn (or warning), error, fatal. This field is case insensitive.
245    #[argh(option, default = "Severity::Info")]
246    pub severity: Severity,
247
248    /// outputs only kernel logs, unless combined with --component.
249    #[argh(switch)]
250    pub kernel: bool,
251
252    /// show only logs after a certain time (exclusive)
253    #[argh(option, from_str_fn(parse_time))]
254    pub since: Option<DetailedDateTime>,
255
256    /// show only logs after a certain time (as a boot
257    /// timestamp: seconds from the target's boot time).
258    #[argh(option, from_str_fn(parse_seconds_string_as_duration))]
259    pub since_boot: Option<Duration>,
260
261    /// show only logs until a certain time (exclusive)
262    #[argh(option, from_str_fn(parse_time))]
263    pub until: Option<DetailedDateTime>,
264
265    /// show only logs until a certain time (as a a boot
266    /// timestamp: seconds since the target's boot time).
267    #[argh(option, from_str_fn(parse_seconds_string_as_duration))]
268    pub until_boot: Option<Duration>,
269
270    /// hide the tag field from output (does not exclude any log messages)
271    #[argh(switch)]
272    pub hide_tags: bool,
273
274    /// hide the file and line number field from output (does not exclude any log messages)
275    #[argh(switch)]
276    pub hide_file: bool,
277
278    /// disable coloring logs according to severity.
279    /// Note that you can permanently disable this with
280    /// `ffx config set log_cmd.color false`
281    #[argh(switch)]
282    pub no_color: bool,
283
284    /// if enabled, text filtering options are case-sensitive
285    /// this applies to --filter, --exclude, --tag, and --exclude-tag.
286    #[argh(switch)]
287    pub case_sensitive: bool,
288
289    /// shows process-id and thread-id in log output
290    #[argh(switch)]
291    pub show_metadata: bool,
292
293    /// shows the full moniker in log output. By default this is false and only the last segment
294    /// of the moniker is printed.
295    #[argh(switch)]
296    pub show_full_moniker: bool,
297
298    /// how to display log timestamps.
299    /// Options are "utc", "local", or "boot" (i.e. nanos since target boot).
300    /// Default is boot.
301    #[argh(option, default = "TimeFormat::Boot")]
302    pub clock: TimeFormat,
303
304    /// configure symbolization options. Valid options are:
305    /// - pretty (default): pretty concise symbolization
306    /// - off: disables all symbolization
307    /// - classic: traditional, non-prettified symbolization
308    #[cfg(not(target_os = "fuchsia"))]
309    #[argh(option, default = "SymbolizeMode::Pretty")]
310    pub symbolize: SymbolizeMode,
311
312    /// configure the log settings on the target device for components matching
313    /// the given selector. This modifies the minimum log severity level emitted
314    /// by components during the logging session.
315    /// Specify using the format <component-selector>#<log-level>, with level
316    /// as one of FATAL|ERROR|WARN|INFO|DEBUG|TRACE.
317    /// May be repeated and it's also possible to pass multiple comma-separated
318    /// strings per invocation.
319    /// Cannot be used in conjunction with --set-severity-persist.
320    #[argh(option, from_str_fn(log_interest_selector))]
321    pub set_severity: Vec<OneOrMany<LogInterestSelector>>,
322
323    /// filters by pid
324    #[argh(option)]
325    pub pid: Option<u64>,
326
327    /// filters by tid
328    #[argh(option)]
329    pub tid: Option<u64>,
330
331    /// if enabled, selectors will be passed directly to Archivist without any filtering.
332    /// If disabled and no matching components are found, the user will be prompted to
333    /// either enable this or be given a list of selectors to choose from.
334    /// This applies to both --set-severity and --set-severity-persist.
335    #[argh(switch)]
336    pub force_set_severity: bool,
337
338    /// enables structured JSON logs.
339    #[cfg(target_os = "fuchsia")]
340    #[argh(switch)]
341    pub json: bool,
342
343    /// disable automatic reconnect
344    #[cfg(not(target_os = "fuchsia"))]
345    #[argh(switch)]
346    pub disable_reconnect: bool,
347}
348
349impl Default for LogCommand {
350    fn default() -> Self {
351        LogCommand {
352            filter: vec![],
353            moniker: vec![],
354            component: vec![],
355            exclude: vec![],
356            tag: vec![],
357            exclude_tags: vec![],
358            hide_tags: false,
359            hide_file: false,
360            clock: TimeFormat::Boot,
361            no_color: false,
362            kernel: false,
363            severity: Severity::Info,
364            show_metadata: false,
365            force_set_severity: false,
366            since: None,
367            since_boot: None,
368            until: None,
369            case_sensitive: false,
370            until_boot: None,
371            sub_command: None,
372            set_severity: vec![],
373            show_full_moniker: false,
374            pid: None,
375            tid: None,
376            #[cfg(target_os = "fuchsia")]
377            json: false,
378            #[cfg(not(target_os = "fuchsia"))]
379            disable_reconnect: false,
380            #[cfg(not(target_os = "fuchsia"))]
381            symbolize: SymbolizeMode::Pretty,
382        }
383    }
384}
385
386/// Result returned from processing logs
387#[derive(PartialEq, Debug)]
388pub enum LogProcessingResult {
389    /// The caller should exit
390    Exit,
391    /// The caller should continue processing logs
392    Continue,
393}
394
395impl FromStr for SymbolizeMode {
396    type Err = anyhow::Error;
397
398    fn from_str(s: &str) -> Result<Self, Self::Err> {
399        let s = s.to_lowercase();
400        match s.as_str() {
401            "off" => Ok(SymbolizeMode::Off),
402            "pretty" => Ok(SymbolizeMode::Pretty),
403            "classic" => Ok(SymbolizeMode::Classic),
404            other => Err(format_err!("invalid symbolize flag: {}", other)),
405        }
406    }
407}
408
409#[derive(Error, Debug)]
410pub enum LogError {
411    #[error(transparent)]
412    UnknownError(#[from] anyhow::Error),
413    #[error("No boot timestamp")]
414    NoBootTimestamp,
415    #[error(transparent)]
416    IOError(#[from] std::io::Error),
417    #[error("Cannot use dump with --since now")]
418    DumpWithSinceNow,
419    #[error("No symbolizer configuration provided")]
420    NoSymbolizerConfig,
421    #[error(transparent)]
422    FfxError(#[from] FfxError),
423    #[error(transparent)]
424    Utf8Error(#[from] FromUtf8Error),
425    #[error(transparent)]
426    FidlError(#[from] fidl::Error),
427    #[error(transparent)]
428    FormatterError(#[from] FormatterError),
429    #[error("Deprecated flag: `{flag}`, use: `{new_flag}`")]
430    DeprecatedFlag { flag: &'static str, new_flag: &'static str },
431    #[error("Fuzzy matching failed due to too many matches, please re-try with one of these:\n{0}")]
432    FuzzyMatchTooManyMatches(String),
433    #[error("No running components were found matching {0}")]
434    SearchParameterNotFound(String),
435}
436
437impl LogError {
438    fn too_many_fuzzy_matches(matches: impl Iterator<Item = String>) -> Self {
439        let mut result = String::new();
440        for component in matches {
441            result.push_str(&component);
442            result.push('\n');
443        }
444
445        Self::FuzzyMatchTooManyMatches(result)
446    }
447}
448
449/// Trait used to get available instances given a moniker query.
450#[async_trait::async_trait(?Send)]
451pub trait InstanceGetter {
452    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError>;
453}
454
455#[async_trait::async_trait(?Send)]
456impl InstanceGetter for RealmQueryProxy {
457    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
458        Ok(get_instances_from_query(query, self)
459            .await?
460            .into_iter()
461            .map(|value| value.moniker)
462            .collect())
463    }
464}
465
466impl LogCommand {
467    async fn map_interest_selectors<'a>(
468        realm_query: &impl InstanceGetter,
469        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
470    ) -> Result<impl Iterator<Item = Cow<'a, LogInterestSelector>>, LogError> {
471        let selectors = Self::get_selectors_and_monikers(interest_selectors);
472        let mut translated_selectors = vec![];
473        for (moniker, selector) in selectors {
474            // Attempt to translate to a single instance
475            let instances = realm_query.get_monikers_from_query(moniker.as_str()).await?;
476            // If exactly one match, perform rewrite
477            if instances.len() == 1 {
478                let mut translated_selector = selector.clone();
479                translated_selector.selector = instances[0].clone().into_component_selector();
480                translated_selectors.push((Cow::Owned(translated_selector), instances));
481            } else {
482                translated_selectors.push((Cow::Borrowed(selector), instances));
483            }
484        }
485        if translated_selectors.iter().any(|(_, matches)| matches.len() > 1) {
486            let mut err_output = vec![];
487            writeln!(
488                &mut err_output,
489                "WARN: One or more of your selectors appears to be ambiguous"
490            )?;
491            writeln!(&mut err_output, "and may not match any components on your system.\n")?;
492            writeln!(
493                &mut err_output,
494                "If this is unintentional you can explicitly match using the"
495            )?;
496            writeln!(&mut err_output, "following command:\n")?;
497            writeln!(&mut err_output, "ffx log \\")?;
498            let mut output = vec![];
499            for (oselector, instances) in translated_selectors {
500                for selector in instances {
501                    writeln!(
502                        output,
503                        "\t--set-severity {}#{} \\",
504                        sanitize_moniker_for_selectors(selector.to_string().as_str())
505                            .replace("\\", "\\\\"),
506                        format!("{:?}", oselector.interest.min_severity.unwrap()).to_uppercase()
507                    )?;
508                }
509            }
510            // Intentionally ignored, removes the newline, space, and \
511            let _ = output.pop();
512            let _ = output.pop();
513            let _ = output.pop();
514
515            writeln!(&mut err_output, "{}", String::from_utf8(output).unwrap())?;
516            writeln!(&mut err_output, "\nIf this is intentional, you can disable this with")?;
517            writeln!(&mut err_output, "ffx log --force-set-severity.")?;
518
519            ffx_bail!("{}", String::from_utf8(err_output)?);
520        }
521        Ok(translated_selectors.into_iter().map(|(selector, _)| selector))
522    }
523
524    pub fn validate_cmd_flags_with_warnings(&mut self) -> Result<Vec<&'static str>, LogError> {
525        let mut warnings = vec![];
526
527        if !self.moniker.is_empty() {
528            warnings.push("WARNING: --moniker is deprecated, use --component instead");
529            if self.component.is_empty() {
530                self.component = std::mem::take(&mut self.moniker);
531            } else {
532                warnings.push("WARNING: ignoring --moniker arguments in favor of --component");
533            }
534        }
535
536        Ok(warnings)
537    }
538
539    /// Sets interest based on configured selectors.
540    /// If a single ambiguous match is found, the monikers in the selectors
541    /// are automatically re-written.
542    pub async fn maybe_set_interest(
543        &self,
544        log_settings_client: &LogSettingsProxy,
545        realm_query: &impl InstanceGetter,
546    ) -> Result<(), LogError> {
547        let (set_severity, force_set_severity, persist) =
548            if let Some(LogSubCommand::SetSeverity(options)) = &self.sub_command {
549                // No other argument can exist in conjunction with SetSeverity
550                let default_cmd = LogCommand {
551                    sub_command: Some(LogSubCommand::SetSeverity(options.clone())),
552                    ..Default::default()
553                };
554                if &default_cmd != self {
555                    ffx_bail!("Cannot combine set-severity with other options.");
556                }
557                (&options.interest_selector, options.force, !options.no_persist)
558            } else {
559                (&self.set_severity, self.force_set_severity, false)
560            };
561        if persist {
562            let selectors = if force_set_severity {
563                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
564            } else {
565                let new_selectors =
566                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
567                        .await?
568                        .map(|s| s.into_owned())
569                        .collect::<Vec<_>>();
570                if new_selectors.is_empty() {
571                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
572                } else {
573                    new_selectors
574                }
575            };
576            log_settings_client
577                .set_component_interest(
578                    &fidl_fuchsia_diagnostics::LogSettingsSetComponentInterestRequest {
579                        selectors: Some(selectors),
580                        persist: Some(true),
581                        ..Default::default()
582                    },
583                )
584                .await?;
585        } else if !set_severity.is_empty() {
586            let selectors = if force_set_severity {
587                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
588            } else {
589                let new_selectors =
590                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
591                        .await?
592                        .map(|s| s.into_owned())
593                        .collect::<Vec<_>>();
594                if new_selectors.is_empty() {
595                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
596                } else {
597                    new_selectors
598                }
599            };
600
601            log_settings_client.set_interest(&selectors).await?;
602        }
603
604        Ok(())
605    }
606
607    fn get_selectors_and_monikers<'a>(
608        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
609    ) -> Vec<(String, &'a LogInterestSelector)> {
610        let mut selectors = vec![];
611        for selector in interest_selectors {
612            let segments = selector.selector.moniker_segments.as_ref().unwrap();
613            let mut full_moniker = String::new();
614            for segment in segments {
615                match segment {
616                    fidl_fuchsia_diagnostics::StringSelector::ExactMatch(segment) => {
617                        if full_moniker.is_empty() {
618                            full_moniker.push_str(segment);
619                        } else {
620                            full_moniker.push('/');
621                            full_moniker.push_str(segment);
622                        }
623                    }
624                    _ => {
625                        // If the user passed a non-exact match we assume they
626                        // know what they're doing and skip this logic.
627                        return vec![];
628                    }
629                }
630            }
631            selectors.push((full_moniker, selector));
632        }
633        selectors
634    }
635}
636
637impl TopLevelCommand for LogCommand {}
638
639fn log_interest_selector(s: &str) -> Result<OneOrMany<LogInterestSelector>, String> {
640    if s.contains(",") {
641        let many: Result<Vec<LogInterestSelector>, String> = s
642            .split(",")
643            .map(|value| selectors::parse_log_interest_selector(value).map_err(|e| e.to_string()))
644            .collect();
645        Ok(OneOrMany::Many(many?))
646    } else {
647        Ok(OneOrMany::One(selectors::parse_log_interest_selector(s).map_err(|s| s.to_string())?))
648    }
649}
650
651#[cfg(test)]
652mod test {
653    use super::*;
654    use assert_matches::assert_matches;
655    use async_trait::async_trait;
656    use fidl::endpoints::create_proxy;
657    use fidl_fuchsia_diagnostics::{LogSettingsMarker, LogSettingsRequest};
658    use futures_util::StreamExt;
659    use futures_util::future::Either;
660    use futures_util::stream::FuturesUnordered;
661    use selectors::parse_log_interest_selector;
662
663    #[derive(Default)]
664    struct FakeInstanceGetter {
665        output: Vec<Moniker>,
666        expected_selector: Option<String>,
667    }
668
669    #[async_trait(?Send)]
670    impl InstanceGetter for FakeInstanceGetter {
671        async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
672            if let Some(expected) = &self.expected_selector {
673                assert_eq!(expected, query);
674            }
675            Ok(self.output.clone())
676        }
677    }
678
679    #[fuchsia::test]
680    async fn test_symbolize_mode_from_str() {
681        assert_matches!(SymbolizeMode::from_str("off"), Ok(value) if value == SymbolizeMode::Off);
682        assert_matches!(
683            SymbolizeMode::from_str("pretty"),
684            Ok(value) if value == SymbolizeMode::Pretty
685        );
686        assert_matches!(
687            SymbolizeMode::from_str("classic"),
688            Ok(value) if value == SymbolizeMode::Classic
689        );
690    }
691
692    #[fuchsia::test]
693    async fn maybe_set_interest_errors_additional_arguments_passed_to_set_interest() {
694        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
695        let getter = FakeInstanceGetter {
696            expected_selector: Some("ambiguous_selector".into()),
697            output: vec![
698                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
699                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
700            ],
701        };
702        // Main should return an error
703
704        let cmd = LogCommand {
705            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
706                interest_selector: vec![OneOrMany::One(
707                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
708                )],
709                force: false,
710                no_persist: false,
711            })),
712            hide_file: true,
713            ..LogCommand::default()
714        };
715        let mut set_interest_result = None;
716
717        let mut scheduler = FuturesUnordered::new();
718        scheduler.push(Either::Left(async {
719            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
720            drop(settings_proxy);
721        }));
722        scheduler.push(Either::Right(async {
723            let request = settings_server.into_stream().next().await;
724            // The channel should be closed without sending any requests.
725            assert_matches!(request, None);
726        }));
727        while scheduler.next().await.is_some() {}
728        drop(scheduler);
729
730        let error = format!("{}", set_interest_result.unwrap().unwrap_err());
731
732        const EXPECTED_INTEREST_ERROR: &str = "Cannot combine set-severity with other options.";
733        assert_eq!(error, EXPECTED_INTEREST_ERROR);
734    }
735
736    #[fuchsia::test]
737    async fn maybe_set_interest_errors_if_ambiguous_selector() {
738        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
739        let getter = FakeInstanceGetter {
740            expected_selector: Some("ambiguous_selector".into()),
741            output: vec![
742                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
743                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
744            ],
745        };
746        // Main should return an error
747
748        let cmd = LogCommand {
749            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
750            set_severity: vec![OneOrMany::One(
751                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
752            )],
753            ..LogCommand::default()
754        };
755        let mut set_interest_result = None;
756
757        let mut scheduler = FuturesUnordered::new();
758        scheduler.push(Either::Left(async {
759            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
760            drop(settings_proxy);
761        }));
762        scheduler.push(Either::Right(async {
763            let request = settings_server.into_stream().next().await;
764            // The channel should be closed without sending any requests.
765            assert_matches!(request, None);
766        }));
767        while scheduler.next().await.is_some() {}
768        drop(scheduler);
769
770        let error = format!("{}", set_interest_result.unwrap().unwrap_err());
771
772        const EXPECTED_INTEREST_ERROR: &str = r#"WARN: One or more of your selectors appears to be ambiguous
773and may not match any components on your system.
774
775If this is unintentional you can explicitly match using the
776following command:
777
778ffx log \
779	--set-severity core/some/ambiguous_selector\\:thing/test#INFO \
780	--set-severity core/other/ambiguous_selector\\:thing/test#INFO
781
782If this is intentional, you can disable this with
783ffx log --force-set-severity.
784"#;
785        assert_eq!(error, EXPECTED_INTEREST_ERROR);
786    }
787
788    #[fuchsia::test]
789    async fn logger_translates_selector_if_one_match() {
790        let cmd = LogCommand {
791            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
792            set_severity: vec![OneOrMany::One(
793                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
794            )],
795            ..LogCommand::default()
796        };
797        let mut set_interest_result = None;
798        let getter = FakeInstanceGetter {
799            expected_selector: Some("ambiguous_selector".into()),
800            output: vec![Moniker::try_from("core/some/ambiguous_selector").unwrap()],
801        };
802        let mut scheduler = FuturesUnordered::new();
803        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
804        scheduler.push(Either::Left(async {
805            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
806            drop(settings_proxy);
807        }));
808        scheduler.push(Either::Right(async {
809            let request = settings_server.into_stream().next().await;
810            let (selectors, responder) = assert_matches!(
811                request,
812                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
813                (selectors, responder)
814            );
815            responder.send().unwrap();
816            assert_eq!(
817                selectors,
818                vec![parse_log_interest_selector("core/some/ambiguous_selector#INFO").unwrap()]
819            );
820        }));
821        while scheduler.next().await.is_some() {}
822        drop(scheduler);
823        assert_matches!(set_interest_result, Some(Ok(())));
824    }
825
826    #[fuchsia::test]
827    async fn logger_uses_specified_selectors_if_no_results_returned() {
828        let cmd = LogCommand {
829            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
830            set_severity: vec![OneOrMany::One(
831                parse_log_interest_selector("core/something/a:b/elements:main/otherstuff:*#DEBUG")
832                    .unwrap(),
833            )],
834            ..LogCommand::default()
835        };
836        let mut set_interest_result = None;
837        let getter = FakeInstanceGetter {
838            expected_selector: Some("core/something/a:b/elements:main/otherstuff:*#DEBUG".into()),
839            output: vec![],
840        };
841        let scheduler = FuturesUnordered::new();
842        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
843        scheduler.push(Either::Left(async {
844            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
845            drop(settings_proxy);
846        }));
847        scheduler.push(Either::Right(async {
848            let request = settings_server.into_stream().next().await;
849            let (selectors, responder) = assert_matches!(
850                request,
851                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
852                (selectors, responder)
853            );
854            responder.send().unwrap();
855            assert_eq!(
856                selectors,
857                vec![
858                    parse_log_interest_selector(
859                        "core/something/a:b/elements:main/otherstuff:*#DEBUG"
860                    )
861                    .unwrap()
862                ]
863            );
864        }));
865        scheduler.map(|_| Ok(())).forward(futures::sink::drain()).await.unwrap();
866        assert_matches!(set_interest_result, Some(Ok(())));
867    }
868
869    #[fuchsia::test]
870    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used() {
871        let cmd = LogCommand {
872            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
873                no_persist: true,
874                interest_selector: vec![OneOrMany::One(
875                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
876                )],
877                force: true,
878            })),
879            ..LogCommand::default()
880        };
881        let getter = FakeInstanceGetter {
882            expected_selector: Some("ambiguous_selector".into()),
883            output: vec![
884                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
885                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
886            ],
887        };
888        let mut set_interest_result = None;
889        let mut scheduler = FuturesUnordered::new();
890        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
891        scheduler.push(Either::Left(async {
892            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
893            drop(settings_proxy);
894        }));
895        scheduler.push(Either::Right(async {
896            let request = settings_server.into_stream().next().await;
897            let (selectors, responder) = assert_matches!(
898                request,
899                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
900                (selectors, responder)
901            );
902            responder.send().unwrap();
903            assert_eq!(
904                selectors,
905                vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()]
906            );
907        }));
908        while scheduler.next().await.is_some() {}
909        drop(scheduler);
910        assert_matches!(set_interest_result, Some(Ok(())));
911    }
912
913    #[fuchsia::test]
914    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used_persistent() {
915        let cmd = LogCommand {
916            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
917                no_persist: false,
918                interest_selector: vec![log_socket_stream::OneOrMany::One(
919                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
920                )],
921                force: true,
922            })),
923            ..LogCommand::default()
924        };
925        let getter = FakeInstanceGetter {
926            expected_selector: Some("ambiguous_selector".into()),
927            output: vec![
928                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
929                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
930            ],
931        };
932        let mut set_interest_result = None;
933        let mut scheduler = FuturesUnordered::new();
934        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
935        scheduler.push(Either::Left(async {
936            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
937            drop(settings_proxy);
938        }));
939        scheduler.push(Either::Right(async {
940            let request = settings_server.into_stream().next().await;
941            let (payload, responder) = assert_matches!(
942                request,
943                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
944                (payload, responder)
945            );
946            assert_eq!(payload.persist, Some(true));
947            responder.send().unwrap();
948            assert_eq!(
949                payload.selectors.unwrap(),
950                vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()]
951            );
952        }));
953        while scheduler.next().await.is_some() {}
954        drop(scheduler);
955        assert_matches!(set_interest_result, Some(Ok(())));
956    }
957
958    #[fuchsia::test]
959    async fn logger_prints_ignores_ambiguity_if_machine_output_is_used() {
960        let cmd = LogCommand {
961            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
962            set_severity: vec![OneOrMany::One(
963                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
964            )],
965            force_set_severity: true,
966            ..LogCommand::default()
967        };
968        let getter = FakeInstanceGetter {
969            expected_selector: Some("ambiguous_selector".into()),
970            output: vec![
971                Moniker::try_from("core/some/collection:thing/test").unwrap(),
972                Moniker::try_from("core/other/collection:thing/test").unwrap(),
973            ],
974        };
975        let mut set_interest_result = None;
976        let mut scheduler = FuturesUnordered::new();
977        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
978        scheduler.push(Either::Left(async {
979            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
980            drop(settings_proxy);
981        }));
982        scheduler.push(Either::Right(async {
983            let request = settings_server.into_stream().next().await;
984            let (selectors, responder) = assert_matches!(
985                request,
986                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
987                (selectors, responder)
988            );
989            responder.send().unwrap();
990            assert_eq!(
991                selectors,
992                vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()]
993            );
994        }));
995        while scheduler.next().await.is_some() {}
996        drop(scheduler);
997        assert_matches!(set_interest_result, Some(Ok(())));
998    }
999    #[test]
1000    fn test_parse_selector() {
1001        assert_eq!(
1002            log_interest_selector("core/audio#DEBUG").unwrap(),
1003            OneOrMany::One(parse_log_interest_selector("core/audio#DEBUG").unwrap())
1004        );
1005    }
1006
1007    #[test]
1008    fn test_parse_selector_with_commas() {
1009        assert_eq!(
1010            log_interest_selector("core/audio#DEBUG,bootstrap/archivist#TRACE").unwrap(),
1011            OneOrMany::Many(vec![
1012                parse_log_interest_selector("core/audio#DEBUG").unwrap(),
1013                parse_log_interest_selector("bootstrap/archivist#TRACE").unwrap()
1014            ])
1015        );
1016    }
1017
1018    #[test]
1019    fn test_parse_time() {
1020        assert!(parse_time("now").unwrap().is_now);
1021        let date_string = "04/20/2020";
1022        let res = parse_time(date_string).unwrap();
1023        assert!(!res.is_now);
1024        assert_eq!(
1025            res.date_naive(),
1026            parse_date_string(date_string, Local::now(), Dialect::Us).unwrap().date_naive()
1027        );
1028    }
1029}
log_command/lib.rs

log_command/
lib.rs
