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::{parse_date_string, Dialect};
9use component_debug::query::get_instances_from_query;
10use diagnostics_data::Severity;
11use errors::{ffx_bail, FfxError};
12use fidl_fuchsia_diagnostics::{LogInterestSelector, LogSettingsProxy};
13use fidl_fuchsia_sys2::RealmQueryProxy;
14pub use log_socket_stream::OneOrMany;
15use moniker::Moniker;
16use selectors::{sanitize_moniker_for_selectors, SelectorExt};
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    dump_logs_from_socket, BootTimeAccessor, DefaultLogFormatter, FormatterError, LogData,
29    LogEntry, Symbolize, Timestamp, WriterContainer, TIMESTAMP_FORMAT,
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(
432        "Fuzzy matching failed due to too many matches, please re-try with one of these:\n{0}"
433    )]
434    FuzzyMatchTooManyMatches(String),
435    #[error("No running components were found matching {0}")]
436    SearchParameterNotFound(String),
437}
438
439impl LogError {
440    fn too_many_fuzzy_matches(matches: impl Iterator<Item = String>) -> Self {
441        let mut result = String::new();
442        for component in matches {
443            result.push_str(&component);
444            result.push('\n');
445        }
446
447        Self::FuzzyMatchTooManyMatches(result)
448    }
449}
450
451/// Trait used to get available instances given a moniker query.
452#[async_trait::async_trait(?Send)]
453pub trait InstanceGetter {
454    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError>;
455}
456
457#[async_trait::async_trait(?Send)]
458impl InstanceGetter for RealmQueryProxy {
459    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
460        Ok(get_instances_from_query(query, self)
461            .await?
462            .into_iter()
463            .map(|value| value.moniker)
464            .collect())
465    }
466}
467
468impl LogCommand {
469    async fn map_interest_selectors<'a>(
470        realm_query: &impl InstanceGetter,
471        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
472    ) -> Result<impl Iterator<Item = Cow<'a, LogInterestSelector>>, LogError> {
473        let selectors = Self::get_selectors_and_monikers(interest_selectors);
474        let mut translated_selectors = vec![];
475        for (moniker, selector) in selectors {
476            // Attempt to translate to a single instance
477            let instances = realm_query.get_monikers_from_query(moniker.as_str()).await?;
478            // If exactly one match, perform rewrite
479            if instances.len() == 1 {
480                let mut translated_selector = selector.clone();
481                translated_selector.selector = instances[0].clone().into_component_selector();
482                translated_selectors.push((Cow::Owned(translated_selector), instances));
483            } else {
484                translated_selectors.push((Cow::Borrowed(selector), instances));
485            }
486        }
487        if translated_selectors.iter().any(|(_, matches)| matches.len() > 1) {
488            let mut err_output = vec![];
489            writeln!(
490                &mut err_output,
491                "WARN: One or more of your selectors appears to be ambiguous"
492            )?;
493            writeln!(&mut err_output, "and may not match any components on your system.\n")?;
494            writeln!(
495                &mut err_output,
496                "If this is unintentional you can explicitly match using the"
497            )?;
498            writeln!(&mut err_output, "following command:\n")?;
499            writeln!(&mut err_output, "ffx log \\")?;
500            let mut output = vec![];
501            for (oselector, instances) in translated_selectors {
502                for selector in instances {
503                    writeln!(
504                        output,
505                        "\t--set-severity {}#{} \\",
506                        sanitize_moniker_for_selectors(selector.to_string().as_str())
507                            .replace("\\", "\\\\"),
508                        format!("{:?}", oselector.interest.min_severity.unwrap()).to_uppercase()
509                    )?;
510                }
511            }
512            // Intentionally ignored, removes the newline, space, and \
513            let _ = output.pop();
514            let _ = output.pop();
515            let _ = output.pop();
516
517            writeln!(&mut err_output, "{}", String::from_utf8(output).unwrap())?;
518            writeln!(&mut err_output, "\nIf this is intentional, you can disable this with")?;
519            writeln!(&mut err_output, "ffx log --force-set-severity.")?;
520
521            ffx_bail!("{}", String::from_utf8(err_output)?);
522        }
523        Ok(translated_selectors.into_iter().map(|(selector, _)| selector))
524    }
525
526    pub fn validate_cmd_flags_with_warnings(&mut self) -> Result<Vec<&'static str>, LogError> {
527        let mut warnings = vec![];
528
529        if !self.moniker.is_empty() {
530            warnings.push("WARNING: --moniker is deprecated, use --component instead");
531            if self.component.is_empty() {
532                self.component = std::mem::take(&mut self.moniker);
533            } else {
534                warnings.push("WARNING: ignoring --moniker arguments in favor of --component");
535            }
536        }
537
538        Ok(warnings)
539    }
540
541    /// Sets interest based on configured selectors.
542    /// If a single ambiguous match is found, the monikers in the selectors
543    /// are automatically re-written.
544    pub async fn maybe_set_interest(
545        &self,
546        log_settings_client: &LogSettingsProxy,
547        realm_query: &impl InstanceGetter,
548    ) -> Result<(), LogError> {
549        let (set_severity, force_set_severity, persist) =
550            if let Some(LogSubCommand::SetSeverity(options)) = &self.sub_command {
551                // No other argument can exist in conjunction with SetSeverity
552                let default_cmd = LogCommand {
553                    sub_command: Some(LogSubCommand::SetSeverity(options.clone())),
554                    ..Default::default()
555                };
556                if &default_cmd != self {
557                    ffx_bail!("Cannot combine set-severity with other options.");
558                }
559                (&options.interest_selector, options.force, !options.no_persist)
560            } else {
561                (&self.set_severity, self.force_set_severity, false)
562            };
563        if persist {
564            let selectors = if force_set_severity {
565                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
566            } else {
567                let new_selectors =
568                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
569                        .await?
570                        .map(|s| s.into_owned())
571                        .collect::<Vec<_>>();
572                if new_selectors.is_empty() {
573                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
574                } else {
575                    new_selectors
576                }
577            };
578            log_settings_client
579                .set_component_interest(
580                    &fidl_fuchsia_diagnostics::LogSettingsSetComponentInterestRequest {
581                        selectors: Some(selectors),
582                        persist: Some(true),
583                        ..Default::default()
584                    },
585                )
586                .await?;
587        } else if !set_severity.is_empty() {
588            let selectors = if force_set_severity {
589                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
590            } else {
591                let new_selectors =
592                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
593                        .await?
594                        .map(|s| s.into_owned())
595                        .collect::<Vec<_>>();
596                if new_selectors.is_empty() {
597                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
598                } else {
599                    new_selectors
600                }
601            };
602
603            log_settings_client.set_interest(&selectors).await?;
604        }
605
606        Ok(())
607    }
608
609    fn get_selectors_and_monikers<'a>(
610        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
611    ) -> Vec<(String, &'a LogInterestSelector)> {
612        let mut selectors = vec![];
613        for selector in interest_selectors {
614            let segments = selector.selector.moniker_segments.as_ref().unwrap();
615            let mut full_moniker = String::new();
616            for segment in segments {
617                match segment {
618                    fidl_fuchsia_diagnostics::StringSelector::ExactMatch(segment) => {
619                        if full_moniker.is_empty() {
620                            full_moniker.push_str(segment);
621                        } else {
622                            full_moniker.push('/');
623                            full_moniker.push_str(segment);
624                        }
625                    }
626                    _ => {
627                        // If the user passed a non-exact match we assume they
628                        // know what they're doing and skip this logic.
629                        return vec![];
630                    }
631                }
632            }
633            selectors.push((full_moniker, selector));
634        }
635        selectors
636    }
637}
638
639impl TopLevelCommand for LogCommand {}
640
641fn log_interest_selector(s: &str) -> Result<OneOrMany<LogInterestSelector>, String> {
642    if s.contains(",") {
643        let many: Result<Vec<LogInterestSelector>, String> = s
644            .split(",")
645            .map(|value| selectors::parse_log_interest_selector(value).map_err(|e| e.to_string()))
646            .collect();
647        Ok(OneOrMany::Many(many?))
648    } else {
649        Ok(OneOrMany::One(selectors::parse_log_interest_selector(s).map_err(|s| s.to_string())?))
650    }
651}
652
653#[cfg(test)]
654mod test {
655    use super::*;
656    use assert_matches::assert_matches;
657    use async_trait::async_trait;
658    use fidl::endpoints::create_proxy;
659    use fidl_fuchsia_diagnostics::{LogSettingsMarker, LogSettingsRequest};
660    use futures_util::future::Either;
661    use futures_util::stream::FuturesUnordered;
662    use futures_util::StreamExt;
663    use selectors::parse_log_interest_selector;
664
665    #[derive(Default)]
666    struct FakeInstanceGetter {
667        output: Vec<Moniker>,
668        expected_selector: Option<String>,
669    }
670
671    #[async_trait(?Send)]
672    impl InstanceGetter for FakeInstanceGetter {
673        async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
674            if let Some(expected) = &self.expected_selector {
675                assert_eq!(expected, query);
676            }
677            Ok(self.output.clone())
678        }
679    }
680
681    #[fuchsia::test]
682    async fn test_symbolize_mode_from_str() {
683        assert_matches!(SymbolizeMode::from_str("off"), Ok(value) if value == SymbolizeMode::Off);
684        assert_matches!(
685            SymbolizeMode::from_str("pretty"),
686            Ok(value) if value == SymbolizeMode::Pretty
687        );
688        assert_matches!(
689            SymbolizeMode::from_str("classic"),
690            Ok(value) if value == SymbolizeMode::Classic
691        );
692    }
693
694    #[fuchsia::test]
695    async fn maybe_set_interest_errors_additional_arguments_passed_to_set_interest() {
696        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
697        let getter = FakeInstanceGetter {
698            expected_selector: Some("ambiguous_selector".into()),
699            output: vec![
700                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
701                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
702            ],
703        };
704        // Main should return an error
705
706        let cmd = LogCommand {
707            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
708                interest_selector: vec![OneOrMany::One(
709                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
710                )],
711                force: false,
712                no_persist: false,
713            })),
714            hide_file: true,
715            ..LogCommand::default()
716        };
717        let mut set_interest_result = None;
718
719        let mut scheduler = FuturesUnordered::new();
720        scheduler.push(Either::Left(async {
721            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
722            drop(settings_proxy);
723        }));
724        scheduler.push(Either::Right(async {
725            let request = settings_server.into_stream().next().await;
726            // The channel should be closed without sending any requests.
727            assert_matches!(request, None);
728        }));
729        while scheduler.next().await.is_some() {}
730        drop(scheduler);
731
732        let error = format!("{}", set_interest_result.unwrap().unwrap_err());
733
734        const EXPECTED_INTEREST_ERROR: &str = "Cannot combine set-severity with other options.";
735        assert_eq!(error, EXPECTED_INTEREST_ERROR);
736    }
737
738    #[fuchsia::test]
739    async fn maybe_set_interest_errors_if_ambiguous_selector() {
740        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
741        let getter = FakeInstanceGetter {
742            expected_selector: Some("ambiguous_selector".into()),
743            output: vec![
744                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
745                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
746            ],
747        };
748        // Main should return an error
749
750        let cmd = LogCommand {
751            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
752            set_severity: vec![OneOrMany::One(
753                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
754            )],
755            ..LogCommand::default()
756        };
757        let mut set_interest_result = None;
758
759        let mut scheduler = FuturesUnordered::new();
760        scheduler.push(Either::Left(async {
761            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
762            drop(settings_proxy);
763        }));
764        scheduler.push(Either::Right(async {
765            let request = settings_server.into_stream().next().await;
766            // The channel should be closed without sending any requests.
767            assert_matches!(request, None);
768        }));
769        while scheduler.next().await.is_some() {}
770        drop(scheduler);
771
772        let error = format!("{}", set_interest_result.unwrap().unwrap_err());
773
774        const EXPECTED_INTEREST_ERROR: &str = r#"WARN: One or more of your selectors appears to be ambiguous
775and may not match any components on your system.
776
777If this is unintentional you can explicitly match using the
778following command:
779
780ffx log \
781	--set-severity core/some/ambiguous_selector\\:thing/test#INFO \
782	--set-severity core/other/ambiguous_selector\\:thing/test#INFO
783
784If this is intentional, you can disable this with
785ffx log --force-set-severity.
786"#;
787        assert_eq!(error, EXPECTED_INTEREST_ERROR);
788    }
789
790    #[fuchsia::test]
791    async fn logger_translates_selector_if_one_match() {
792        let cmd = LogCommand {
793            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
794            set_severity: vec![OneOrMany::One(
795                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
796            )],
797            ..LogCommand::default()
798        };
799        let mut set_interest_result = None;
800        let getter = FakeInstanceGetter {
801            expected_selector: Some("ambiguous_selector".into()),
802            output: vec![Moniker::try_from("core/some/ambiguous_selector").unwrap()],
803        };
804        let mut scheduler = FuturesUnordered::new();
805        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
806        scheduler.push(Either::Left(async {
807            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
808            drop(settings_proxy);
809        }));
810        scheduler.push(Either::Right(async {
811            let request = settings_server.into_stream().next().await;
812            let (selectors, responder) = assert_matches!(
813                request,
814                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
815                (selectors, responder)
816            );
817            responder.send().unwrap();
818            assert_eq!(
819                selectors,
820                vec![parse_log_interest_selector("core/some/ambiguous_selector#INFO").unwrap()]
821            );
822        }));
823        while scheduler.next().await.is_some() {}
824        drop(scheduler);
825        assert_matches!(set_interest_result, Some(Ok(())));
826    }
827
828    #[fuchsia::test]
829    async fn logger_uses_specified_selectors_if_no_results_returned() {
830        let cmd = LogCommand {
831            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
832            set_severity: vec![OneOrMany::One(
833                parse_log_interest_selector("core/something/a:b/elements:main/otherstuff:*#DEBUG")
834                    .unwrap(),
835            )],
836            ..LogCommand::default()
837        };
838        let mut set_interest_result = None;
839        let getter = FakeInstanceGetter {
840            expected_selector: Some("core/something/a:b/elements:main/otherstuff:*#DEBUG".into()),
841            output: vec![],
842        };
843        let scheduler = FuturesUnordered::new();
844        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
845        scheduler.push(Either::Left(async {
846            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
847            drop(settings_proxy);
848        }));
849        scheduler.push(Either::Right(async {
850            let request = settings_server.into_stream().next().await;
851            let (selectors, responder) = assert_matches!(
852                request,
853                Some(Ok(LogSettingsRequest::SetInterest { selectors, responder })) =>
854                (selectors, responder)
855            );
856            responder.send().unwrap();
857            assert_eq!(
858                selectors,
859                vec![parse_log_interest_selector(
860                    "core/something/a:b/elements:main/otherstuff:*#DEBUG"
861                )
862                .unwrap()]
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
