[time][inspect] Adds basic inspect metric collection for UTC adjustments

Adds success and failure counts, as well as rudimentary info of last
attempted adjust. This is implemented only for inspect for the time
being.

Bug: 388898827
Change-Id: I7b926e7fb217c38b66ce08aeddd70ff2d24d7053
Reviewed-on: https://fuchsia-review.googlesource.com/c/fuchsia/+/1234127
Fuchsia-Auto-Submit: Filip Filmar <[email protected]>
Commit-Queue: Auto-Submit <[email protected]>
Reviewed-by: Guocheng Wei <[email protected]>

Author: filmil

src/sys/time/timekeeper/src/clock_manager.rs

@@ -4,7 +4,8 @@
 
 use crate::diagnostics::{Diagnostics, Event};
 use crate::enums::{
-    ClockCorrectionStrategy, ClockUpdateReason, StartClockSource, Track, WriteRtcOutcome,
+    ClockCorrectionStrategy, ClockUpdateReason, StartClockSource, Track, UserAdjustUtcOutcome,
+    WriteRtcOutcome,
 };
 use crate::estimator::Estimator;
 use crate::rtc::Rtc;
@@ -504,8 +505,20 @@ impl<R: Rtc, D: 'static + Diagnostics> ClockManager<R, D> {
                 None => estimate_transform,
                 Some(ref proposal) => adjust_decision
                     .try_adjust(&estimate_transform, proposal.reference, proposal.utc)
-                    .map(|(tr, _)| tr)
+                    .map(|(tr, offset)| {
+                        self.diagnostics
+                            .record(Event::WriteRtc { outcome: WriteRtcOutcome::Succeeded });
+                        self.diagnostics.record(Event::UserAdjustUtc {
+                            outcome: UserAdjustUtcOutcome::Succeeded,
+                            offset,
+                        });
+                        tr
+                    })
                     .map_err(|e| {
+                        self.diagnostics.record(Event::UserAdjustUtc {
+                            outcome: UserAdjustUtcOutcome::Failed,
+                            offset: UtcDuration::from_nanos(0),
+                        });
                         error!("time adjustmend rejected: {:?}", e);
                     })
                     .unwrap_or(estimate_transform),

src/sys/time/timekeeper/src/diagnostics/cobalt.rs

@@ -308,6 +308,9 @@ impl Diagnostics for CobaltDiagnostics {
             Event::UpdateClock { track, reason } => {
                 self.record_clock_update(track, reason);
             }
+            Event::UserAdjustUtc { .. } => {
+                // Don't record anything to Cobalt.
+            }
         }
     }
 }

src/sys/time/timekeeper/src/diagnostics/inspect.rs

@@ -5,12 +5,13 @@
 use crate::diagnostics::{Diagnostics, Event};
 use crate::enums::{
     ClockCorrectionStrategy, ClockUpdateReason, FrequencyDiscardReason, InitializeRtcOutcome, Role,
-    SampleValidationError, TimeSourceError, Track, WriteRtcOutcome,
+    SampleValidationError, TimeSourceError, Track, UserAdjustUtcOutcome, WriteRtcOutcome,
 };
 use crate::{MonitorTrack, PrimaryTrack, TimeSource};
 use fidl_fuchsia_time_external::Status;
 use fuchsia_inspect::{
-    Inspector, IntProperty, Node, NumericProperty, Property, StringProperty, UintProperty,
+    BoolProperty, Inspector, IntProperty, Node, NumericProperty, Property, StringProperty,
+    UintProperty,
 };
 use fuchsia_runtime::{UtcClock, UtcClockDetails, UtcDuration, UtcInstant};
 use fuchsia_sync::Mutex;
@@ -187,6 +188,49 @@ impl RealTimeClockNode {
     }
 }
 
+/// An inspect `Node` and properties used to describe the history of user UTC
+/// adjustments.
+struct UserAdjustUtcNode {
+    /// The count of successful user adjustment UTC attempts.
+    success_count: UintProperty,
+    /// The count of failed user adjustment UTC attempts.
+    failure_count: UintProperty,
+    /// The value of the offset resulting from the last successful proposal.
+    last_allowed_offset_nanos: IntProperty,
+    /// Was last update was a failure?
+    last_update_failure: BoolProperty,
+    /// The inspect node these fields are exported to.
+    _node: Node,
+}
+
+impl UserAdjustUtcNode {
+    pub fn new(node: Node) -> Self {
+        Self {
+            success_count: node.create_uint("success_count", 0),
+            failure_count: node.create_uint("failure_count", 0),
+            last_allowed_offset_nanos: node.create_int("last_proposed_offset_nanos", 0),
+            last_update_failure: node.create_bool("last_updated_failure", false),
+            _node: node,
+        }
+    }
+}
+
+impl UserAdjustUtcNode {
+    fn update_user_adjust_utc(&mut self, outcome: UserAdjustUtcOutcome, offset: UtcDuration) {
+        match outcome {
+            UserAdjustUtcOutcome::Succeeded => {
+                self.success_count.add(1);
+                self.last_update_failure.set(false);
+                self.last_allowed_offset_nanos.set(offset.into_nanos());
+            }
+            UserAdjustUtcOutcome::Failed => {
+                self.failure_count.add(1);
+                self.last_update_failure.set(true);
+            }
+        }
+    }
+}
+
 /// An inspect `Node` and properties used to describe the health of a time source.
 struct TimeSourceNode {
     /// The most recent status of the time source.
@@ -210,7 +254,7 @@ impl TimeSourceNode {
             status_change: node.create_int("status_change_reference", reference_time()),
             failure_counters: HashMap::new(),
             rejection_counters: HashMap::new(),
-            node: node,
+            node,
         }
     }
 
@@ -395,6 +439,8 @@ pub struct InspectDiagnostics {
     tracks: Mutex<HashMap<Track, TrackNode>>,
     /// Details of interactions with the real time clock.
     rtc: Mutex<Option<RealTimeClockNode>>,
+    /// Details of user utc adjustments.
+    user_utc_adjustments: Mutex<Option<UserAdjustUtcNode>>,
     /// The inspect node used to export the contents of this `InspectDiagnostics`.
     node: Node,
 }
@@ -406,6 +452,7 @@ impl InspectDiagnostics {
         node: &Node,
         primary: &PrimaryTrack,
         optional_monitor: &Option<MonitorTrack>,
+        allow_user_utc_adjustments: bool,
     ) -> Self {
         // Record fixed data directly into the node without retaining any references.
         node.record_child("initialization", |child| TimeSet::now(&primary.clock).record(child));
@@ -434,11 +481,18 @@ impl InspectDiagnostics {
             );
         }
 
+        let user_utc_adjustments = Mutex::new(if allow_user_utc_adjustments {
+            Some(UserAdjustUtcNode::new(node.create_child("user_utc_adjustments")))
+        } else {
+            None
+        });
+
         let diagnostics = InspectDiagnostics {
             time_sources: Mutex::new(time_sources_hashmap),
             tracks: Mutex::new(tracks_hashmap),
             rtc: Mutex::new(None),
             node: node.clone_weak(),
+            user_utc_adjustments,
         };
         let clock = Arc::clone(&primary.clock);
         node.record_lazy_child("current", move || {
@@ -513,6 +567,11 @@ impl Diagnostics for InspectDiagnostics {
             Event::UpdateClock { track, reason } => {
                 self.update_track(track, |tn| tn.update_clock(Some(reason)));
             }
+            Event::UserAdjustUtc { outcome, offset } => {
+                if let Some(ref mut utc_node) = *self.user_utc_adjustments.lock() {
+                    utc_node.update_user_adjust_utc(outcome, offset);
+                }
+            }
         }
     }
 }
@@ -589,7 +648,7 @@ mod tests {
             false => None,
         };
 
-        (InspectDiagnostics::new(inspector.root(), &primary, &monitor), primary.clock)
+        (InspectDiagnostics::new(inspector.root(), &primary, &monitor, false), primary.clock)
     }
 
     #[fuchsia::test]

src/sys/time/timekeeper/src/diagnostics/mod.rs

@@ -17,7 +17,7 @@ pub use self::inspect::{InspectDiagnostics, INSPECTOR};
 use crate::enums::{
     ClockCorrectionStrategy, ClockUpdateReason, FrequencyDiscardReason, InitialClockState,
     InitializeRtcOutcome, Role, SampleValidationError, StartClockSource, TimeSourceError, Track,
-    WriteRtcOutcome,
+    UserAdjustUtcOutcome, WriteRtcOutcome,
 };
 use fidl_fuchsia_time_external::Status;
 use fuchsia_runtime::{UtcDuration, UtcInstant};
@@ -79,6 +79,8 @@ pub enum Event {
     StartClock { track: Track, source: StartClockSource },
     /// The userspace clock has been updated.
     UpdateClock { track: Track, reason: ClockUpdateReason },
+    /// The UTC clock user adjustment result.
+    UserAdjustUtc { outcome: UserAdjustUtcOutcome, offset: UtcDuration },
 }
 
 /// A standard interface for systems that record events for diagnostic purposes.

src/sys/time/timekeeper/src/enums.rs

@@ -257,3 +257,9 @@ impl Into<CobaltTimeSourceEvent> for TimeSourceError {
         }
     }
 }
+
+#[derive(Clone, Copy, Debug, PartialEq)]
+pub enum UserAdjustUtcOutcome {
+    Failed,
+    Succeeded,
+}

src/sys/time/timekeeper/src/main.rs

@@ -261,10 +261,17 @@ async fn main() -> Result<()> {
         clock: Arc::new(create_monitor_clock(&primary_track.clock)),
     });
 
+    let enable_user_utc_adjustment = config.serve_fuchsia_time_external_adjust();
+
     info!("initializing diagnostics and serving inspect on servicefs");
     let cobalt_experiment = COBALT_EXPERIMENT;
     let diagnostics = Arc::new(CompositeDiagnostics::new(
-        InspectDiagnostics::new(inspector_root, &primary_track, &monitor_track),
+        InspectDiagnostics::new(
+            inspector_root,
+            &primary_track,
+            &monitor_track,
+            enable_user_utc_adjustment,
+        ),
         CobaltDiagnostics::new(cobalt_experiment, &primary_track, &monitor_track),
     ));
 
@@ -287,7 +294,6 @@ async fn main() -> Result<()> {
     let cmd_send_clone = cmd_send.clone();
     let serve_test_protocols = config.serve_test_protocols();
     let serve_fuchsia_time_alarms = config.serve_fuchsia_time_alarms();
-    let serve_adjust = config.serve_fuchsia_time_external_adjust();
     let ps = persistent_state.clone();
 
     if config.has_always_on_counter() {
@@ -356,7 +362,7 @@ async fn main() -> Result<()> {
         fs.dir("svc").add_fidl_service(Rpcs::Wake);
         info!("serving protocol: fuchsia.time.alarms/Wake");
     }
-    if serve_adjust {
+    if enable_user_utc_adjustment {
         fs.dir("svc").add_fidl_service(Rpcs::Adjust);
         info!("serving protocol: fuchsia.time.alarms/Adjust");
     }
@@ -388,7 +394,7 @@ async fn main() -> Result<()> {
 
     let rtc_test_server = Rc::new(rtc_testing::Server::new(persistence_health, persistent_state));
 
-    let adjust_server = Rc::new(if serve_adjust {
+    let adjust_server = Rc::new(if enable_user_utc_adjustment {
         let cmd_send_clone = cmd_send.clone();
         Some(time_adjust::Server::new(cmd_send_clone))
     } else {