wlan_telemetry/
lib.rs

1// Copyright 2024 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.
4use anyhow::{Context as _, Error, format_err};
5use fidl_fuchsia_power_battery as fidl_battery;
6use fidl_fuchsia_wlan_ieee80211 as fidl_ieee80211;
7use fidl_fuchsia_wlan_internal as fidl_internal;
8use fuchsia_async as fasync;
9use fuchsia_inspect::Node as InspectNode;
10use futures::channel::mpsc;
11use futures::{Future, StreamExt, select};
12use log::error;
13use std::boxed::Box;
14use std::sync::Arc;
15use windowed_stats::experimental::inspect::TimeMatrixClient;
16use wlan_common::bss::BssDescription;
17use wlan_legacy_metrics_registry as metrics;
18
19mod config;
20mod convert;
21mod processors;
22pub(crate) mod util;
23pub use crate::config::{CobaltAllowlist, DeviceMobility, TelemetryConfig};
24pub use crate::processors::connect_disconnect::DisconnectInfo;
25pub use crate::processors::pno_scan::PnoScanDisabledReason;
26pub use crate::processors::power::{IfacePowerLevel, UnclearPowerDemand};
27pub use crate::processors::scan::ScanResult;
28pub use crate::processors::sme_timeout::TimeoutSource;
29pub use crate::processors::toggle_events::ClientConnectionsToggleEvent;
30pub use util::sender::TelemetrySender;
31#[cfg(test)]
32mod testing;
33
34#[derive(Debug)]
35pub enum TelemetryEvent {
36    ConnectResult {
37        result: fidl_ieee80211::StatusCode,
38        bss: Box<BssDescription>,
39        is_credential_rejected: bool,
40        is_owe_transition: bool,
41    },
42    Disconnect {
43        info: DisconnectInfo,
44    },
45    ChannelSwitched {
46        channel: wlan_common::channel::Channel,
47    },
48    // We should maintain docstrings if we can see any possibility of ambiguity for an enum
49    /// Client connections enabled or disabled
50    ClientConnectionsToggle {
51        event: ClientConnectionsToggleEvent,
52    },
53    ClientIfaceCreated {
54        iface_id: u16,
55    },
56    ClientIfaceDestroyed {
57        iface_id: u16,
58    },
59    IfaceCreationFailure,
60    IfaceDestructionFailure,
61    ScanStart,
62    ScanResult {
63        result: ScanResult,
64    },
65    IfacePowerLevelChanged {
66        iface_power_level: IfacePowerLevel,
67        iface_id: u16,
68    },
69    /// System suspension imminent
70    SuspendImminent,
71    /// Unclear power level requested by policy layer
72    UnclearPowerDemand(UnclearPowerDemand),
73    BatteryChargeStatus(fidl_battery::ChargeStatus),
74    RecoveryEvent,
75    RecoveryResult {
76        result: Result<(), ()>,
77    },
78    SmeTimeout {
79        source: TimeoutSource,
80    },
81    ChipPowerUpFailure,
82    ResetTxPowerScenario,
83    SetTxPowerScenario {
84        scenario: fidl_internal::TxPowerScenario,
85    },
86    PnoScanFailure,
87    PnoScanEnabled,
88    PnoScanResultsReceived,
89    PnoScanDisabled {
90        reason: PnoScanDisabledReason,
91    },
92}
93
94/// If metrics cannot be reported for extended periods of time, logging new metrics will fail and
95/// the error messages tend to clutter up the logs.  This container limits the rate at which such
96/// potentially noisy logs are reported.  Duplicate error messages are aggregated periodically
97/// reported.
98pub struct ThrottledErrorLogger {
99    time_of_last_log: fasync::MonotonicInstant,
100    pub suppressed_errors: std::collections::HashMap<String, usize>,
101    minutes_between_reports: i64,
102}
103
104impl ThrottledErrorLogger {
105    pub fn new(minutes_between_reports: i64) -> Self {
106        Self {
107            time_of_last_log: fasync::MonotonicInstant::from_nanos(0),
108            suppressed_errors: std::collections::HashMap::new(),
109            minutes_between_reports,
110        }
111    }
112
113    pub fn throttle_log(&mut self, message: String, level: log::Level) {
114        let curr_time = fasync::MonotonicInstant::now();
115        let time_since_last_log = curr_time - self.time_of_last_log;
116
117        if time_since_last_log.into_minutes() > self.minutes_between_reports {
118            log::log!(level, "{}", message);
119            if !self.suppressed_errors.is_empty() {
120                for (log, count) in self.suppressed_errors.iter() {
121                    log::warn!("Suppressed {} instances: {}", count, log);
122                }
123                self.suppressed_errors.clear();
124            }
125            self.time_of_last_log = curr_time;
126        } else {
127            let count = self.suppressed_errors.entry(message).or_default();
128            *count += 1;
129        }
130    }
131
132    pub fn throttle_error(&mut self, result: Result<(), Error>) {
133        if let Err(e) = result {
134            self.throttle_log(e.to_string(), log::Level::Error);
135        }
136    }
137}
138
139/// Attempts to connect to the Cobalt service.
140pub async fn setup_cobalt_proxy()
141-> Result<fidl_fuchsia_metrics::MetricEventLoggerProxy, anyhow::Error> {
142    let cobalt_svc = fuchsia_component::client::connect_to_protocol::<
143        fidl_fuchsia_metrics::MetricEventLoggerFactoryMarker,
144    >()
145    .context("failed to connect to metrics service")?;
146
147    let (cobalt_proxy, cobalt_server) =
148        fidl::endpoints::create_proxy::<fidl_fuchsia_metrics::MetricEventLoggerMarker>();
149
150    let project_spec = fidl_fuchsia_metrics::ProjectSpec {
151        customer_id: Some(metrics::CUSTOMER_ID),
152        project_id: Some(metrics::PROJECT_ID),
153        ..Default::default()
154    };
155
156    match cobalt_svc.create_metric_event_logger(&project_spec, cobalt_server).await {
157        Ok(_) => Ok(cobalt_proxy),
158        Err(err) => Err(format_err!("failed to create metrics event logger: {:?}", err)),
159    }
160}
161
162/// Attempts to create a disconnected FIDL channel with types matching the Cobalt service. This
163/// allows for a fallback with a uniform code path in case of a failure to connect to Cobalt.
164pub fn setup_disconnected_cobalt_proxy()
165-> Result<fidl_fuchsia_metrics::MetricEventLoggerProxy, anyhow::Error> {
166    // Create a disconnected proxy
167    Ok(fidl::endpoints::create_proxy::<fidl_fuchsia_metrics::MetricEventLoggerMarker>().0)
168}
169
170/// How often to refresh time series stats. Also how often to request packet counters.
171const TELEMETRY_QUERY_INTERVAL: zx::MonotonicDuration = zx::MonotonicDuration::from_seconds(10);
172
173pub fn serve_telemetry(
174    cobalt_proxy: fidl_fuchsia_metrics::MetricEventLoggerProxy,
175    monitor_svc_proxy: fidl_fuchsia_wlan_device_service::DeviceMonitorProxy,
176    inspect_node: InspectNode,
177    inspect_path: &str,
178    config: TelemetryConfig,
179    allowlist: CobaltAllowlist,
180) -> (TelemetrySender, impl Future<Output = Result<(), Error>> + use<>) {
181    let (sender, mut receiver) =
182        mpsc::channel::<TelemetryEvent>(util::sender::TELEMETRY_EVENT_BUFFER_SIZE);
183    let sender = TelemetrySender::new(sender);
184
185    let cobalt_logger =
186        Arc::new(util::cobalt_logger::FilteredCobaltLogger::new(cobalt_proxy, allowlist));
187
188    // Inspect nodes to hold time series and metadata for other nodes
189    const METADATA_NODE_NAME: &str = "metadata";
190    let inspect_metadata_node = inspect_node.create_child(METADATA_NODE_NAME);
191    let inspect_metadata_path = format!("{inspect_path}/{METADATA_NODE_NAME}");
192    let inspect_time_series_node = inspect_node.create_child("time_series");
193
194    let time_matrix_client = TimeMatrixClient::new(inspect_time_series_node.clone_weak());
195
196    // Create and initialize modules
197    let connect_disconnect = config.enable_connect_disconnect.then(|| {
198        processors::connect_disconnect::ConnectDisconnectLogger::new(
199            cobalt_logger.clone(),
200            &inspect_node,
201            &inspect_metadata_node,
202            &inspect_metadata_path,
203            &time_matrix_client,
204            config.device_mobility,
205        )
206    });
207    let iface_logger = config
208        .enable_iface_logger
209        .then(|| processors::iface::IfaceLogger::new(cobalt_logger.clone()));
210    let power_logger = config
211        .enable_power_logger
212        .then(|| processors::power::PowerLogger::new(cobalt_logger.clone(), &inspect_node));
213    let recovery_logger = config
214        .enable_recovery_logger
215        .then(|| processors::recovery::RecoveryLogger::new(cobalt_logger.clone()));
216    let mut scan_logger = config
217        .enable_scan_logger
218        .then(|| processors::scan::ScanLogger::new(cobalt_logger.clone(), &time_matrix_client));
219    let mut pno_scan_logger = config
220        .enable_pno_scan_logger
221        .then(|| processors::pno_scan::PnoScanLogger::new(cobalt_logger.clone()));
222    let sme_timeout_logger = config
223        .enable_sme_timeout_logger
224        .then(|| processors::sme_timeout::SmeTimeoutLogger::new(cobalt_logger.clone()));
225    let mut toggle_logger = config.enable_toggle_logger.then(|| {
226        processors::toggle_events::ToggleLogger::new(cobalt_logger.clone(), &inspect_node)
227    });
228    let tx_power_scenario_logger = config
229        .enable_tx_power_scenario_logger
230        .then(|| processors::tx_power_scenario::TxPowerScenarioLogger::new(cobalt_logger.clone()));
231
232    let client_iface_counters_logger = config.enable_client_iface_counters_logger.then(|| {
233        let driver_specific_time_series_node =
234            inspect_time_series_node.create_child("driver_specific");
235        let driver_counters_time_series_node =
236            driver_specific_time_series_node.create_child("counters");
237        let driver_gauges_time_series_node =
238            driver_specific_time_series_node.create_child("gauges");
239
240        let driver_counters_time_series_client =
241            TimeMatrixClient::new(driver_counters_time_series_node.clone_weak());
242        let driver_gauges_time_series_client =
243            TimeMatrixClient::new(driver_gauges_time_series_node.clone_weak());
244
245        inspect_time_series_node.record(driver_specific_time_series_node);
246        inspect_time_series_node.record(driver_counters_time_series_node);
247        inspect_time_series_node.record(driver_gauges_time_series_node);
248
249        processors::client_iface_counters::ClientIfaceCountersLogger::new(
250            cobalt_logger.clone(),
251            monitor_svc_proxy,
252            &inspect_metadata_node,
253            &inspect_metadata_path,
254            &time_matrix_client,
255            driver_counters_time_series_client,
256            driver_gauges_time_series_client,
257        )
258    });
259
260    let fut = async move {
261        // Prevent the inspect nodes from being dropped while the loop is running.
262        let _inspect_node = inspect_node;
263        let _inspect_metadata_node = inspect_metadata_node;
264        let _inspect_time_series_node = inspect_time_series_node;
265
266        let mut telemetry_interval = fasync::Interval::new(TELEMETRY_QUERY_INTERVAL);
267        loop {
268            select! {
269                event = receiver.next() => {
270                    let Some(event) = event else {
271                        error!("Telemetry event stream unexpectedly terminated.");
272                        return Err(format_err!("Telemetry event stream unexpectedly terminated."));
273                    };
274                    use TelemetryEvent::*;
275                    match event {
276                        ConnectResult { result, bss, is_credential_rejected, is_owe_transition } => {
277                            if let Some(ref connect_disconnect) = connect_disconnect {
278                                connect_disconnect.handle_connect_attempt(result, &bss, is_credential_rejected, is_owe_transition).await;
279                            }
280                        }
281                        Disconnect { info } => {
282                            if let Some(ref connect_disconnect) = connect_disconnect {
283                                connect_disconnect.log_disconnect(&info).await;
284                            }
285                            if let Some(ref power_logger) = power_logger {
286                                power_logger.handle_iface_disconnect(info.iface_id).await;
287                            }
288                        }
289                        ChannelSwitched { channel } => {
290                            if let Some(ref connect_disconnect) = connect_disconnect {
291                                connect_disconnect.handle_channel_switched(channel).await;
292                            }
293                        }
294                        ClientConnectionsToggle { event } => {
295                            if let Some(ref connect_disconnect) = connect_disconnect {
296                                connect_disconnect.handle_client_connections_toggle(&event).await;
297                            }
298                            if let Some(ref mut toggle_logger) = toggle_logger {
299                                toggle_logger.handle_toggle_event(event).await;
300                            }
301                        }
302                        ClientIfaceCreated { iface_id } => {
303                            if let Some(ref client_iface_counters_logger) = client_iface_counters_logger {
304                                client_iface_counters_logger.handle_iface_created(iface_id).await;
305                            }
306                        }
307                        ClientIfaceDestroyed { iface_id } => {
308                            if let Some(ref connect_disconnect) = connect_disconnect {
309                                connect_disconnect.handle_iface_destroyed().await;
310                            }
311                            if let Some(ref client_iface_counters_logger) = client_iface_counters_logger {
312                                client_iface_counters_logger.handle_iface_destroyed(iface_id).await;
313                            }
314                            if let Some(ref power_logger) = power_logger {
315                                power_logger.handle_iface_destroyed(iface_id).await;
316                            }
317                        }
318                        IfaceCreationFailure => {
319                            if let Some(ref iface_logger) = iface_logger {
320                                iface_logger.handle_iface_creation_failure().await;
321                            }
322                        }
323                        IfaceDestructionFailure => {
324                            if let Some(ref iface_logger) = iface_logger {
325                                iface_logger.handle_iface_destruction_failure().await;
326                            }
327                        }
328                        ScanStart => {
329                            if let Some(ref mut scan_logger) = scan_logger {
330                                scan_logger.handle_scan_start().await;
331                            }
332                        }
333                        ScanResult { result } => {
334                            if let Some(ref mut scan_logger) = scan_logger {
335                                scan_logger.handle_scan_result(result).await;
336                            }
337                        }
338                        IfacePowerLevelChanged { iface_power_level, iface_id } => {
339                            if let Some(ref power_logger) = power_logger {
340                                power_logger.log_iface_power_event(iface_power_level, iface_id).await;
341                            }
342                        }
343                        // TODO(b/340921554): either watch for suspension directly in the library,
344                        // or plumb this from callers once suspend mechanisms are integrated
345                        SuspendImminent => {
346                            if let Some(ref power_logger) = power_logger {
347                                power_logger.handle_suspend_imminent().await;
348                            }
349                            if let Some(ref connect_disconnect) = connect_disconnect {
350                                connect_disconnect.handle_suspend_imminent().await;
351                            }
352                        }
353                        UnclearPowerDemand(demand) => {
354                            if let Some(ref power_logger) = power_logger {
355                                power_logger.handle_unclear_power_demand(demand).await;
356                            }
357                        }
358                        ChipPowerUpFailure => {
359                            if let Some(ref power_logger) = power_logger {
360                                power_logger.handle_chip_power_up_failure().await;
361                            }
362                            if let Some(ref connect_disconnect) = connect_disconnect {
363                                connect_disconnect.handle_client_connections_failed_to_start().await;
364                            }
365                        }
366                        BatteryChargeStatus(charge_status) => {
367                            if let Some(ref mut scan_logger) = scan_logger {
368                                scan_logger.handle_battery_charge_status(charge_status).await;
369                            }
370                            if let Some(ref mut toggle_logger) = toggle_logger {
371                                toggle_logger.handle_battery_charge_status(charge_status).await;
372                            }
373                        }
374                        RecoveryEvent => {
375                            if let Some(ref recovery_logger) = recovery_logger {
376                                recovery_logger.handle_recovery_event().await;
377                            }
378                        }
379                        RecoveryResult { result } => {
380                            if let Some(ref recovery_logger) = recovery_logger {
381                                recovery_logger.handle_recovery_result(result).await;
382                            }
383                        }
384                        SmeTimeout { source } => {
385                            if let Some(ref sme_timeout_logger) = sme_timeout_logger {
386                                sme_timeout_logger.handle_sme_timeout_event(source).await;
387                            }
388                        }
389                        ResetTxPowerScenario => {
390                            if let Some(ref tx_power_scenario_logger) = tx_power_scenario_logger {
391                                tx_power_scenario_logger.handle_sar_reset().await;
392                            }
393                        }
394                        SetTxPowerScenario {scenario} => {
395                            if let Some(ref tx_power_scenario_logger) = tx_power_scenario_logger {
396                                tx_power_scenario_logger.handle_set_sar(scenario).await;
397                            }
398                        }
399                        PnoScanFailure => {
400                            if let Some(ref connect_disconnect) = connect_disconnect {
401                                connect_disconnect.handle_pno_scan_failure().await;
402                            }
403                        }
404                        PnoScanEnabled => {
405                            if let Some(ref mut pno_scan_logger) = pno_scan_logger {
406                                let is_connected = connect_disconnect
407                                    .as_ref()
408                                    .map(|cd| cd.is_connected())
409                                    .unwrap_or(false);
410                                pno_scan_logger.handle_pno_scan_enabled(is_connected).await;
411                            }
412                        }
413                        PnoScanResultsReceived => {
414                            if let Some(ref mut pno_scan_logger) = pno_scan_logger {
415                                pno_scan_logger.handle_pno_scan_results_received().await;
416                            }
417                        }
418                        PnoScanDisabled { reason } => {
419                            if let Some(ref mut pno_scan_logger) = pno_scan_logger {
420                                pno_scan_logger.handle_pno_scan_disabled(reason).await;
421                            }
422                        }
423                    }
424                }
425                _ = telemetry_interval.next() => {
426                    if let Some(ref connect_disconnect) = connect_disconnect {
427                        connect_disconnect.handle_periodic_telemetry().await;
428                    }
429                    if let Some(ref client_iface_counters_logger) = client_iface_counters_logger {
430                        client_iface_counters_logger.handle_periodic_telemetry().await;
431                    }
432                    if let Some(ref mut pno_scan_logger) = pno_scan_logger {
433                        pno_scan_logger.handle_periodic_telemetry().await;
434                    }
435                }
436            }
437        }
438    };
439    (sender, fut)
440}
wlan_telemetry/lib.rs

wlan_telemetry/
lib.rs
