add timestamps to db_metadata_nexus records for debugging handoff

nexus/db-model/src/db_metadata.rs

@@ -71,14 +71,26 @@ pub struct DbMetadataNexus {
     nexus_id: DbTypedUuid<OmicronZoneKind>,
     last_drained_blueprint_id: Option<DbTypedUuid<BlueprintKind>>,
     state: DbMetadataNexusState,
+    time_row_created: Option<DateTime<Utc>>,
+    time_quiesced: Option<DateTime<Utc>>,
+    time_active: Option<DateTime<Utc>>,
 }
 
 impl DbMetadataNexus {
     pub fn new(nexus_id: OmicronZoneUuid, state: DbMetadataNexusState) -> Self {
+        let now = Utc::now();
+        let (time_active, time_quiesced) = match state {
+            DbMetadataNexusState::Active => (Some(now), None),
+            DbMetadataNexusState::Quiesced => (None, Some(now)),
+            DbMetadataNexusState::NotYet => (None, None),
+        };
         Self {
             nexus_id: nexus_id.into(),
             last_drained_blueprint_id: None,
             state,
+            time_row_created: Some(now),
+            time_quiesced,
+            time_active,
         }
     }
 
@@ -93,4 +105,12 @@ impl DbMetadataNexus {
     pub fn last_drained_blueprint_id(&self) -> Option<BlueprintUuid> {
         self.last_drained_blueprint_id.map(|id| id.into())
     }
+
+    pub fn time_active(&self) -> Option<DateTime<Utc>> {
+        self.time_active
+    }
+
+    pub fn time_quiesced(&self) -> Option<DateTime<Utc>> {
+        self.time_quiesced
+    }
 }

nexus/db-model/src/schema_versions.rs

@@ -16,7 +16,7 @@ use std::{collections::BTreeMap, sync::LazyLock};
 ///
 /// This must be updated when you change the database schema.  Refer to
 /// schema/crdb/README.adoc in the root of this repository for details.
-pub const SCHEMA_VERSION: Version = Version::new(195, 0, 0);
+pub const SCHEMA_VERSION: Version = Version::new(196, 0, 0);
 
 /// List of all past database schema versions, in *reverse* order
 ///
@@ -28,6 +28,7 @@ static KNOWN_VERSIONS: LazyLock<Vec<KnownVersion>> = LazyLock::new(|| {
         // |  leaving the first copy as an example for the next person.
         // v
         // KnownVersion::new(next_int, "unique-dirname-with-the-sql-files"),
+        KnownVersion::new(196, "db-metadata-timestamps"),
         KnownVersion::new(195, "tuf-pruned-index"),
         KnownVersion::new(194, "tuf-pruned"),
         KnownVersion::new(193, "nexus-lockstep-port"),

nexus/db-queries/src/db/datastore/db_metadata.rs

@@ -768,7 +768,11 @@ impl DataStore {
         let nexus_id = nexus_db_model::to_db_typed_uuid(nexus_id);
         let count = diesel::update(dsl::db_metadata_nexus)
             .filter(dsl::nexus_id.eq(nexus_id))
-            .set(dsl::state.eq(DbMetadataNexusState::Quiesced))
+            .filter(dsl::state.ne(DbMetadataNexusState::Quiesced))
+            .set((
+                dsl::state.eq(DbMetadataNexusState::Quiesced),
+                dsl::time_quiesced.eq(Utc::now()),
+            ))
             .execute_async(&*conn)
             .await
             .map_err(|e| public_error_from_diesel(e, ErrorHandler::Server))?;
@@ -1017,7 +1021,10 @@ impl DataStore {
         // Update all "not_yet" records to "active"
         diesel::update(dsl::db_metadata_nexus)
             .filter(dsl::state.eq(DbMetadataNexusState::NotYet))
-            .set(dsl::state.eq(DbMetadataNexusState::Active))
+            .set((
+                dsl::state.eq(DbMetadataNexusState::Active),
+                dsl::time_active.eq(Utc::now()),
+            ))
             .execute_async(&conn)
             .await?;
 
@@ -1750,7 +1757,9 @@ mod test {
         assert_eq!(nexus3_before.state(), DbMetadataNexusState::Quiesced);
 
         // Attempt handoff with nexus2 - should succeed
+        let before = Utc::now();
         let result = datastore.attempt_handoff(nexus2_id).await;
+        let after = Utc::now();
         if let Err(ref e) = result {
             panic!("Handoff should succeed but got error: {}", e);
         }
@@ -1775,7 +1784,17 @@ mod test {
             .expect("nexus3 should exist");
 
         assert_eq!(nexus1_after.state(), DbMetadataNexusState::Active);
+        let nexus1_after_active_time = nexus1_after
+            .time_active()
+            .expect("active record should have time_active");
+        assert!(nexus1_after_active_time >= before);
+        assert!(nexus1_after_active_time <= after);
         assert_eq!(nexus2_after.state(), DbMetadataNexusState::Active);
+        let nexus2_after_active_time = nexus2_after
+            .time_active()
+            .expect("active record should have time_active");
+        assert!(nexus2_after_active_time >= before);
+        assert!(nexus2_after_active_time <= after);
         // Should remain unchanged
         assert_eq!(nexus3_after.state(), DbMetadataNexusState::Quiesced);
 

nexus/db-schema/src/schema.rs

@@ -2398,6 +2398,9 @@ table! {
         nexus_id -> Uuid,
         last_drained_blueprint_id -> Nullable<Uuid>,
         state -> crate::enums::DbMetadataNexusStateEnum,
+        time_row_created -> Nullable<Timestamptz>,
+        time_quiesced -> Nullable<Timestamptz>,
+        time_active -> Nullable<Timestamptz>,
     }
 }
 

nexus/src/app/quiesce.rs

@@ -988,10 +988,12 @@ mod test {
             .expect("reading access records");
         assert_eq!(records.len(), 3);
         assert!(
-            records.iter().all(|r| r.state() == DbMetadataNexusState::Active)
+            records.iter().all(|r| r.state() == DbMetadataNexusState::Active
+                && r.time_quiesced().is_none())
         );
 
         // Now finish that saga.  All three handles should quiesce.
+        let time_before = Utc::now();
         drop(saga_ref);
         wait_for_condition(
             || async {
@@ -1009,6 +1011,7 @@ mod test {
         )
         .await
         .expect("did not quiesce within timeout");
+        let time_after = Utc::now();
 
         // Each "Nexus" record should say that it's quiesced.
         //
@@ -1023,9 +1026,14 @@ mod test {
             .await
             .expect("reading access records");
         assert_eq!(records.len(), 3);
-        assert!(
-            records.iter().all(|r| r.state() == DbMetadataNexusState::Quiesced)
-        );
+        assert!(records.iter().all(|r| {
+            let time_quiesced = r
+                .time_quiesced()
+                .expect("quiesced record should have time quiesced");
+            r.state() == DbMetadataNexusState::Quiesced
+                && time_quiesced >= time_before
+                && time_quiesced <= time_after
+        }));
 
         testdb.terminate().await;
         logctx.cleanup_successful();

schema/crdb/db-metadata-timestamps/up.sql

@@ -0,0 +1,4 @@
+ALTER TABLE omicron.public.db_metadata_nexus
+    ADD COLUMN IF NOT EXISTS time_row_created TIMESTAMPTZ,
+    ADD COLUMN IF NOT EXISTS time_quiesced TIMESTAMPTZ,
+    ADD COLUMN IF NOT EXISTS time_active TIMESTAMPTZ

schema/crdb/dbinit.sql

@@ -6678,7 +6678,11 @@ CREATE TYPE IF NOT EXISTS omicron.public.db_metadata_nexus_state AS ENUM (
 CREATE TABLE IF NOT EXISTS omicron.public.db_metadata_nexus (
     nexus_id UUID NOT NULL PRIMARY KEY,
     last_drained_blueprint_id UUID,
-    state omicron.public.db_metadata_nexus_state NOT NULL
+    state omicron.public.db_metadata_nexus_state NOT NULL,
+    -- the following fields are for debugging only
+    time_row_created TIMESTAMPTZ, -- nullable
+    time_quiesced TIMESTAMPTZ,    -- nullable
+    time_active TIMESTAMPTZ       -- nullable
 );
 
 CREATE UNIQUE INDEX IF NOT EXISTS lookup_db_metadata_nexus_by_state on omicron.public.db_metadata_nexus (