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

log_command/
lib.rs
