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

log_command/
lib.rs
