log_command/

lib.rs

// Copyright 2023 The Fuchsia Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.

use anyhow::format_err;
use argh::{ArgsInfo, FromArgs, TopLevelCommand};
use chrono::{DateTime, Local};
use chrono_english::{parse_date_string, Dialect};
use component_debug::query::get_instances_from_query;
use diagnostics_data::Severity;
use errors::{ffx_bail, FfxError};
use fidl_fuchsia_diagnostics::{LogInterestSelector, LogSettingsProxy};
use fidl_fuchsia_sys2::RealmQueryProxy;
pub use log_socket_stream::OneOrMany;
use moniker::Moniker;
use selectors::{sanitize_moniker_for_selectors, SelectorExt};
use std::borrow::Cow;
use std::io::Write;
use std::ops::Deref;
use std::str::FromStr;
use std::string::FromUtf8Error;
use std::time::Duration;
use thiserror::Error;
mod filter;
mod log_formatter;
mod log_socket_stream;
pub use log_formatter::{
    dump_logs_from_socket, BootTimeAccessor, DefaultLogFormatter, FormatterError, LogData,
    LogEntry, Symbolize, Timestamp, WriterContainer, TIMESTAMP_FORMAT,
};
pub use log_socket_stream::{JsonDeserializeError, LogsDataStream};

// Subcommand for ffx log (either watch or dump).
#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug)]
#[argh(subcommand)]
pub enum LogSubCommand {
    Watch(WatchCommand),
    Dump(DumpCommand),
    SetSeverity(SetSeverityCommand),
}

#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug, Default)]
/// Sets the severity, but doesn't view any logs.
#[argh(subcommand, name = "set-severity")]
pub struct SetSeverityCommand {
    /// if true, doesn't persist the interest setting
    /// and blocks forever, keeping the connection open.
    /// Interest settings will be reset when the command exits.
    #[argh(switch)]
    pub no_persist: bool,

    /// if enabled, selectors will be passed directly to Archivist without any filtering.
    /// If disabled and no matching components are found, the user will be prompted to
    /// either enable this or be given a list of selectors to choose from.
    #[argh(switch)]
    pub force: bool,

    /// configure the log settings on the target device for components matching
    /// the given selector. This modifies the minimum log severity level emitted
    /// by components during the logging session.
    /// Specify using the format <component-selector>#<log-level>, with level
    /// as one of FATAL|ERROR|WARN|INFO|DEBUG|TRACE.
    /// May be repeated.
    #[argh(positional, from_str_fn(log_interest_selector))]
    pub interest_selector: Vec<OneOrMany<LogInterestSelector>>,
}

#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug)]
/// Watches for and prints logs from a target. Default if no sub-command is specified.
#[argh(subcommand, name = "watch")]
pub struct WatchCommand {}

#[derive(ArgsInfo, FromArgs, Clone, PartialEq, Debug)]
/// Dumps all log from a given target's session.
#[argh(subcommand, name = "dump")]
pub struct DumpCommand {}

pub fn parse_time(value: &str) -> Result<DetailedDateTime, String> {
    parse_date_string(value, Local::now(), Dialect::Us)
        .map(|time| DetailedDateTime { time, is_now: value == "now" })
        .map_err(|e| format!("invalid date string: {}", e))
}

/// Parses a duration from a string. The input is in seconds
/// and the output is a Rust duration.
pub fn parse_seconds_string_as_duration(value: &str) -> Result<Duration, String> {
    Ok(Duration::from_secs(
        value.parse().map_err(|e| format!("value '{}' is not a number: {}", value, e))?,
    ))
}

// Time format for displaying logs
#[derive(Clone, Debug, PartialEq)]
pub enum TimeFormat {
    // UTC time
    Utc,
    // Local time
    Local,
    // Boot time
    Boot,
}

impl std::str::FromStr for TimeFormat {
    type Err = String;

    fn from_str(s: &str) -> Result<Self, Self::Err> {
        let lower = s.to_ascii_lowercase();
        match lower.as_str() {
            "local" => Ok(TimeFormat::Local),
            "utc" => Ok(TimeFormat::Utc),
            "boot" => Ok(TimeFormat::Boot),
            _ => {
                Err(format!("'{}' is not a valid value: must be one of 'local', 'utc', 'boot'", s))
            }
        }
    }
}

/// Date/time structure containing a "now"
/// field, set if it should be interpreted as the
/// current time (used to call Subscribe instead of SnapshotThenSubscribe).
#[derive(PartialEq, Clone, Debug)]
pub struct DetailedDateTime {
    /// The absolute timestamp as specified by the user
    /// or the current timestamp if 'now' is specified.
    pub time: DateTime<Local>,
    /// Whether or not the DateTime was "now".
    /// If the DateTime is "now", logs will be collected in subscribe
    /// mode, instead of SnapshotThenSubscribe.
    pub is_now: bool,
}

impl Deref for DetailedDateTime {
    type Target = DateTime<Local>;

    fn deref(&self) -> &Self::Target {
        &self.time
    }
}

#[derive(Clone, PartialEq, Debug)]
pub enum SymbolizeMode {
    /// Disable all symbolization
    Off,
    /// Use prettified symbolization
    Pretty,
    /// Use classic (non-prettified) symbolization
    Classic,
}

impl SymbolizeMode {
    pub fn is_prettification_disabled(&self) -> bool {
        matches!(self, SymbolizeMode::Classic)
    }

    pub fn is_symbolize_disabled(&self) -> bool {
        matches!(self, SymbolizeMode::Off)
    }
}

#[derive(ArgsInfo, FromArgs, Clone, Debug, PartialEq)]
#[argh(
    subcommand,
    name = "log",
    description = "Display logs from a target device",
    note = "Logs are retrieve from the target at the moment this command is called.

You may see some additional information attached to the log line:

- `dropped=N`: this means that N logs attributed to the component were dropped when the component
  wrote to the log socket. This can happen when archivist cannot keep up with the rate of logs being
  emitted by the component and the component filled the log socket buffer in the kernel.

- `rolled=N`: this means that N logs rolled out from the archivist buffer and ffx never saw them.
  This can happen when more logs are being ingested by the archivist across all components and the
  ffx couldn't retrieve them fast enough.

Symbolization is performed in the background using the symbolizer host tool. You can pass
additional arguments to the symbolizer tool (for example, to add a remote symbol server) using:
  $ ffx config set proactive_log.symbolize.extra_args \"--symbol-server gs://some-url/path --symbol-server gs://some-other-url/path ...\"

To learn more about configuring the log viewer, visit https://fuchsia.dev/fuchsia-src/development/tools/ffx/commands/log",
    example = "\
Dump the most recent logs and stream new ones as they happen:
  $ ffx log

Stream new logs starting from the current time, filtering for severity of at least \"WARN\":
  $ ffx log --severity warn --since now

Stream logs where the source moniker, component url and message do not include \"sys\":
  $ ffx log --exclude sys

Stream ERROR logs with source moniker, component url or message containing either
\"netstack\" or \"remote-control.cm\", but not containing \"sys\":
  $ ffx log --severity error --filter netstack --filter remote-control.cm --exclude sys

Dump all available logs where the source moniker, component url, or message contains
\"remote-control\":
  $ ffx log --filter remote-control dump

Dump all logs from the last 30 minutes logged before 5 minutes ago:
  $ ffx log --since \"30m ago\" --until \"5m ago\" dump

Enable DEBUG logs from the \"core/audio\" component while logs are streaming:
  $ ffx log --set-severity core/audio#DEBUG"
)]
pub struct LogCommand {
    #[argh(subcommand)]
    pub sub_command: Option<LogSubCommand>,

    /// filter for a string in either the message, component or url.
    /// May be repeated.
    #[argh(option)]
    pub filter: Vec<String>,

    /// DEPRECATED: use --component
    #[argh(option)]
    pub moniker: Vec<String>,

    /// fuzzy search for a component by moniker or url.
    /// May be repeated.
    #[argh(option)]
    pub component: Vec<String>,

    /// exclude a string in either the message, component or url.
    /// May be repeated.
    #[argh(option)]
    pub exclude: Vec<String>,

    /// filter for only logs with a given tag. May be repeated.
    #[argh(option)]
    pub tag: Vec<String>,

    /// exclude logs with a given tag. May be repeated.
    #[argh(option)]
    pub exclude_tags: Vec<String>,

    /// set the minimum severity. Accepted values (from lower to higher) are: trace, debug, info,
    /// warn (or warning), error, fatal. This field is case insensitive.
    #[argh(option, default = "Severity::Info")]
    pub severity: Severity,

    /// outputs only kernel logs, unless combined with --component.
    #[argh(switch)]
    pub kernel: bool,

    /// show only logs after a certain time (exclusive)
    #[argh(option, from_str_fn(parse_time))]
    pub since: Option<DetailedDateTime>,

    /// show only logs after a certain time (as a boot
    /// timestamp: seconds from the target's boot time).
    #[argh(option, from_str_fn(parse_seconds_string_as_duration))]
    pub since_boot: Option<Duration>,

    /// show only logs until a certain time (exclusive)
    #[argh(option, from_str_fn(parse_time))]
    pub until: Option<DetailedDateTime>,

    /// show only logs until a certain time (as a a boot
    /// timestamp: seconds since the target's boot time).
    #[argh(option, from_str_fn(parse_seconds_string_as_duration))]
    pub until_boot: Option<Duration>,

    /// hide the tag field from output (does not exclude any log messages)
    #[argh(switch)]
    pub hide_tags: bool,

    /// hide the file and line number field from output (does not exclude any log messages)
    #[argh(switch)]
    pub hide_file: bool,

    /// disable coloring logs according to severity.
    /// Note that you can permanently disable this with
    /// `ffx config set log_cmd.color false`
    #[argh(switch)]
    pub no_color: bool,

    /// if enabled, text filtering options are case-sensitive
    /// this applies to --filter and --exclude.
    #[argh(switch)]
    pub case_sensitive: bool,

    /// shows process-id and thread-id in log output
    #[argh(switch)]
    pub show_metadata: bool,

    /// shows the full moniker in log output. By default this is false and only the last segment
    /// of the moniker is printed.
    #[argh(switch)]
    pub show_full_moniker: bool,

    /// how to display log timestamps.
    /// Options are "utc", "local", or "boot" (i.e. nanos since target boot).
    /// Default is boot.
    #[argh(option, default = "TimeFormat::Boot")]
    pub clock: TimeFormat,

    /// configure symbolization options. Valid options are:
    /// - pretty (default): pretty concise symbolization
    /// - off: disables all symbolization
    /// - classic: traditional, non-prettified symbolization
    #[cfg(not(target_os = "fuchsia"))]
    #[argh(option, default = "SymbolizeMode::Pretty")]
    pub symbolize: SymbolizeMode,

    /// configure the log settings on the target device for components matching
    /// the given selector. This modifies the minimum log severity level emitted
    /// by components during the logging session.
    /// Specify using the format <component-selector>#<log-level>, with level
    /// as one of FATAL|ERROR|WARN|INFO|DEBUG|TRACE.
    /// May be repeated and it's also possible to pass multiple comma-separated
    /// strings per invocation.
    /// Cannot be used in conjunction with --set-severity-persist.
    #[argh(option, from_str_fn(log_interest_selector))]
    pub set_severity: Vec<OneOrMany<LogInterestSelector>>,

    /// filters by pid
    #[argh(option)]
    pub pid: Option<u64>,

    /// filters by tid
    #[argh(option)]
    pub tid: Option<u64>,

    /// if enabled, selectors will be passed directly to Archivist without any filtering.
    /// If disabled and no matching components are found, the user will be prompted to
    /// either enable this or be given a list of selectors to choose from.
    /// This applies to both --set-severity and --set-severity-persist.
    #[argh(switch)]
    pub force_set_severity: bool,

    /// enables structured JSON logs.
    #[cfg(target_os = "fuchsia")]
    #[argh(switch)]
    pub json: bool,
}

impl Default for LogCommand {
    fn default() -> Self {
        LogCommand {
            filter: vec![],
            moniker: vec![],
            component: vec![],
            exclude: vec![],
            tag: vec![],
            exclude_tags: vec![],
            hide_tags: false,
            hide_file: false,
            clock: TimeFormat::Boot,
            no_color: false,
            kernel: false,
            severity: Severity::Info,
            show_metadata: false,
            force_set_severity: false,
            since: None,
            since_boot: None,
            until: None,
            case_sensitive: false,
            until_boot: None,
            sub_command: None,
            set_severity: vec![],
            show_full_moniker: false,
            pid: None,
            tid: None,
            #[cfg(target_os = "fuchsia")]
            json: false,
            #[cfg(not(target_os = "fuchsia"))]
            symbolize: SymbolizeMode::Pretty,
        }
    }
}

/// Result returned from processing logs
#[derive(PartialEq, Debug)]
pub enum LogProcessingResult {
    /// The caller should exit
    Exit,
    /// The caller should continue processing logs
    Continue,
}

impl FromStr for SymbolizeMode {
    type Err = anyhow::Error;

    fn from_str(s: &str) -> Result<Self, Self::Err> {
        let s = s.to_lowercase();
        match s.as_str() {
            "off" => Ok(SymbolizeMode::Off),
            "pretty" => Ok(SymbolizeMode::Pretty),
            "classic" => Ok(SymbolizeMode::Classic),
            other => Err(format_err!("invalid symbolize flag: {}", other)),
        }
    }
}

#[derive(Error, Debug)]
pub enum LogError {
    #[error(transparent)]
    UnknownError(#[from] anyhow::Error),
    #[error("No boot timestamp")]
    NoBootTimestamp,
    #[error(transparent)]
    IOError(#[from] std::io::Error),
    #[error("Cannot use dump with --since now")]
    DumpWithSinceNow,
    #[error("No symbolizer configuration provided")]
    NoSymbolizerConfig,
    #[error(transparent)]
    FfxError(#[from] FfxError),
    #[error(transparent)]
    Utf8Error(#[from] FromUtf8Error),
    #[error(transparent)]
    FidlError(#[from] fidl::Error),
    #[error(transparent)]
    FormatterError(#[from] FormatterError),
    #[error("Deprecated flag: `{flag}`, use: `{new_flag}`")]
    DeprecatedFlag { flag: &'static str, new_flag: &'static str },
    #[error(
        "Fuzzy matching failed due to too many matches, please re-try with one of these:\n{0}"
    )]
    FuzzyMatchTooManyMatches(String),
    #[error("No running components were found matching {0}")]
    SearchParameterNotFound(String),
}

impl LogError {
    fn too_many_fuzzy_matches(matches: impl Iterator<Item = String>) -> Self {
        let mut result = String::new();
        for component in matches {
            result.push_str(&component);
            result.push('\n');
        }

        Self::FuzzyMatchTooManyMatches(result)
    }
}

/// Trait used to get available instances given a moniker query.
#[async_trait::async_trait(?Send)]
pub trait InstanceGetter {
    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError>;
}

#[async_trait::async_trait(?Send)]
impl InstanceGetter for RealmQueryProxy {
    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
        Ok(get_instances_from_query(query, self)
            .await?
            .into_iter()
            .map(|value| value.moniker)
            .collect())
    }
}

impl LogCommand {
    async fn map_interest_selectors<'a>(
        realm_query: &impl InstanceGetter,
        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
    ) -> Result<impl Iterator<Item = Cow<'a, LogInterestSelector>>, LogError> {
        let selectors = Self::get_selectors_and_monikers(interest_selectors);
        let mut translated_selectors = vec![];
        for (moniker, selector) in selectors {
            // Attempt to translate to a single instance
            let instances = realm_query.get_monikers_from_query(moniker.as_str()).await?;
            // If exactly one match, perform rewrite
            if instances.len() == 1 {
                let mut translated_selector = selector.clone();
                translated_selector.selector = instances[0].clone().into_component_selector();
                translated_selectors.push((Cow::Owned(translated_selector), instances));
            } else {
                translated_selectors.push((Cow::Borrowed(selector), instances));
            }
        }
        if translated_selectors.iter().any(|(_, matches)| matches.len() > 1) {
            let mut err_output = vec![];
            writeln!(
                &mut err_output,
                "WARN: One or more of your selectors appears to be ambiguous"
            )?;
            writeln!(&mut err_output, "and may not match any components on your system.\n")?;
            writeln!(
                &mut err_output,
                "If this is unintentional you can explicitly match using the"
            )?;
            writeln!(&mut err_output, "following command:\n")?;
            writeln!(&mut err_output, "ffx log \\")?;
            let mut output = vec![];
            for (oselector, instances) in translated_selectors {
                for selector in instances {
                    writeln!(
                        output,
                        "\t--set-severity {}#{} \\",
                        sanitize_moniker_for_selectors(selector.to_string().as_str())
                            .replace("\\", "\\\\"),
                        format!("{:?}", oselector.interest.min_severity.unwrap()).to_uppercase()
                    )?;
                }
            }
            // Intentionally ignored, removes the newline, space, and \
            let _ = output.pop();
            let _ = output.pop();
            let _ = output.pop();

            writeln!(&mut err_output, "{}", String::from_utf8(output).unwrap())?;
            writeln!(&mut err_output, "\nIf this is intentional, you can disable this with")?;
            writeln!(&mut err_output, "ffx log --force-set-severity.")?;

            ffx_bail!("{}", String::from_utf8(err_output)?);
        }
        Ok(translated_selectors.into_iter().map(|(selector, _)| selector))
    }

    pub fn validate_cmd_flags_with_warnings(&mut self) -> Result<Vec<&'static str>, LogError> {
        let mut warnings = vec![];

        if !self.moniker.is_empty() {
            warnings.push("WARNING: --moniker is deprecated, use --component instead");
            if self.component.is_empty() {
                self.component = std::mem::take(&mut self.moniker);
            } else {
                warnings.push("WARNING: ignoring --moniker arguments in favor of --component");
            }
        }

        Ok(warnings)
    }

    /// Sets interest based on configured selectors.
    /// If a single ambiguous match is found, the monikers in the selectors
    /// are automatically re-written.
    pub async fn maybe_set_interest(
        &self,
        log_settings_client: &LogSettingsProxy,
        realm_query: &impl InstanceGetter,
    ) -> Result<(), LogError> {
        let (set_severity, force_set_severity, persist) =
            if let Some(LogSubCommand::SetSeverity(options)) = &self.sub_command {
                // No other argument can exist in conjunction with SetSeverity
                let default_cmd = LogCommand {
                    sub_command: Some(LogSubCommand::SetSeverity(options.clone())),
                    ..Default::default()
                };
                if &default_cmd != self {
                    ffx_bail!("Cannot combine set-severity with other options.");
                }
                (&options.interest_selector, options.force, !options.no_persist)
            } else {
                (&self.set_severity, self.force_set_severity, false)
            };
        if persist {
            let selectors = if force_set_severity {
                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
            } else {
                let new_selectors =
                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
                        .await?
                        .map(|s| s.into_owned())
                        .collect::<Vec<_>>();
                if new_selectors.is_empty() {
                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
                } else {
                    new_selectors
                }
            };
            log_settings_client
                .set_component_interest(
                    &fidl_fuchsia_diagnostics::LogSettingsSetComponentInterestRequest {
                        selectors: Some(selectors),
                        persist: Some(true),
                        ..Default::default()
                    },
                )
                .await?;
        } else if !set_severity.is_empty() {
            let selectors = if force_set_severity {
                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
            } else {
                let new_selectors =
                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
                        .await?
                        .map(|s| s.into_owned())
                        .collect::<Vec<_>>();
                if new_selectors.is_empty() {
                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
                } else {
                    new_selectors
                }
            };

            log_settings_client.set_interest(&selectors).await?;
        }

        Ok(())
    }

    fn get_selectors_and_monikers<'a>(
        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
    ) -> Vec<(String, &'a LogInterestSelector)> {
        let mut selectors = vec![];
        for selector in interest_selectors {
            let segments = selector.selector.moniker_segments.as_ref().unwrap();
            let mut full_moniker = String::new();
            for segment in segments {
                match segment {
                    fidl_fuchsia_diagnostics::StringSelector::ExactMatch(segment) => {
                        if full_moniker.is_empty() {
                            full_moniker.push_str(segment);
                        } else {
                            full_moniker.push('/');
                            full_moniker.push_str(segment);
                        }
                    }
                    _ => {
                        // If the user passed a non-exact match we assume they
                        // know what they're doing and skip this logic.
                        return vec![];
                    }
                }
            }
            selectors.push((full_moniker, selector));
        }
        selectors
    }
}

impl TopLevelCommand for LogCommand {}

fn log_interest_selector(s: &str) -> Result<OneOrMany<LogInterestSelector>, String> {
    if s.contains(",") {
        let many: Result<Vec<LogInterestSelector>, String> = s
            .split(",")
            .map(|value| selectors::parse_log_interest_selector(value).map_err(|e| e.to_string()))
            .collect();
        Ok(OneOrMany::Many(many?))
    } else {
        Ok(OneOrMany::One(selectors::parse_log_interest_selector(s).map_err(|s| s.to_string())?))
    }
}

#[cfg(test)]
mod test {
    use super::*;
    use assert_matches::assert_matches;
    use async_trait::async_trait;
    use fidl::endpoints::create_proxy;
    use fidl_fuchsia_diagnostics::{LogSettingsMarker, LogSettingsRequest};
    use futures_util::future::Either;
    use futures_util::stream::FuturesUnordered;
    use futures_util::StreamExt;
    use selectors::parse_log_interest_selector;

    #[derive(Default)]
    struct FakeInstanceGetter {
        output: Vec<Moniker>,
        expected_selector: Option<String>,
    }

    #[async_trait(?Send)]
    impl InstanceGetter for FakeInstanceGetter {
        async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
            if let Some(expected) = &self.expected_selector {
                assert_eq!(expected, query);
            }
            Ok(self.output.clone())
        }
    }

    #[fuchsia::test]
    async fn test_symbolize_mode_from_str() {
        assert_matches!(SymbolizeMode::from_str("off"), Ok(value) if value == SymbolizeMode::Off);
        assert_matches!(
            SymbolizeMode::from_str("pretty"),
            Ok(value) if value == SymbolizeMode::Pretty
        );
        assert_matches!(
            SymbolizeMode::from_str("classic"),
            Ok(value) if value == SymbolizeMode::Classic
        );
    }

    #[fuchsia::test]
    async fn maybe_set_interest_errors_additional_arguments_passed_to_set_interest() {
        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
        let getter = FakeInstanceGetter {
            expected_selector: Some("ambiguous_selector".into()),
            output: vec![
                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
            ],
        };
        // Main should return an error

        let cmd = LogCommand {
            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
                interest_selector: vec![OneOrMany::One(
                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
                )],
                force: false,
                no_persist: false,
            })),
            hide_file: true,
            ..LogCommand::default()
        };
        let mut set_interest_result = None;

        let mut scheduler = FuturesUnordered::new();
        scheduler.push(Either::Left(async {
            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
            drop(settings_proxy);
        }));
        scheduler.push(Either::Right(async {
            let request = settings_server.into_stream().next().await;
            // The channel should be closed without sending any requests.
            assert_matches!(request, None);
        }));
        while scheduler.next().await.is_some() {}
        drop(scheduler);

        let error = format!("{}", set_interest_result.unwrap().unwrap_err());

        const EXPECTED_INTEREST_ERROR: &str = "Cannot combine set-severity with other options.";
        assert_eq!(error, EXPECTED_INTEREST_ERROR);
    }

    #[fuchsia::test]
    async fn maybe_set_interest_errors_if_ambiguous_selector() {
        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
        let getter = FakeInstanceGetter {
            expected_selector: Some("ambiguous_selector".into()),
            output: vec![
                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
            ],
        };
        // Main should return an error

        let cmd = LogCommand {
            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
            set_severity: vec![OneOrMany::One(
                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
            )],
            ..LogCommand::default()
        };
        let mut set_interest_result = None;

        let mut scheduler = FuturesUnordered::new();
        scheduler.push(Either::Left(async {
            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
            drop(settings_proxy);
        }));
        scheduler.push(Either::Right(async {
            let request = settings_server.into_stream().next().await;
            // The channel should be closed without sending any requests.
            assert_matches!(request, None);
        }));
        while scheduler.next().await.is_some() {}
        drop(scheduler);

        let error = format!("{}", set_interest_result.unwrap().unwrap_err());

        const EXPECTED_INTEREST_ERROR: &str = r#"WARN: One or more of your selectors appears to be ambiguous
and may not match any components on your system.

If this is unintentional you can explicitly match using the
following command:

ffx log \
	--set-severity core/some/ambiguous_selector\\:thing/test#INFO \
	--set-severity core/other/ambiguous_selector\\:thing/test#INFO

If this is intentional, you can disable this with
ffx log --force-set-severity.
"#;
        assert_eq!(error, EXPECTED_INTEREST_ERROR);
    }

    #[fuchsia::test]
    async fn logger_translates_selector_if_one_match() {
        let cmd = LogCommand {
            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
            set_severity: vec![OneOrMany::One(
                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
            )],
            ..LogCommand::default()
        };
        let mut set_interest_result = None;
        let getter = FakeInstanceGetter {
            expected_selector: Some("ambiguous_selector".into()),
            output: vec![Moniker::try_from("core/some/ambiguous_selector").unwrap()],
        };
        let mut scheduler = FuturesUnordered::new();
        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
        scheduler.push(Either::Left(async {
            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
            drop(settings_proxy);
        }));
        scheduler.push(Either::Right(async {
            let request = settings_server.into_stream().next().await;
            let (selectors, responder) = assert_matches!(
                request,
                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
                (selectors, responder)
            );
            responder.send().unwrap();
            assert_eq!(
                selectors,
                vec![parse_log_interest_selector("core/some/ambiguous_selector#INFO").unwrap()]
            );
        }));
        while scheduler.next().await.is_some() {}
        drop(scheduler);
        assert_matches!(set_interest_result, Some(Ok(())));
    }

    #[fuchsia::test]
    async fn logger_uses_specified_selectors_if_no_results_returned() {
        let cmd = LogCommand {
            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
            set_severity: vec![OneOrMany::One(
                parse_log_interest_selector("core/something/a:b/elements:main/otherstuff:*#DEBUG")
                    .unwrap(),
            )],
            ..LogCommand::default()
        };
        let mut set_interest_result = None;
        let getter = FakeInstanceGetter {
            expected_selector: Some("core/something/a:b/elements:main/otherstuff:*#DEBUG".into()),
            output: vec![],
        };
        let scheduler = FuturesUnordered::new();
        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
        scheduler.push(Either::Left(async {
            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
            drop(settings_proxy);
        }));
        scheduler.push(Either::Right(async {
            let request = settings_server.into_stream().next().await;
            let (selectors, responder) = assert_matches!(
                request,
                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
                (selectors, responder)
            );
            responder.send().unwrap();
            assert_eq!(
                selectors,
                vec![parse_log_interest_selector(
                    "core/something/a:b/elements:main/otherstuff:*#DEBUG"
                )
                .unwrap()]
            );
        }));
        scheduler.map(|_| Ok(())).forward(futures::sink::drain()).await.unwrap();
        assert_matches!(set_interest_result, Some(Ok(())));
    }

    #[fuchsia::test]
    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used() {
        let cmd = LogCommand {
            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
                no_persist: true,
                interest_selector: vec![OneOrMany::One(
                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
                )],
                force: true,
            })),
            ..LogCommand::default()
        };
        let getter = FakeInstanceGetter {
            expected_selector: Some("ambiguous_selector".into()),
            output: vec![
                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
            ],
        };
        let mut set_interest_result = None;
        let mut scheduler = FuturesUnordered::new();
        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
        scheduler.push(Either::Left(async {
            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
            drop(settings_proxy);
        }));
        scheduler.push(Either::Right(async {
            let request = settings_server.into_stream().next().await;
            let (selectors, responder) = assert_matches!(
                request,
                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
                (selectors, responder)
            );
            responder.send().unwrap();
            assert_eq!(
                selectors,
                vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()]
            );
        }));
        while scheduler.next().await.is_some() {}
        drop(scheduler);
        assert_matches!(set_interest_result, Some(Ok(())));
    }

    #[fuchsia::test]
    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used_persistent() {
        let cmd = LogCommand {
            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
                no_persist: false,
                interest_selector: vec![log_socket_stream::OneOrMany::One(
                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
                )],
                force: true,
            })),
            ..LogCommand::default()
        };
        let getter = FakeInstanceGetter {
            expected_selector: Some("ambiguous_selector".into()),
            output: vec![
                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
            ],
        };
        let mut set_interest_result = None;
        let mut scheduler = FuturesUnordered::new();
        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
        scheduler.push(Either::Left(async {
            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
            drop(settings_proxy);
        }));
        scheduler.push(Either::Right(async {
            let request = settings_server.into_stream().next().await;
            let (payload, responder) = assert_matches!(
                request,
                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
                (payload, responder)
            );
            assert_eq!(payload.persist, Some(true));
            responder.send().unwrap();
            assert_eq!(
                payload.selectors.unwrap(),
                vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()]
            );
        }));
        while scheduler.next().await.is_some() {}
        drop(scheduler);
        assert_matches!(set_interest_result, Some(Ok(())));
    }

    #[fuchsia::test]
    async fn logger_prints_ignores_ambiguity_if_machine_output_is_used() {
        let cmd = LogCommand {
            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
            set_severity: vec![OneOrMany::One(
                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
            )],
            force_set_severity: true,
            ..LogCommand::default()
        };
        let getter = FakeInstanceGetter {
            expected_selector: Some("ambiguous_selector".into()),
            output: vec![
                Moniker::try_from("core/some/collection:thing/test").unwrap(),
                Moniker::try_from("core/other/collection:thing/test").unwrap(),
            ],
        };
        let mut set_interest_result = None;
        let mut scheduler = FuturesUnordered::new();
        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
        scheduler.push(Either::Left(async {
            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
            drop(settings_proxy);
        }));
        scheduler.push(Either::Right(async {
            let request = settings_server.into_stream().next().await;
            let (selectors, responder) = assert_matches!(
                request,
                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
                (selectors, responder)
            );
            responder.send().unwrap();
            assert_eq!(
                selectors,
                vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()]
            );
        }));
        while scheduler.next().await.is_some() {}
        drop(scheduler);
        assert_matches!(set_interest_result, Some(Ok(())));
    }
    #[test]
    fn test_parse_selector() {
        assert_eq!(
            log_interest_selector("core/audio#DEBUG").unwrap(),
            OneOrMany::One(parse_log_interest_selector("core/audio#DEBUG").unwrap())
        );
    }

    #[test]
    fn test_parse_selector_with_commas() {
        assert_eq!(
            log_interest_selector("core/audio#DEBUG,bootstrap/archivist#TRACE").unwrap(),
            OneOrMany::Many(vec![
                parse_log_interest_selector("core/audio#DEBUG").unwrap(),
                parse_log_interest_selector("bootstrap/archivist#TRACE").unwrap()
            ])
        );
    }

    #[test]
    fn test_parse_time() {
        assert!(parse_time("now").unwrap().is_now);
        let date_string = "04/20/2020";
        let res = parse_time(date_string).unwrap();
        assert!(!res.is_now);
        assert_eq!(
            res.date_naive(),
            parse_date_string(date_string, Local::now(), Dialect::Us).unwrap().date_naive()
        );
    }
}