log_command_ctf/
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(any(feature = "fdomain", feature = "ctf")))]
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"))]
29pub mod 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#[cfg(not(feature = "ctf"))]
554#[async_trait::async_trait(?Send)]
555impl InstanceGetter for RealmQueryProxy {
556    async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
557        Ok(get_instances_from_query(query, self)
558            .await?
559            .into_iter()
560            .map(|value| value.moniker)
561            .collect())
562    }
563}
564
565#[cfg(feature = "ctf")]
566#[async_trait::async_trait(?Send)]
567impl InstanceGetter for RealmQueryProxy {
568    async fn get_monikers_from_query(&self, _query: &str) -> Result<Vec<Moniker>, LogError> {
569        unreachable!("get_monikers_from_query is not supported in CTF tests.");
570    }
571}
572
573impl LogCommand {
574    async fn map_interest_selectors<'a>(
575        realm_query: &impl InstanceGetter,
576        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
577    ) -> Result<impl Iterator<Item = Cow<'a, LogInterestSelector>>, LogError> {
578        let selectors = Self::get_selectors_and_monikers(interest_selectors);
579        let mut translated_selectors = vec![];
580        for (moniker, selector) in selectors {
581            // Attempt to translate to a single instance
582            let instances = realm_query.get_monikers_from_query(moniker.as_str()).await?;
583            // If exactly one match, perform rewrite
584            if instances.len() == 1 {
585                let mut translated_selector = selector.clone();
586                translated_selector.selector = instances[0].clone().into_component_selector();
587                translated_selectors.push((Cow::Owned(translated_selector), instances));
588            } else {
589                translated_selectors.push((Cow::Borrowed(selector), instances));
590            }
591        }
592        if translated_selectors.iter().any(|(_, matches)| matches.len() > 1) {
593            let mut err_output = vec![];
594            writeln!(
595                &mut err_output,
596                "WARN: One or more of your selectors appears to be ambiguous"
597            )?;
598            writeln!(&mut err_output, "and may not match any components on your system.\n")?;
599            writeln!(
600                &mut err_output,
601                "If this is unintentional you can explicitly match using the"
602            )?;
603            writeln!(&mut err_output, "following command:\n")?;
604            writeln!(&mut err_output, "ffx log \\")?;
605            let mut output = vec![];
606            for (oselector, instances) in translated_selectors {
607                for selector in instances {
608                    writeln!(
609                        output,
610                        "\t--set-severity {}#{} \\",
611                        sanitize_moniker_for_selectors(selector.to_string().as_str())
612                            .replace("\\", "\\\\"),
613                        format!("{:?}", oselector.interest.min_severity.unwrap()).to_uppercase()
614                    )?;
615                }
616            }
617            // Intentionally ignored, removes the newline, space, and \
618            let _ = output.pop();
619            let _ = output.pop();
620            let _ = output.pop();
621
622            writeln!(&mut err_output, "{}", String::from_utf8(output).unwrap())?;
623            writeln!(&mut err_output, "\nIf this is intentional, you can disable this with")?;
624            writeln!(&mut err_output, "ffx log --force-set-severity.")?;
625
626            ffx_bail!("{}", String::from_utf8(err_output)?);
627        }
628        Ok(translated_selectors.into_iter().map(|(selector, _)| selector))
629    }
630
631    pub fn validate_cmd_flags_with_warnings(&mut self) -> Result<Vec<&'static str>, LogError> {
632        let mut warnings = vec![];
633
634        if !self.moniker.is_empty() {
635            warnings.push("WARNING: --moniker is deprecated, use --component instead");
636            if self.component.is_empty() {
637                self.component = std::mem::take(&mut self.moniker);
638            } else {
639                warnings.push("WARNING: ignoring --moniker arguments in favor of --component");
640            }
641        }
642
643        Ok(warnings)
644    }
645
646    /// Sets interest based on configured selectors.
647    /// If a single ambiguous match is found, the monikers in the selectors
648    /// are automatically re-written.
649    pub async fn maybe_set_interest(
650        &self,
651        log_settings_client: &LogSettingsProxy,
652        realm_query: &impl InstanceGetter,
653    ) -> Result<(), LogError> {
654        let (set_severity, force_set_severity, persist) =
655            if let Some(LogSubCommand::SetSeverity(options)) = &self.sub_command {
656                // No other argument can exist in conjunction with SetSeverity
657                let default_cmd = LogCommand {
658                    sub_command: Some(LogSubCommand::SetSeverity(options.clone())),
659                    ..Default::default()
660                };
661                if &default_cmd != self {
662                    ffx_bail!("Cannot combine set-severity with other options.");
663                }
664                (&options.interest_selector, options.force, !options.no_persist)
665            } else {
666                (&self.set_severity, self.force_set_severity, false)
667            };
668
669        if persist || !set_severity.is_empty() {
670            let selectors = if force_set_severity {
671                set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
672            } else {
673                let new_selectors =
674                    Self::map_interest_selectors(realm_query, set_severity.iter().flatten())
675                        .await?
676                        .map(|s| s.into_owned())
677                        .collect::<Vec<_>>();
678                if new_selectors.is_empty() {
679                    set_severity.clone().into_iter().flatten().collect::<Vec<_>>()
680                } else {
681                    new_selectors
682                }
683            };
684            log_settings_client
685                .set_component_interest(
686                    &flex_fuchsia_diagnostics::LogSettingsSetComponentInterestRequest {
687                        selectors: Some(selectors),
688                        persist: Some(persist),
689                        ..Default::default()
690                    },
691                )
692                .await?;
693        }
694
695        Ok(())
696    }
697
698    fn get_selectors_and_monikers<'a>(
699        interest_selectors: impl Iterator<Item = &'a LogInterestSelector>,
700    ) -> Vec<(String, &'a LogInterestSelector)> {
701        let mut selectors = vec![];
702        for selector in interest_selectors {
703            let segments = selector.selector.moniker_segments.as_ref().unwrap();
704            let mut full_moniker = String::new();
705            for segment in segments {
706                match segment {
707                    flex_fuchsia_diagnostics::StringSelector::ExactMatch(segment) => {
708                        if full_moniker.is_empty() {
709                            full_moniker.push_str(segment);
710                        } else {
711                            full_moniker.push('/');
712                            full_moniker.push_str(segment);
713                        }
714                    }
715                    _ => {
716                        // If the user passed a non-exact match we assume they
717                        // know what they're doing and skip this logic.
718                        return vec![];
719                    }
720                }
721            }
722            selectors.push((full_moniker, selector));
723        }
724        selectors
725    }
726}
727
728impl TopLevelCommand for LogCommand {}
729
730fn log_interest_selector(s: &str) -> Result<OneOrMany<LogInterestSelector>, String> {
731    if s.contains(",") {
732        let many: Result<Vec<LogInterestSelector>, String> = s
733            .split(",")
734            .map(|value| selectors::parse_log_interest_selector(value).map_err(|e| e.to_string()))
735            .collect();
736        Ok(OneOrMany::Many(many?))
737    } else {
738        Ok(OneOrMany::One(selectors::parse_log_interest_selector(s).map_err(|s| s.to_string())?))
739    }
740}
741
742#[cfg(test)]
743mod test {
744    use super::*;
745    use assert_matches::assert_matches;
746    use async_trait::async_trait;
747    use fidl::endpoints::create_proxy;
748    use flex_fuchsia_diagnostics::{LogSettingsMarker, LogSettingsRequest};
749    use futures_util::StreamExt;
750    use futures_util::future::Either;
751    use futures_util::stream::FuturesUnordered;
752    use selectors::parse_log_interest_selector;
753
754    #[derive(Default)]
755    struct FakeInstanceGetter {
756        output: Vec<Moniker>,
757        expected_selector: Option<String>,
758    }
759
760    #[async_trait(?Send)]
761    impl InstanceGetter for FakeInstanceGetter {
762        async fn get_monikers_from_query(&self, query: &str) -> Result<Vec<Moniker>, LogError> {
763            if let Some(expected) = &self.expected_selector {
764                assert_eq!(expected, query);
765            }
766            Ok(self.output.clone())
767        }
768    }
769
770    #[fuchsia::test]
771    async fn test_symbolize_mode_from_str() {
772        assert_matches!(SymbolizeMode::from_str("off"), Ok(value) if value == SymbolizeMode::Off);
773        assert_matches!(
774            SymbolizeMode::from_str("pretty"),
775            Ok(value) if value == SymbolizeMode::Pretty
776        );
777        assert_matches!(
778            SymbolizeMode::from_str("classic"),
779            Ok(value) if value == SymbolizeMode::Classic
780        );
781    }
782
783    #[fuchsia::test]
784    async fn maybe_set_interest_errors_additional_arguments_passed_to_set_interest() {
785        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
786        let getter = FakeInstanceGetter {
787            expected_selector: Some("ambiguous_selector".into()),
788            output: vec![
789                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
790                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
791            ],
792        };
793        // Main should return an error
794
795        let cmd = LogCommand {
796            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
797                interest_selector: vec![OneOrMany::One(
798                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
799                )],
800                force: false,
801                no_persist: false,
802            })),
803            hide_file: true,
804            ..LogCommand::default()
805        };
806        let mut set_interest_result = None;
807
808        let mut scheduler = FuturesUnordered::new();
809        scheduler.push(Either::Left(async {
810            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
811            drop(settings_proxy);
812        }));
813        scheduler.push(Either::Right(async {
814            let request = settings_server.into_stream().next().await;
815            // The channel should be closed without sending any requests.
816            assert_matches!(request, None);
817        }));
818        while scheduler.next().await.is_some() {}
819        drop(scheduler);
820
821        let error = format!("{}", set_interest_result.unwrap().unwrap_err());
822
823        const EXPECTED_INTEREST_ERROR: &str = "Cannot combine set-severity with other options.";
824        assert_eq!(error, EXPECTED_INTEREST_ERROR);
825    }
826
827    #[fuchsia::test]
828    async fn maybe_set_interest_errors_if_ambiguous_selector() {
829        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
830        let getter = FakeInstanceGetter {
831            expected_selector: Some("ambiguous_selector".into()),
832            output: vec![
833                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
834                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
835            ],
836        };
837        // Main should return an error
838
839        let cmd = LogCommand {
840            sub_command: Some(LogSubCommand::Dump(DumpCommand::default())),
841            set_severity: vec![OneOrMany::One(
842                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
843            )],
844            ..LogCommand::default()
845        };
846        let mut set_interest_result = None;
847
848        let mut scheduler = FuturesUnordered::new();
849        scheduler.push(Either::Left(async {
850            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
851            drop(settings_proxy);
852        }));
853        scheduler.push(Either::Right(async {
854            let request = settings_server.into_stream().next().await;
855            // The channel should be closed without sending any requests.
856            assert_matches!(request, None);
857        }));
858        while scheduler.next().await.is_some() {}
859        drop(scheduler);
860
861        let error = format!("{}", set_interest_result.unwrap().unwrap_err());
862
863        const EXPECTED_INTEREST_ERROR: &str = r#"WARN: One or more of your selectors appears to be ambiguous
864and may not match any components on your system.
865
866If this is unintentional you can explicitly match using the
867following command:
868
869ffx log \
870	--set-severity core/some/ambiguous_selector\\:thing/test#INFO \
871	--set-severity core/other/ambiguous_selector\\:thing/test#INFO
872
873If this is intentional, you can disable this with
874ffx log --force-set-severity.
875"#;
876        assert_eq!(error, EXPECTED_INTEREST_ERROR);
877    }
878
879    #[fuchsia::test]
880    async fn logger_translates_selector_if_one_match() {
881        let cmd = LogCommand {
882            sub_command: Some(LogSubCommand::Dump(DumpCommand::default())),
883            set_severity: vec![OneOrMany::One(
884                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
885            )],
886            ..LogCommand::default()
887        };
888        let mut set_interest_result = None;
889        let getter = FakeInstanceGetter {
890            expected_selector: Some("ambiguous_selector".into()),
891            output: vec![Moniker::try_from("core/some/ambiguous_selector").unwrap()],
892        };
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![
910                    parse_log_interest_selector("core/some/ambiguous_selector#INFO").unwrap()
911                ])
912            );
913        }));
914        while scheduler.next().await.is_some() {}
915        drop(scheduler);
916        assert_matches!(set_interest_result, Some(Ok(())));
917    }
918
919    #[fuchsia::test]
920    async fn logger_uses_specified_selectors_if_no_results_returned() {
921        let cmd = LogCommand {
922            sub_command: Some(LogSubCommand::Dump(DumpCommand::default())),
923            set_severity: vec![OneOrMany::One(
924                parse_log_interest_selector("core/something/a:b/elements:main/otherstuff:*#DEBUG")
925                    .unwrap(),
926            )],
927            ..LogCommand::default()
928        };
929        let mut set_interest_result = None;
930        let getter = FakeInstanceGetter {
931            expected_selector: Some("core/something/a:b/elements:main/otherstuff:*#DEBUG".into()),
932            output: vec![],
933        };
934        let scheduler = FuturesUnordered::new();
935        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
936        scheduler.push(Either::Left(async {
937            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
938            drop(settings_proxy);
939        }));
940        scheduler.push(Either::Right(async {
941            let request = settings_server.into_stream().next().await;
942            let (payload, responder) = assert_matches!(
943                request,
944                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
945                (payload, responder)
946            );
947            responder.send().unwrap();
948            assert_eq!(
949                payload.selectors,
950                Some(vec![
951                    parse_log_interest_selector(
952                        "core/something/a:b/elements:main/otherstuff:*#DEBUG"
953                    )
954                    .unwrap()
955                ])
956            );
957        }));
958        scheduler.map(|_| Ok(())).forward(futures::sink::drain()).await.unwrap();
959        assert_matches!(set_interest_result, Some(Ok(())));
960    }
961
962    #[fuchsia::test]
963    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used() {
964        let cmd = LogCommand {
965            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
966                no_persist: true,
967                interest_selector: vec![OneOrMany::One(
968                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
969                )],
970                force: true,
971            })),
972            ..LogCommand::default()
973        };
974        let getter = FakeInstanceGetter {
975            expected_selector: Some("ambiguous_selector".into()),
976            output: vec![
977                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
978                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
979            ],
980        };
981        let mut set_interest_result = None;
982        let mut scheduler = FuturesUnordered::new();
983        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
984        scheduler.push(Either::Left(async {
985            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
986            drop(settings_proxy);
987        }));
988        scheduler.push(Either::Right(async {
989            let request = settings_server.into_stream().next().await;
990            let (payload, responder) = assert_matches!(
991                request,
992                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
993                (payload, responder)
994            );
995            responder.send().unwrap();
996            assert_eq!(
997                payload.selectors,
998                Some(vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()])
999            );
1000        }));
1001        while scheduler.next().await.is_some() {}
1002        drop(scheduler);
1003        assert_matches!(set_interest_result, Some(Ok(())));
1004    }
1005
1006    #[fuchsia::test]
1007    async fn logger_prints_ignores_ambiguity_if_force_set_severity_is_used_persistent() {
1008        let cmd = LogCommand {
1009            sub_command: Some(LogSubCommand::SetSeverity(SetSeverityCommand {
1010                no_persist: false,
1011                interest_selector: vec![log_socket_stream::OneOrMany::One(
1012                    parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
1013                )],
1014                force: true,
1015            })),
1016            ..LogCommand::default()
1017        };
1018        let getter = FakeInstanceGetter {
1019            expected_selector: Some("ambiguous_selector".into()),
1020            output: vec![
1021                Moniker::try_from("core/some/ambiguous_selector:thing/test").unwrap(),
1022                Moniker::try_from("core/other/ambiguous_selector:thing/test").unwrap(),
1023            ],
1024        };
1025        let mut set_interest_result = None;
1026        let mut scheduler = FuturesUnordered::new();
1027        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
1028        scheduler.push(Either::Left(async {
1029            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
1030            drop(settings_proxy);
1031        }));
1032        scheduler.push(Either::Right(async {
1033            let request = settings_server.into_stream().next().await;
1034            let (payload, responder) = assert_matches!(
1035                request,
1036                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
1037                (payload, responder)
1038            );
1039            responder.send().unwrap();
1040            assert_eq!(
1041                payload.selectors,
1042                Some(vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()])
1043            );
1044            assert_eq!(payload.persist, Some(true));
1045        }));
1046        while scheduler.next().await.is_some() {}
1047        drop(scheduler);
1048        assert_matches!(set_interest_result, Some(Ok(())));
1049    }
1050
1051    #[fuchsia::test]
1052    async fn logger_prints_ignores_ambiguity_if_machine_output_is_used() {
1053        let cmd = LogCommand {
1054            sub_command: Some(LogSubCommand::Dump(DumpCommand::default())),
1055            set_severity: vec![OneOrMany::One(
1056                parse_log_interest_selector("ambiguous_selector#INFO").unwrap(),
1057            )],
1058            force_set_severity: true,
1059            ..LogCommand::default()
1060        };
1061        let getter = FakeInstanceGetter {
1062            expected_selector: Some("ambiguous_selector".into()),
1063            output: vec![
1064                Moniker::try_from("core/some/collection:thing/test").unwrap(),
1065                Moniker::try_from("core/other/collection:thing/test").unwrap(),
1066            ],
1067        };
1068        let mut set_interest_result = None;
1069        let mut scheduler = FuturesUnordered::new();
1070        let (settings_proxy, settings_server) = create_proxy::<LogSettingsMarker>();
1071        scheduler.push(Either::Left(async {
1072            set_interest_result = Some(cmd.maybe_set_interest(&settings_proxy, &getter).await);
1073            drop(settings_proxy);
1074        }));
1075        scheduler.push(Either::Right(async {
1076            let request = settings_server.into_stream().next().await;
1077            let (payload, responder) = assert_matches!(
1078                request,
1079                Some(Ok(LogSettingsRequest::SetComponentInterest { payload, responder })) =>
1080                (payload, responder)
1081            );
1082            responder.send().unwrap();
1083            assert_eq!(
1084                payload.selectors,
1085                Some(vec![parse_log_interest_selector("ambiguous_selector#INFO").unwrap()])
1086            );
1087        }));
1088        while scheduler.next().await.is_some() {}
1089        drop(scheduler);
1090        assert_matches!(set_interest_result, Some(Ok(())));
1091    }
1092    #[test]
1093    fn test_parse_selector() {
1094        assert_eq!(
1095            log_interest_selector("core/audio#DEBUG").unwrap(),
1096            OneOrMany::One(parse_log_interest_selector("core/audio#DEBUG").unwrap())
1097        );
1098    }
1099
1100    #[test]
1101    fn test_parse_selector_with_commas() {
1102        assert_eq!(
1103            log_interest_selector("core/audio#DEBUG,bootstrap/archivist#TRACE").unwrap(),
1104            OneOrMany::Many(vec![
1105                parse_log_interest_selector("core/audio#DEBUG").unwrap(),
1106                parse_log_interest_selector("bootstrap/archivist#TRACE").unwrap()
1107            ])
1108        );
1109    }
1110
1111    #[test]
1112    fn test_parse_time() {
1113        assert!(parse_time("now").unwrap().is_now);
1114        let date_string = "04/20/2020";
1115        let res = parse_time(date_string).unwrap();
1116        assert!(!res.is_now);
1117        assert_eq!(
1118            res.date_naive(),
1119            parse_date_string(date_string, Local::now(), Dialect::Us).unwrap().date_naive()
1120        );
1121    }
1122
1123    #[test]
1124    fn test_log_error_is_broken_pipe() {
1125        assert!(
1126            LogError::IOError(std::io::Error::new(std::io::ErrorKind::BrokenPipe, "broken pipe"))
1127                .is_broken_pipe()
1128        );
1129        assert!(
1130            LogError::UnknownError(anyhow::Error::new(std::io::Error::new(
1131                std::io::ErrorKind::BrokenPipe,
1132                "broken pipe"
1133            )))
1134            .is_broken_pipe()
1135        );
1136        assert!(!LogError::IOError(std::io::Error::other("other")).is_broken_pipe());
1137        assert!(!LogError::NoBootTimestamp.is_broken_pipe());
1138    }
1139}
log_command_ctf/lib.rs

log_command_ctf/
lib.rs
