test flake: integration_tests::crucible_replacements::test_region_replacement_triple_sanity_2

[jmpesp]

test_region_replacement_triple_sanity_2 is failing with:

thread 'integration_tests::crucible_replacements::test_region_replacement_triple_sanity_2' panicked at nexus/tests/integration_tests/crucible_replacements.rs:2267:5:
assertion `left == right` failed
  left: 2
 right: 3

An example is https://github.com/oxidecomputer/omicron/runs/37129536786

[jmpesp]

The purpose of test_region_replacement_triple_sanity_2 is to test that multiple physical disks can be expunged before any Crucible replacements take place, and the process can still run to completion. This is important because Crucible data is replicated to three regions, so losing two should not result in any lost data.

The assertion that's failing is the first one of this pair:

omicron/nexus/tests/integration_tests/crucible_replacements.rs

Lines 2266 to 2268 in a45a089

	// Assert region snapshots replaced with three read-only regions
	assert_eq!(snapshot_allocated_regions.len(), 3);
	assert!(snapshot_allocated_regions.iter().all(|(_, r)| r.read_only()));

This test picks the three physical disks that are backing a snapshot volume's region snapshots to expunge, so it is asserting that all those region snapshots have been replaced with read-only regions.

This assertion should pass due to all replacements that Nexus thinks should be completed being run until they are done. Above those assertions:

omicron/nexus/tests/integration_tests/crucible_replacements.rs

Lines 2255 to 2256 in a45a089

	// Now, run all replacement tasks to completion
	wait_for_all_replacements(&datastore, &internal_client).await;

wait_for_all_replacements will, in a loop:

1. run all background tasks related to region replacement and region snapshot replacement
2. bail out of the loop if there are no more non-completed replacements

Step 1 of this loop will identify what resources need to be replaced, insert the necessary requests, and trigger the associated sagas to perform the work.

The fact that this assertion is firing means that:

1. Nexus thinks there are no more replacements that need to occur (because the associated "start" background tasks did not make new requests)
2. Nexus has completed any replacements that were requested (because replacements_left == 0

This is troubling because the snapshot volume, because that assert is failing, still has a region snapshot, meaning it is still using an expunged physical disk.

[jmpesp]

In order to reproduce this locally on my workstation, I need to run cargo nextest run test_region_replacement_triple_sanity_2 in a loop, while also running mprime to max out CPU usage. I started doing this to reproduce timeouts that were seen in CI, but it is also useful to reproduce this flake (ignore the line number difference, this is on my checkout where I had tried a few things before opening this issue!):

thread 'integration_tests::crucible_replacements::test_region_replacement_triple_sanity_2' panicked at nexus/tests/integration_tests/crucible_replacements.rs:2301:5:
assertion `left == right` failed
  left: 2
 right: 3

Using cargo xtask db-dev run --no-populate --store-dirand pointing to this test's directory, we can observe a few things:

1. All sagas are done running:

root@[::1]:32221/omicron> select * from saga where saga_state != 'done';
  id | creator | time_created | name | saga_dag | saga_state | current_sec | adopt_generation | adopt_time
-----+---------+--------------+------+----------+------------+-------------+------------------+-------------
(0 rows)

2. A region snapshot does still exist:

root@[::1]:32221/omicron> select * from region_snapshot;
               dataset_id              |              region_id               |             snapshot_id              | snapshot_addr | volume_references | deleting
---------------------------------------+--------------------------------------+--------------------------------------+---------------+-------------------+-----------
  b366cde1-d2e0-43f9-bcd7-b20ceea1e846 | a8f7fc06-ecdd-4160-85bd-b03984221601 | e670501b-cfaa-42bb-a424-88498b87fda6 | [::1]:6001    |                 0 |  false
(1 row)

Using the following omdb patch:

diff --git a/dev-tools/omdb/src/bin/omdb/db.rs b/dev-tools/omdb/src/bin/omdb/db.rs
index 96e5c39c7..322fd1659 100644
--- a/dev-tools/omdb/src/bin/omdb/db.rs
+++ b/dev-tools/omdb/src/bin/omdb/db.rs
@@ -316,6 +316,7 @@ pub struct DbFetchOptions {
 /// Subcommands that query or update the database
 #[derive(Debug, Subcommand, Clone)]
 enum DbCommands {
+    ReplacementsToDo,
     /// Print information about the rack
     Rack(RackArgs),
     /// Print information about virtual disks
@@ -915,6 +916,9 @@ impl DbArgs {
         self.db_url_opts.with_datastore(omdb, log, |opctx, datastore| {
             async move {
                 match &self.command {
+                    DbCommands::ReplacementsToDo => {
+                        replacements_to_do(&opctx, &datastore, &fetch_opts).await
+                    }
                     DbCommands::Rack(RackArgs { command: RackCommands::List }) => {
                         cmd_db_rack_list(&opctx, &datastore, &fetch_opts).await
                     }
@@ -1419,6 +1423,78 @@ async fn cmd_db_disk_list(
     Ok(())
 }
 
+async fn replacements_to_do(
+    opctx: &OpContext,
+    datastore: &DataStore,
+    _fetch_opts: &DbFetchOptions,
+) -> Result<(), anyhow::Error> {
+    #[derive(Tabled)]
+    #[tabled(rename_all = "SCREAMING_SNAKE_CASE")]
+    struct RegionRow {
+        id: String,
+        dataset_id: String,
+        resource: String,
+    }
+
+    let region_rows: Vec<RegionRow> = vec![
+        datastore
+            .find_read_only_regions_on_expunged_physical_disks(opctx)
+            .await?,
+
+        datastore
+            .find_read_write_regions_on_expunged_physical_disks(opctx)
+            .await?,
+        ]
+        .into_iter()
+        .flatten()
+        .into_iter()
+        .map(|region| RegionRow {
+            id: region.id().to_string(),
+            dataset_id: region.dataset_id().to_string(),
+            resource: if region.read_only() {
+                String::from("read-only region")
+            } else {
+                String::from("read/write region")
+            },
+        })
+        .collect();
+
+    let table = tabled::Table::new(region_rows)
+        .with(tabled::settings::Style::empty())
+        .with(tabled::settings::Padding::new(0, 1, 0, 0))
+        .to_string();
+
+    println!("{}", table);
+
+    #[derive(Tabled)]
+    #[tabled(rename_all = "SCREAMING_SNAKE_CASE")]
+    struct RegionSnapshotRow {
+        dataset_id: String,
+        region_id: String,
+        snapshot_id: String,
+    }
+
+    let rs_rows: Vec<RegionSnapshotRow> = datastore
+        .find_region_snapshots_on_expunged_physical_disks(opctx)
+        .await?
+        .into_iter()
+        .map(|rs| RegionSnapshotRow {
+            dataset_id: rs.dataset_id().to_string(),
+            region_id: rs.region_id.to_string(),
+            snapshot_id: rs.snapshot_id.to_string(),
+        })
+        .collect();
+
+    let table = tabled::Table::new(rs_rows)
+        .with(tabled::settings::Style::empty())
+        .with(tabled::settings::Padding::new(0, 1, 0, 0))
+        .to_string();
+
+    println!("{}", table);
+
+    Ok(())
+}
+
 /// Run `omdb db rack info`.
 async fn cmd_db_rack_list(
     opctx: &OpContext,

We can run the same code that Nexus uses to identify replacements that need to occur, namely the find_*_on_expunged_physical disks:

$ OMDB_DB_URL="postgresql://root@[::1]:32221/omicron" ./target/debug/omdb db replacements-to-do
note: using database URL postgresql://root@[::1]:32221/omicron
note: database schema version matches expected (124.0.0)
ID                                   DATASET_ID                           RESOURCE          
a8f7fc06-ecdd-4160-85bd-b03984221601 b366cde1-d2e0-43f9-bcd7-b20ceea1e846 read/write region 
DATASET_ID                           REGION_ID                            SNAPSHOT_ID                          
b366cde1-d2e0-43f9-bcd7-b20ceea1e846 a8f7fc06-ecdd-4160-85bd-b03984221601 e670501b-cfaa-42bb-a424-88498b87fda6

Again, this is troubling! Nexus should be creating replacement requests for these resources.

[jmpesp]

Looking at nexus/src/app/background/tasks/region_snapshot_replacement_start.rs, here's the spot where this code is called:

omicron/nexus/src/app/background/tasks/region_snapshot_replacement_start.rs

Lines 69 to 87 in a45a089

	// Find region snapshots on expunged physical disks
	let region_snapshots_to_be_replaced = match self
	.datastore
	.find_region_snapshots_on_expunged_physical_disks(opctx)
	.await
	{
	Ok(region_snapshots) => region_snapshots,
	Err(e) => {
	let s = format!(
	"find_region_snapshots_on_expunged_physical_disks \
	failed: {e}",
	);
	error!(&log, "{s}");
	status.errors.push(s);
	return;
	}
	};

Any errors?

$ grep 'find_region_snapshots_on_expunged_physical_disks failed' /tmp/test_all-ee015358b2f8c194-test_region_replacement_triple_sanity_2.6347.0.log
- exit 1

This background task was invoked 28 times:

14:51:38.060Z DEBG 55186790-6ea1-4b92-8ebb-087c40cad4bf (ServerContext): activation complete
    background_task = region_snapshot_replacement_start
    elapsed = 380.246688ms
    iteration = 28
    status = {"errors":[],"requests_completed_ok":[],"requests_created_ok":[],"start_invoked_ok":[]}

Surely it should have found something!

[jmpesp]

My first thought was that the test was expunging the same physical disk multiple times, so I added:

diff --git a/nexus/tests/integration_tests/crucible_replacements.rs b/nexus/tests/integration_tests/crucible_replacements.rs
index b4bdcd3c5..f20704381 100644
--- a/nexus/tests/integration_tests/crucible_replacements.rs
+++ b/nexus/tests/integration_tests/crucible_replacements.rs
@@ -2200,6 +2226,8 @@ async fn test_region_replacement_triple_sanity_2(
     assert_eq!(snapshot_allocated_regions.len(), 0);
 
     // Expunge two physical disks before any replacements occur
+    let mut expunged_disks = HashSet::new();
+
     for i in [0, 1] {
         let (dataset, _) = &disk_allocated_regions[i];
 
@@ -2222,6 +2250,8 @@ async fn test_region_replacement_triple_sanity_2(
             )
             .await
             .unwrap();
+
+        assert!(expunged_disks.insert(db_zpool.physical_disk_id));
     }
 
     // Now, run all replacement tasks to completion
@@ -2250,6 +2280,8 @@ async fn test_region_replacement_triple_sanity_2(
             )
             .await
             .unwrap();
+
+        assert!(expunged_disks.insert(db_zpool.physical_disk_id));
     }
 
     // Now, run all replacement tasks to completion

This assert has not failed (yet?).

[jmpesp]

Note: the above assert patch not failing makes sense, as each part of the snapshot volume's region set will have been located on separate physical disks according to the region allocation policy.

[jmpesp]

My second thought was to add a check in the wait_for_all_replacements loop to assert that there actually is no more work to be done:

diff --git a/nexus/tests/integration_tests/crucible_replacements.rs b/nexus/tests/integration_tests/crucible_replacements.rs
index b4bdcd3c5..f20704381 100644
--- a/nexus/tests/integration_tests/crucible_replacements.rs
+++ b/nexus/tests/integration_tests/crucible_replacements.rs
@@ -130,6 +130,10 @@ pub(crate) async fn wait_for_all_replacements(
     wait_for_condition(
         || {
             let datastore = datastore.clone();
+            let opctx = OpContext::for_tests(
+                internal_client.client_log.new(o!()),
+                datastore.clone(),
+            );
 
             async move {
                 // Trigger all the replacement related background tasks. If
@@ -149,6 +153,28 @@ pub(crate) async fn wait_for_all_replacements(
                 }
 
                 if replacements_left(&datastore).await == 0 {
+                    // Ensure we're done!
+                    let left_to_do =
+                        datastore
+                            .find_read_only_regions_on_expunged_physical_disks(&opctx)
+                            .await
+                            .unwrap()
+                            .len() +
+
+                        datastore
+                            .find_read_write_regions_on_expunged_physical_disks(&opctx)
+                            .await
+                            .unwrap()
+                            .len() +
+
+                        datastore
+                            .find_region_snapshots_on_expunged_physical_disks(&opctx)
+                            .await
+                            .unwrap()
+                            .len();
+
+                    assert_eq!(left_to_do, 0);
+
                     return Ok(());
                 }
 

This did fail!:

thread 'integration_tests::crucible_replacements::test_region_replacement_triple_sanity_2' panicked at nexus/tests/integration_tests/crucible_replacements.rs:176:21:
assertion `left == right` failed
  left: 2
 right: 0

[andrewjstone]

Just saw this again on #8517

https://github.com/oxidecomputer/omicron/pull/8517/checks?check_run_id=45323383096

https://buildomat.eng.oxide.computer/wg/0/details/01JZ8ZHJ4XVXCS5GAWKKXC11Q9/tJkl0XS27a36jT8mKQiplMj26YHk8lrIySvMrYusjb4QhsMM/01JZ8ZJY7C0EXAKJHGRC501EAD