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    /// if enabled, prefer using the component URL for the component name over the moniker.
302    #[argh(switch)]
303    pub prefer_url_component_name: bool,
304
305    /// if enabled, do not prefer using the component URL for the component name over the moniker.
306    #[argh(switch)]
307    pub noprefer_url_component_name: bool,
308
309    /// hide the moniker field from output (does not exclude any log messages)
310    #[argh(switch)]
311    pub hide_moniker: bool,
312
313    /// how to display log timestamps.
314    /// Options are "utc", "local", or "boot" (i.e. nanos since target boot).
315    /// Default is boot.
316    #[argh(option, default = "TimeFormat::Boot")]
317    pub clock: TimeFormat,
318
319    /// configure symbolization options. Valid options are:
320    /// - pretty (default): pretty concise symbolization
321    /// - off: disables all symbolization
322    /// - classic: traditional, non-prettified symbolization
323    #[cfg(not(target_os = "fuchsia"))]
324    #[argh(option, default = "SymbolizeMode::Pretty")]
325    pub symbolize: SymbolizeMode,
326
327    /// configure the log settings on the target device for components matching
328    /// the given selector. This modifies the minimum log severity level emitted
329    /// by components during the logging session.
330    /// Specify using the format <component-selector>#<log-level>, with level
331    /// as one of FATAL|ERROR|WARN|INFO|DEBUG|TRACE.
332    /// May be repeated and it's also possible to pass multiple comma-separated
333    /// strings per invocation.
334    /// Cannot be used in conjunction with --set-severity-persist.
335    #[argh(option, from_str_fn(log_interest_selector))]
336    pub set_severity: Vec<OneOrMany<LogInterestSelector>>,
337
338    /// filters by pid
339    #[argh(option)]
340    pub pid: Option<u64>,
341
342    /// filters by tid
343    #[argh(option)]
344    pub tid: Option<u64>,
345
346    /// if enabled, selectors will be passed directly to Archivist without any filtering.
347    /// If disabled and no matching components are found, the user will be prompted to
348    /// either enable this or be given a list of selectors to choose from.
349    /// This applies to both --set-severity and --set-severity-persist.
350    #[argh(switch)]
351    pub force_set_severity: bool,
352
353    /// enables structured JSON logs.
354    #[cfg(target_os = "fuchsia")]
355    #[argh(switch)]
356    pub json: bool,
357
358    /// disable automatic reconnect
359    #[cfg(not(target_os = "fuchsia"))]
360    #[argh(switch)]
361    pub disable_reconnect: bool,
362}
363
364impl Default for LogCommand {
365    fn default() -> Self {
366        LogCommand {
367            filter: vec![],
368            moniker: vec![],
369            component: vec![],
370            exclude: vec![],
371            tag: vec![],
372            exclude_tags: vec![],
373            hide_tags: false,
374            hide_file: false,
375            clock: TimeFormat::Boot,
376            no_color: false,
377            kernel: false,
378            severity: Severity::Info,
379            show_metadata: false,
380            force_set_severity: false,
381            since: None,
382            since_boot: None,
383            until: None,
384            case_sensitive: false,
385            until_boot: None,
386            sub_command: None,
387            set_severity: vec![],
388            show_full_moniker: false,
389            prefer_url_component_name: false,
390            noprefer_url_component_name: false,
391            hide_moniker: false,
392            pid: None,
393            tid: None,
394            #[cfg(target_os = "fuchsia")]
395            json: false,
396            #[cfg(not(target_os = "fuchsia"))]
397            disable_reconnect: false,
398            #[cfg(not(target_os = "fuchsia"))]
399            symbolize: SymbolizeMode::Pretty,
400        }
401    }
402}
403
404/// Result returned from processing logs
405#[derive(PartialEq, Debug)]
406pub enum LogProcessingResult {
407    /// The caller should exit
408    Exit,
409    /// The caller should continue processing logs
410    Continue,
411}
412
413impl FromStr for SymbolizeMode {
414    type Err = anyhow::Error;
415
416    fn from_str(s: &str) -> Result<Self, Self::Err> {
417        let s = s.to_lowercase();
418        match s.as_str() {
419            "off" => Ok(SymbolizeMode::Off),
420            "pretty" => Ok(SymbolizeMode::Pretty),
421            "classic" => Ok(SymbolizeMode::Classic),
422            other => Err(format_err!("invalid symbolize flag: {}", other)),
423        }
424    }
425}
426
427#[derive(Error, Debug)]
428pub enum LogError {
429    #[error(transparent)]
430    UnknownError(#[from] anyhow::Error),
431    #[error("No boot timestamp")]
432    NoBootTimestamp,
433    #[error(transparent)]
434    IOError(#[from] std::io::Error),
435    #[error("Cannot use dump with --since now")]
436    DumpWithSinceNow,
437    #[error("No symbolizer configuration provided")]
438    NoSymbolizerConfig,
439    #[error(transparent)]
440    FfxError(#[from] FfxError),
441    #[error(transparent)]
442    Utf8Error(#[from] FromUtf8Error),
443    #[error(transparent)]
444    FidlError(#[from] fidl::Error),
445    #[error(transparent)]
446    FormatterError(#[from] FormatterError),
447    #[error("Deprecated flag: `{flag}`, use: `{new_flag}`")]
448    DeprecatedFlag { flag: &'static str, new_flag: &'static str },
449    #[error("Fuzzy matching failed due to too many matches, please re-try with one of these:\n{0}")]
450    FuzzyMatchTooManyMatches(String),
451    #[error("No running components were found matching {0}")]
452    SearchParameterNotFound(String),
453}
454
455impl LogError {
456    fn too_many_fuzzy_matches(matches: impl Iterator<Item = String>) -> Self {
457        let mut result = String::new();
458        for component in matches {
459            result.push_str(&component);
460            result.push('\n');
461        }
462
463        Self::FuzzyMatchTooManyMatches(result)
464    }
465}
466
467/// Trait used to get available instances given a moniker query.
468#[async_trait::async_trait(?Send)]
469pub trait InstanceGetter {
470    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError>;
471}
472
473#[async_trait::async_trait(?Send)]
474impl InstanceGetter for RealmQueryProxy {
475    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
476        Ok(get_instances_from_query(query, self)
477            .await?
478            .into_iter()
479            .map(|value| value.moniker)
480            .collect())
481    }
482}
483
484impl LogCommand {
485    async fn map_interest_selectors<'a>(
486        realm_query: &impl InstanceGetter,
487        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
488    ) -> Result<impl Iterator<Item = Cow<'a, LogInterestSelector>>, LogError> {
489        let selectors = Self::get_selectors_and_monikers(interest_selectors);
490        let mut translated_selectors = vec![];
491        for (moniker, selector) in selectors {
492            // Attempt to translate to a single instance
493            let instances = realm_query.get_monikers_from_query(moniker.as_str()).await?;
494            // If exactly one match, perform rewrite
495            if instances.len() == 1 {
496                let mut translated_selector = selector.clone();
497                translated_selector.selector = instances[0].clone().into_component_selector();
498                translated_selectors.push((Cow::Owned(translated_selector), instances));
499            } else {
500                translated_selectors.push((Cow::Borrowed(selector), instances));
501            }
502        }
503        if translated_selectors.iter().any(|(_, matches)| matches.len() > 1) {
504            let mut err_output = vec![];
505            writeln!(
506                &mut err_output,
507                "WARN: One or more of your selectors appears to be ambiguous"
508            )?;
509            writeln!(&mut err_output, "and may not match any components on your system.\n")?;
510            writeln!(
511                &mut err_output,
512                "If this is unintentional you can explicitly match using the"
513            )?;
514            writeln!(&mut err_output, "following command:\n")?;
515            writeln!(&mut err_output, "ffx log \\")?;
516            let mut output = vec![];
517            for (oselector, instances) in translated_selectors {
518                for selector in instances {
519                    writeln!(
520                        output,
521                        "\t--set-severity {}#{} \\",
522                        sanitize_moniker_for_selectors(selector.to_string().as_str())
523                            .replace("\\", "\\\\"),
524                        format!("{:?}", oselector.interest.min_severity.unwrap()).to_uppercase()
525                    )?;
526                }
527            }
528            // Intentionally ignored, removes the newline, space, and \
529            let _ = output.pop();
530            let _ = output.pop();
531            let _ = output.pop();
532
533            writeln!(&mut err_output, "{}", String::from_utf8(output).unwrap())?;
534            writeln!(&mut err_output, "\nIf this is intentional, you can disable this with")?;
535            writeln!(&mut err_output, "ffx log --force-set-severity.")?;
536
537            ffx_bail!("{}", String::from_utf8(err_output)?);
538        }
539        Ok(translated_selectors.into_iter().map(|(selector, _)| selector))
540    }
541
542    pub fn validate_cmd_flags_with_warnings(&mut self) -> Result<Vec<&'static str>, LogError> {
543        let mut warnings = vec![];
544
545        if !self.moniker.is_empty() {
546            warnings.push("WARNING: --moniker is deprecated, use --component instead");
547            if self.component.is_empty() {
548                self.component = std::mem::take(&mut self.moniker);
549            } else {
550                warnings.push("WARNING: ignoring --moniker arguments in favor of --component");
551            }
552        }
553
554        Ok(warnings)
555    }
556
557    /// Sets interest based on configured selectors.
558    /// If a single ambiguous match is found, the monikers in the selectors
559    /// are automatically re-written.
560    pub async fn maybe_set_interest(
561        &self,
562        log_settings_client: &LogSettingsProxy,
563        realm_query: &impl InstanceGetter,
564    ) -> Result<(), LogError> {
565        let (set_severity, force_set_severity, persist) =
566            if let Some(LogSubCommand::SetSeverity(options)) = &self.sub_command {
567                // No other argument can exist in conjunction with SetSeverity
568                let default_cmd = LogCommand {
569                    sub_command: Some(LogSubCommand::SetSeverity(options.clone())),
570                    ..Default::default()
571                };
572                if &default_cmd != self {
573                    ffx_bail!("Cannot combine set-severity with other options.");
574                }
575                (&options.interest_selector, options.force, !options.no_persist)
576            } else {
577                (&self.set_severity, self.force_set_severity, false)
578            };
579
580        if persist || !set_severity.is_empty() {
581            let selectors = if force_set_severity {
582                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
583            } else {
584                let new_selectors =
585                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
586                        .await?
587                        .map(|s| s.into_owned())
588                        .collect::<Vec<_>>();
589                if new_selectors.is_empty() {
590                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
591                } else {
592                    new_selectors
593                }
594            };
595            log_settings_client
596                .set_component_interest(
597                    &flex_fuchsia_diagnostics::LogSettingsSetComponentInterestRequest {
598                        selectors: Some(selectors),
599                        persist: Some(persist),
600                        ..Default::default()
601                    },
602                )
603                .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                    flex_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 flex_fuchsia_diagnostics::{LogSettingsMarker, LogSettingsRequest};
660    use futures_util::StreamExt;
661    use futures_util::future::Either;
662    use futures_util::stream::FuturesUnordered;
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 (payload, responder) = assert_matches!(
813                request,
814                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
815                (payload, responder)
816            );
817            responder.send().unwrap();
818            assert_eq!(
819                payload.selectors,
820                Some(vec![
821                    parse_log_interest_selector("core/some/ambiguous_selector#INFO").unwrap()
822                ])
823            );
824        }));
825        while scheduler.next().await.is_some() {}
826        drop(scheduler);
827        assert_matches!(set_interest_result, Some(Ok(())));
828    }
829
830    #[fuchsia::test]
831    async fn logger_uses_specified_selectors_if_no_results_returned() {
832        let cmd = LogCommand {
833            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
834            set_severity: vec![OneOrMany::One(
835                parse_log_interest_selector("core/something/a:b/elements:main/otherstuff:*#DEBUG")
836                    .unwrap(),
837            )],
838            ..LogCommand::default()
839        };
840        let mut set_interest_result = None;
841        let getter = FakeInstanceGetter {
842            expected_selector: Some("core/something/a:b/elements:main/otherstuff:*#DEBUG".into()),
843            output: vec![],
844        };
845        let scheduler = FuturesUnordered::new();
846        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
847        scheduler.push(Either::Left(async {
848            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
849            drop(settings_proxy);
850        }));
851        scheduler.push(Either::Right(async {
852            let request = settings_server.into_stream().next().await;
853            let (payload, responder) = assert_matches!(
854                request,
855                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
856                (payload, responder)
857            );
858            responder.send().unwrap();
859            assert_eq!(
860                payload.selectors,
861                Some(vec![
862                    parse_log_interest_selector(
863                        "core/something/a:b/elements:main/otherstuff:*#DEBUG"
864                    )
865                    .unwrap()
866                ])
867            );
868        }));
869        scheduler.map(|_| Ok(())).forward(futures::sink::drain()).await.unwrap();
870        assert_matches!(set_interest_result, Some(Ok(())));
871    }
872
873    #[fuchsia::test]
874    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used() {
875        let cmd = LogCommand {
876            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
877                no_persist: true,
878                interest_selector: vec![OneOrMany::One(
879                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
880                )],
881                force: true,
882            })),
883            ..LogCommand::default()
884        };
885        let getter = FakeInstanceGetter {
886            expected_selector: Some("ambiguous_selector".into()),
887            output: vec![
888                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
889                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
890            ],
891        };
892        let mut set_interest_result = None;
893        let mut scheduler = FuturesUnordered::new();
894        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
895        scheduler.push(Either::Left(async {
896            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
897            drop(settings_proxy);
898        }));
899        scheduler.push(Either::Right(async {
900            let request = settings_server.into_stream().next().await;
901            let (payload, responder) = assert_matches!(
902                request,
903                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
904                (payload, responder)
905            );
906            responder.send().unwrap();
907            assert_eq!(
908                payload.selectors,
909                Some(vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()])
910            );
911        }));
912        while scheduler.next().await.is_some() {}
913        drop(scheduler);
914        assert_matches!(set_interest_result, Some(Ok(())));
915    }
916
917    #[fuchsia::test]
918    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used_persistent() {
919        let cmd = LogCommand {
920            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
921                no_persist: false,
922                interest_selector: vec![log_socket_stream::OneOrMany::One(
923                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
924                )],
925                force: true,
926            })),
927            ..LogCommand::default()
928        };
929        let getter = FakeInstanceGetter {
930            expected_selector: Some("ambiguous_selector".into()),
931            output: vec![
932                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
933                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
934            ],
935        };
936        let mut set_interest_result = None;
937        let mut scheduler = FuturesUnordered::new();
938        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
939        scheduler.push(Either::Left(async {
940            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
941            drop(settings_proxy);
942        }));
943        scheduler.push(Either::Right(async {
944            let request = settings_server.into_stream().next().await;
945            let (payload, responder) = assert_matches!(
946                request,
947                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
948                (payload, responder)
949            );
950            responder.send().unwrap();
951            assert_eq!(
952                payload.selectors,
953                Some(vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()])
954            );
955            assert_eq!(payload.persist, Some(true));
956        }));
957        while scheduler.next().await.is_some() {}
958        drop(scheduler);
959        assert_matches!(set_interest_result, Some(Ok(())));
960    }
961
962    #[fuchsia::test]
963    async fn logger_prints_ignores_ambiguity_if_machine_output_is_used() {
964        let cmd = LogCommand {
965            sub_command: Some(LogSubCommand::Dump(DumpCommand {})),
966            set_severity: vec![OneOrMany::One(
967                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
968            )],
969            force_set_severity: true,
970            ..LogCommand::default()
971        };
972        let getter = FakeInstanceGetter {
973            expected_selector: Some("ambiguous_selector".into()),
974            output: vec![
975                Moniker::try_from("core/some/collection:thing/test").unwrap(),
976                Moniker::try_from("core/other/collection:thing/test").unwrap(),
977            ],
978        };
979        let mut set_interest_result = None;
980        let mut scheduler = FuturesUnordered::new();
981        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
982        scheduler.push(Either::Left(async {
983            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
984            drop(settings_proxy);
985        }));
986        scheduler.push(Either::Right(async {
987            let request = settings_server.into_stream().next().await;
988            let (payload, responder) = assert_matches!(
989                request,
990                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
991                (payload, responder)
992            );
993            responder.send().unwrap();
994            assert_eq!(
995                payload.selectors,
996                Some(vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()])
997            );
998        }));
999        while scheduler.next().await.is_some() {}
1000        drop(scheduler);
1001        assert_matches!(set_interest_result, Some(Ok(())));
1002    }
1003    #[test]
1004    fn test_parse_selector() {
1005        assert_eq!(
1006            log_interest_selector("core/audio#DEBUG").unwrap(),
1007            OneOrMany::One(parse_log_interest_selector("core/audio#DEBUG").unwrap())
1008        );
1009    }
1010
1011    #[test]
1012    fn test_parse_selector_with_commas() {
1013        assert_eq!(
1014            log_interest_selector("core/audio#DEBUG,bootstrap/archivist#TRACE").unwrap(),
1015            OneOrMany::Many(vec![
1016                parse_log_interest_selector("core/audio#DEBUG").unwrap(),
1017                parse_log_interest_selector("bootstrap/archivist#TRACE").unwrap()
1018            ])
1019        );
1020    }
1021
1022    #[test]
1023    fn test_parse_time() {
1024        assert!(parse_time("now").unwrap().is_now);
1025        let date_string = "04/20/2020";
1026        let res = parse_time(date_string).unwrap();
1027        assert!(!res.is_now);
1028        assert_eq!(
1029            res.date_naive(),
1030            parse_date_string(date_string, Local::now(), Dialect::Us).unwrap().date_naive()
1031        );
1032    }
1033}
log_command/lib.rs

log_command/
lib.rs
