wlan_telemetry/processors/
toggle_events.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.
4
5use crate::util::cobalt_logger::log_cobalt_batch;
6use fidl_fuchsia_metrics::{MetricEvent, MetricEventPayload};
7use fuchsia_inspect::Node as InspectNode;
8use fuchsia_inspect_contrib::inspect_log;
9use fuchsia_inspect_contrib::nodes::BoundedListNode;
10use std::cmp::max;
11use {
12    fidl_fuchsia_power_battery as fidl_battery, fuchsia_async as fasync,
13    wlan_legacy_metrics_registry as metrics, zx,
14};
15
16pub const INSPECT_TOGGLE_EVENTS_LIMIT: usize = 20;
17const TIME_QUICK_TOGGLE_WIFI: zx::BootDuration = zx::BootDuration::from_seconds(5);
18
19#[derive(Debug, PartialEq)]
20pub enum ClientConnectionsToggleEvent {
21    Enabled,
22    Disabled,
23}
24
25pub struct ToggleLogger {
26    toggle_inspect_node: BoundedListNode,
27    cobalt_proxy: fidl_fuchsia_metrics::MetricEventLoggerProxy,
28    /// This is None until telemetry is notified of an off or on event, since these metrics don't
29    /// currently need to know the starting state.
30    current_state: Option<ClientConnectionsToggleEvent>,
31    /// The last time wlan was toggled on
32    time_started: Option<fasync::BootInstant>,
33    /// The last time wlan was toggled off, or None if it hasn't been. Used to determine if WLAN
34    /// was turned on right after being turned off.
35    time_stopped: Option<fasync::BootInstant>,
36    /// When the device was last on battery. This is not populated on init and when the device is
37    /// on charger.
38    on_battery_since: Option<fasync::BootInstant>,
39}
40
41impl ToggleLogger {
42    pub fn new(
43        cobalt_proxy: fidl_fuchsia_metrics::MetricEventLoggerProxy,
44        inspect_node: &InspectNode,
45    ) -> Self {
46        // Initialize inspect children
47        let toggle_events = inspect_node.create_child("client_connections_toggle_events");
48        let toggle_inspect_node = BoundedListNode::new(toggle_events, INSPECT_TOGGLE_EVENTS_LIMIT);
49        let current_state = None;
50        let time_started = None;
51        let time_stopped = None;
52        let on_battery_since = None;
53
54        Self {
55            toggle_inspect_node,
56            cobalt_proxy,
57            current_state,
58            time_started,
59            time_stopped,
60            on_battery_since,
61        }
62    }
63
64    pub async fn handle_toggle_event(&mut self, event_type: ClientConnectionsToggleEvent) {
65        // This inspect macro logs the time as well
66        inspect_log!(self.toggle_inspect_node, {
67            event_type: std::format!("{:?}", event_type)
68        });
69
70        let mut metric_events = vec![];
71        let now = fasync::BootInstant::now();
72        match &event_type {
73            ClientConnectionsToggleEvent::Enabled => {
74                // Log an occurrence if the client connection was not already enabled
75                if self.current_state != Some(ClientConnectionsToggleEvent::Enabled) {
76                    self.time_started = Some(now);
77
78                    metric_events.push(MetricEvent {
79                        metric_id: metrics::CLIENT_CONNECTION_ENABLED_OCCURRENCE_METRIC_ID,
80                        event_codes: vec![],
81                        payload: MetricEventPayload::Count(1),
82                    });
83                }
84
85                // If connections were just disabled before this, log a metric for the quick wifi
86                // restart.
87                if self.current_state == Some(ClientConnectionsToggleEvent::Disabled) {
88                    if let Some(time_stopped) = self.time_stopped {
89                        if now - time_stopped < TIME_QUICK_TOGGLE_WIFI {
90                            metric_events.push(MetricEvent {
91                                metric_id: metrics::CLIENT_CONNECTIONS_STOP_AND_START_METRIC_ID,
92                                event_codes: vec![],
93                                payload: MetricEventPayload::Count(1),
94                            });
95                        }
96                    }
97                }
98            }
99            ClientConnectionsToggleEvent::Disabled => {
100                // Only change the time and log duration if connections were not already disabled.
101                if self.current_state == Some(ClientConnectionsToggleEvent::Enabled) {
102                    self.time_stopped = Some(now);
103
104                    if let Some(time_started) = self.time_started {
105                        let duration = now - time_started;
106                        metric_events.push(MetricEvent {
107                            metric_id: metrics::CLIENT_CONNECTION_ENABLED_DURATION_METRIC_ID,
108                            event_codes: vec![],
109                            payload: MetricEventPayload::IntegerValue(duration.into_millis()),
110                        });
111
112                        // If `on_battery_since` is `Some`, it indicates that we have been
113                        // on battery, as otherwise this Option would be cleared out in
114                        // `handle_battery_charge_status`
115                        //
116                        // Here we only handle the transition from connection-enabled +
117                        // on-battery state -> connection disabled. The other case
118                        // where we transition to on charger is handled in
119                        // `handle_battery_charge_status`
120                        if let Some(on_battery_since) = self.on_battery_since {
121                            // Get the max of `time_started` and `on_battery_since` as it was
122                            // when connection is enabled *and* device is on battery
123                            let duration = now - max(time_started, on_battery_since);
124                            metric_events.push(MetricEvent {
125                                metric_id: metrics::CLIENT_CONNECTION_ENABLED_DURATION_ON_BATTERY_METRIC_ID,
126                                event_codes: vec![],
127                                payload: MetricEventPayload::IntegerValue(duration.into_millis()),
128                            });
129                        }
130                    }
131                }
132            }
133        }
134        self.current_state = Some(event_type);
135
136        log_cobalt_batch!(self.cobalt_proxy, &metric_events, "handle_toggle_events");
137    }
138
139    pub async fn handle_battery_charge_status(
140        &mut self,
141        charge_status: fidl_battery::ChargeStatus,
142    ) {
143        let mut metric_events = vec![];
144        let now = fasync::BootInstant::now();
145        let on_battery_now = matches!(charge_status, fidl_battery::ChargeStatus::Discharging);
146
147        match (self.on_battery_since, on_battery_now) {
148            (None, true) => self.on_battery_since = Some(now),
149            (Some(on_battery_since), false) => {
150                let _on_battery_since = self.on_battery_since.take();
151                // Here we only handle the transition from connection-enabled *and*
152                // on-battery state -> on-charger state. The other case
153                // where we transition to connection disabled is handled in
154                // `handle_toggle_event`
155                if let Some(ClientConnectionsToggleEvent::Enabled) = self.current_state {
156                    if let Some(time_started) = self.time_started {
157                        // Get the max of `time_started` and `on_battery_since` as it was
158                        // when connection is enabled *and* device is on battery
159                        let duration = now - max(time_started, on_battery_since);
160                        metric_events.push(MetricEvent {
161                            metric_id:
162                                metrics::CLIENT_CONNECTION_ENABLED_DURATION_ON_BATTERY_METRIC_ID,
163                            event_codes: vec![],
164                            payload: MetricEventPayload::IntegerValue(duration.into_millis()),
165                        });
166                    }
167                }
168            }
169            _ => (),
170        }
171
172        log_cobalt_batch!(self.cobalt_proxy, &metric_events, "handle_battery_charge_status");
173    }
174}
175
176#[cfg(test)]
177mod tests {
178    use super::*;
179    use crate::testing::{setup_test, TestHelper};
180    use diagnostics_assertions::{assert_data_tree, AnyNumericProperty};
181    use futures::task::Poll;
182    use std::pin::pin;
183    use wlan_common::assert_variant;
184
185    #[fuchsia::test]
186    fn test_toggle_is_recorded_to_inspect() {
187        let mut test_helper = setup_test();
188        let node = test_helper.create_inspect_node("wlan_mock_node");
189        let mut toggle_logger = ToggleLogger::new(test_helper.cobalt_proxy.clone(), &node);
190
191        let event = ClientConnectionsToggleEvent::Enabled;
192        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
193
194        let event = ClientConnectionsToggleEvent::Disabled;
195        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
196
197        let event = ClientConnectionsToggleEvent::Enabled;
198        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
199
200        assert_data_tree!(@executor test_helper.exec, test_helper.inspector, root: contains {
201            wlan_mock_node: {
202                client_connections_toggle_events: {
203                    "0": {
204                        "event_type": "Enabled",
205                        "@time": AnyNumericProperty
206                    },
207                    "1": {
208                        "event_type": "Disabled",
209                        "@time": AnyNumericProperty
210                    },
211                    "2": {
212                        "event_type": "Enabled",
213                        "@time": AnyNumericProperty
214                    },
215                }
216            }
217        });
218    }
219
220    // Uses the test helper to run toggle_logger.handle_toggle_event so that any cobalt metrics sent
221    // will be acked and not block anything. It expects no response from the handle_toggle_event.
222    fn run_handle_toggle_event(
223        test_helper: &mut TestHelper,
224        toggle_logger: &mut ToggleLogger,
225        event: ClientConnectionsToggleEvent,
226    ) {
227        let mut test_fut = pin!(toggle_logger.handle_toggle_event(event));
228        assert_eq!(
229            test_helper.run_until_stalled_drain_cobalt_events(&mut test_fut),
230            Poll::Ready(())
231        );
232    }
233
234    fn run_handle_battery_charge_status(
235        test_helper: &mut TestHelper,
236        toggle_logger: &mut ToggleLogger,
237        charge_status: fidl_battery::ChargeStatus,
238    ) {
239        let mut test_fut = pin!(toggle_logger.handle_battery_charge_status(charge_status));
240        assert_eq!(
241            test_helper.run_until_stalled_drain_cobalt_events(&mut test_fut),
242            Poll::Ready(())
243        );
244    }
245
246    #[fuchsia::test]
247    fn test_quick_toggle_metric_is_recorded() {
248        let mut test_helper = setup_test();
249        let inspect_node = test_helper.create_inspect_node("test_stats");
250        let mut toggle_logger = ToggleLogger::new(test_helper.cobalt_proxy.clone(), &inspect_node);
251
252        // Start with client connections enabled.
253        let mut test_time = fasync::MonotonicInstant::from_nanos(123);
254        let event = ClientConnectionsToggleEvent::Enabled;
255        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
256
257        // Stop client connections and quickly start them again.
258        test_time += fasync::MonotonicDuration::from_minutes(40);
259        test_helper.exec.set_fake_time(test_time);
260        let event = ClientConnectionsToggleEvent::Disabled;
261        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
262
263        test_time += fasync::MonotonicDuration::from_seconds(1);
264        test_helper.exec.set_fake_time(test_time);
265        let event = ClientConnectionsToggleEvent::Enabled;
266        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
267
268        // Check that a metric is logged for the quick stop and start.
269        let logged_metrics =
270            test_helper.get_logged_metrics(metrics::CLIENT_CONNECTIONS_STOP_AND_START_METRIC_ID);
271        assert_variant!(&logged_metrics[..], [metric] => {
272            let expected_metric = fidl_fuchsia_metrics::MetricEvent {
273                metric_id: metrics::CLIENT_CONNECTIONS_STOP_AND_START_METRIC_ID,
274                event_codes: vec![],
275                payload: fidl_fuchsia_metrics::MetricEventPayload::Count(1),
276            };
277            assert_eq!(metric, &expected_metric);
278        });
279    }
280
281    #[fuchsia::test]
282    fn test_quick_toggle_no_metric_is_recorded_if_not_quick() {
283        let mut test_helper = setup_test();
284        let inspect_node = test_helper.create_inspect_node("test_stats");
285        let mut toggle_logger = ToggleLogger::new(test_helper.cobalt_proxy.clone(), &inspect_node);
286
287        // Start with client connections enabled.
288        let mut test_time = fasync::MonotonicInstant::from_nanos(123);
289        let event = ClientConnectionsToggleEvent::Enabled;
290        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
291
292        // Stop client connections and a while later start them again.
293        test_time += fasync::MonotonicDuration::from_minutes(20);
294        test_helper.exec.set_fake_time(test_time);
295        let event = ClientConnectionsToggleEvent::Disabled;
296        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
297
298        test_time += fasync::MonotonicDuration::from_minutes(30);
299        test_helper.exec.set_fake_time(test_time);
300        let event = ClientConnectionsToggleEvent::Enabled;
301        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
302
303        // Check that no metric is logged for quick toggles since there was a while between the
304        // stop and start.
305        let logged_metrics =
306            test_helper.get_logged_metrics(metrics::CLIENT_CONNECTIONS_STOP_AND_START_METRIC_ID);
307        assert!(logged_metrics.is_empty());
308    }
309
310    #[fuchsia::test]
311    fn test_quick_toggle_metric_second_disable_doesnt_update_time() {
312        // Verify that if two consecutive disables happen, only the first is used to determine
313        // quick toggles since the following ones don't change the state.
314        let mut test_helper = setup_test();
315        let inspect_node = test_helper.create_inspect_node("test_stats");
316        let mut toggle_logger = ToggleLogger::new(test_helper.cobalt_proxy.clone(), &inspect_node);
317
318        // Start with client connections enabled.
319        let mut test_time = fasync::MonotonicInstant::from_nanos(123);
320        let event = ClientConnectionsToggleEvent::Enabled;
321        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
322
323        // Stop client connections and a while later stop them again.
324        test_time += fasync::MonotonicDuration::from_minutes(40);
325        test_helper.exec.set_fake_time(test_time);
326        let event = ClientConnectionsToggleEvent::Disabled;
327        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
328
329        test_time += fasync::MonotonicDuration::from_minutes(30);
330        test_helper.exec.set_fake_time(test_time);
331        let event = ClientConnectionsToggleEvent::Disabled;
332        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
333
334        // Start client connections right after the last disable message.
335        test_time += fasync::MonotonicDuration::from_seconds(1);
336        test_helper.exec.set_fake_time(test_time);
337        let event = ClientConnectionsToggleEvent::Enabled;
338        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
339
340        // Check that no metric is logged since the enable message came a while after the first
341        // disable message.
342        let logged_metrics =
343            test_helper.get_logged_metrics(metrics::CLIENT_CONNECTIONS_STOP_AND_START_METRIC_ID);
344        assert!(logged_metrics.is_empty());
345    }
346
347    #[fuchsia::test]
348    fn test_log_client_connection_enabled() {
349        let mut test_helper = setup_test();
350        let inspect_node = test_helper.create_inspect_node("test_stats");
351        let mut toggle_logger = ToggleLogger::new(test_helper.cobalt_proxy.clone(), &inspect_node);
352
353        // Start with client connections enabled.
354        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(10_000_000));
355        let event = ClientConnectionsToggleEvent::Enabled;
356        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
357
358        let metrics =
359            test_helper.get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_OCCURRENCE_METRIC_ID);
360        assert_eq!(metrics.len(), 1);
361        assert_eq!(metrics[0].payload, MetricEventPayload::Count(1));
362
363        // Send enabled event again. This should not log any metric because the device was not
364        // in a disabled state
365        test_helper.clear_cobalt_events();
366        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(50_000_000));
367        let event = ClientConnectionsToggleEvent::Enabled;
368        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
369
370        let metrics =
371            test_helper.get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_OCCURRENCE_METRIC_ID);
372        assert!(metrics.is_empty());
373
374        // Send disabled event. This should log the duration between now and when the
375        // first enabled event was sent.
376        test_helper.clear_cobalt_events();
377        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(100_000_000));
378        let event = ClientConnectionsToggleEvent::Disabled;
379        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
380
381        let metrics =
382            test_helper.get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_DURATION_METRIC_ID);
383        assert_eq!(metrics.len(), 1);
384        assert_eq!(metrics[0].payload, MetricEventPayload::IntegerValue(90));
385        let metrics = test_helper
386            .get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_DURATION_ON_BATTERY_METRIC_ID);
387        assert!(metrics.is_empty());
388    }
389
390    #[fuchsia::test]
391    fn test_log_client_connection_enabled_duration_on_battery_with_reenable() {
392        let mut test_helper = setup_test();
393        let inspect_node = test_helper.create_inspect_node("test_stats");
394        let mut toggle_logger = ToggleLogger::new(test_helper.cobalt_proxy.clone(), &inspect_node);
395
396        // Start with client connections enabled.
397        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(10_000_000));
398        let event = ClientConnectionsToggleEvent::Enabled;
399        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
400
401        // Set on battery
402        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(30_000_000));
403        let charge_status = fidl_battery::ChargeStatus::Discharging;
404        run_handle_battery_charge_status(&mut test_helper, &mut toggle_logger, charge_status);
405
406        // Send disabled event. This should log the duration between now and when the client
407        // connections enabled AND device is on battery
408        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(100_000_000));
409        let event = ClientConnectionsToggleEvent::Disabled;
410        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
411
412        let metrics = test_helper
413            .get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_DURATION_ON_BATTERY_METRIC_ID);
414        assert_eq!(metrics.len(), 1);
415        assert_eq!(metrics[0].payload, MetricEventPayload::IntegerValue(70));
416
417        test_helper.clear_cobalt_events();
418        // Send client connections enabled and disabled events again.
419        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(110_000_000));
420        let event = ClientConnectionsToggleEvent::Enabled;
421        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
422        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(150_000_000));
423        let event = ClientConnectionsToggleEvent::Disabled;
424        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
425
426        // Verify that only the duration since the second enabled event is logged.
427        let metrics = test_helper
428            .get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_DURATION_ON_BATTERY_METRIC_ID);
429        assert_eq!(metrics.len(), 1);
430        assert_eq!(metrics[0].payload, MetricEventPayload::IntegerValue(40));
431    }
432
433    #[fuchsia::test]
434    fn test_log_client_connection_enabled_duration_on_battery_with_repeated_battery_change() {
435        let mut test_helper = setup_test();
436        let inspect_node = test_helper.create_inspect_node("test_stats");
437        let mut toggle_logger = ToggleLogger::new(test_helper.cobalt_proxy.clone(), &inspect_node);
438
439        // Start with client connections enabled.
440        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(10_000_000));
441        let event = ClientConnectionsToggleEvent::Enabled;
442        run_handle_toggle_event(&mut test_helper, &mut toggle_logger, event);
443
444        // Set on battery
445        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(30_000_000));
446        let charge_status = fidl_battery::ChargeStatus::Discharging;
447        run_handle_battery_charge_status(&mut test_helper, &mut toggle_logger, charge_status);
448
449        // Set on charger. This should log the duration between now and when the client
450        // connection is enabled *and* device is on battery
451        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(100_000_000));
452        let charge_status = fidl_battery::ChargeStatus::Charging;
453        run_handle_battery_charge_status(&mut test_helper, &mut toggle_logger, charge_status);
454
455        let metrics = test_helper
456            .get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_DURATION_ON_BATTERY_METRIC_ID);
457        assert_eq!(metrics.len(), 1);
458        assert_eq!(metrics[0].payload, MetricEventPayload::IntegerValue(70));
459
460        test_helper.clear_cobalt_events();
461        // Set on battery and then on charger again.
462        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(110_000_000));
463        let charge_status = fidl_battery::ChargeStatus::Discharging;
464        run_handle_battery_charge_status(&mut test_helper, &mut toggle_logger, charge_status);
465        test_helper.exec.set_fake_time(fasync::MonotonicInstant::from_nanos(150_000_000));
466        let charge_status = fidl_battery::ChargeStatus::Charging;
467        run_handle_battery_charge_status(&mut test_helper, &mut toggle_logger, charge_status);
468
469        // Verify that only the duration since the second enabled event is logged.
470        let metrics = test_helper
471            .get_logged_metrics(metrics::CLIENT_CONNECTION_ENABLED_DURATION_ON_BATTERY_METRIC_ID);
472        assert_eq!(metrics.len(), 1);
473        assert_eq!(metrics[0].payload, MetricEventPayload::IntegerValue(40));
474    }
475}
wlan_telemetry/processors/toggle_events.rs

wlan_telemetry/processors/
toggle_events.rs
