test failed in CI: `test_region_snapshot_replacement_step_after_rop_remove_target_gone`

[david-crespo]

This test failed on a CI run on #8564:

https://github.com/oxidecomputer/omicron/pull/8564/checks?check_run_id=45737263049

Log showing the specific test failure:

https://buildomat.eng.oxide.computer/wg/0/details/01JZTHHRW0Z4XZNP2QDAN725NX/vRd388kKuDNEoacSDWR6JkiVQpK7Y1RfB54em22tE0W2iZc0/01JZTHJ39YNFMEJJZ02VVW1R7Y#S7295

Excerpt from the log showing the failure:

      FAIL [  84.633s] omicron-nexus::test_all integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone
stdout ───
  running 1 test
  test integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone has been running for over 60 seconds
  test integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone ... FAILED
  failures:
  failures:
      integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone
  test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 446 filtered out; finished in 84.20s
  
stderr ───
  log file: /var/tmp/omicron_tmp/test_all-d7048d765dc5ce31-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22155.0.log
  note: configured to log to "/var/tmp/omicron_tmp/test_all-d7048d765dc5ce31-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22155.0.log"
  DB URL: postgresql://root@[::1]:41476/omicron?sslmode=disable
  DB address: [::1]:41476
  log file: /var/tmp/omicron_tmp/test_all-d7048d765dc5ce31-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22155.2.log
  note: configured to log to "/var/tmp/omicron_tmp/test_all-d7048d765dc5ce31-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22155.2.log"
  log file: /var/tmp/omicron_tmp/test_all-d7048d765dc5ce31-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22155.3.log
  note: configured to log to "/var/tmp/omicron_tmp/test_all-d7048d765dc5ce31-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22155.3.log"
  thread 'integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone' panicked at nexus/tests/integration_tests/crucible_replacements.rs:1671:13:
  assertion failed: self.datastore.read_only_target_addr(&region_snapshot_replace_request).await.unwrap().is_none()
  stack backtrace:
     0: __rustc::rust_begin_unwind
               at /rustc/6b00bc3880198600130e1cf62b8f8a93494488cc/library/std/src/panicking.rs:697:5
     1: core::panicking::panic_fmt
               at /rustc/6b00bc3880198600130e1cf62b8f8a93494488cc/library/core/src/panicking.rs:75:14
     2: core::panicking::panic
               at /rustc/6b00bc3880198600130e1cf62b8f8a93494488cc/library/core/src/panicking.rs:145:5
     3: {async_fn#0}
               at ./tests/integration_tests/crucible_replacements.rs:1671:13
     4: {async_fn#0}
               at ./tests/integration_tests/crucible_replacements.rs:1959:49
     5: {async_block#0}
               at ./tests/integration_tests/crucible_replacements.rs:1933:1

[jgallagher]

Saw again on #8570: https://buildomat.eng.oxide.computer/wg/0/details/01JZV4212MSKP2QMSXZ3TNQE2E/9AYNqnNfYaYtcIDC3rr3g9fM7tMdB8SCMNadvcS72lBVRH12/01JZV4308Y9N0G96MQ2STJW1XN

[jgallagher]

Failed on main also: https://buildomat.eng.oxide.computer/wg/0/details/01JZX35GGB142R8YC43S5ZWPMC/CkGt4UHher0Sq4LbTdptoJxk8faoNAfI187DxDbDAuuaq116/01JZX35YSBFYZE48EX8Q4D1CRT

[andrewjstone]

Again: https://github.com/oxidecomputer/omicron/runs/46042334664

[david-crespo]

Another one here https://github.com/oxidecomputer/omicron/pull/8614/checks?check_run_id=46133602514

[leftwo]

Some initial data.

I ran just the test_region_snapshot_replacement_step_after_rop_remove_target_gone in a loop by itself, and it passed some 3400 times.

while :; do 
    cargo nextest run -p omicron-nexus test_region_snapshot_replacement_step_after_rop_remove_target_gone
    if [[ $? -ne 0 ]]; then
        echo "$(date) Break at $count"
        break
    fi
    ((count += 1))
    echo "--------------------- $(date) loop at: $count ---------------------"
done

Moving on to test with more, I tried this:

while :; do
    cargo nextest run -p omicron-nexus
    if [[ $? -ne 0 ]]; then
        echo "$(date) Break at $count"
        break
    fi
    ((count += 1))
    banner loop
    echo "--------------------- $(date) loop at: $count ---------------------"
done

This failed on the first loop.. at a different test:

FAIL [  48.659s] omicron-nexus app::sagas::snapshot_create::test::test_action_failure_can_unwind_pantry

The details are:

        FAIL [  48.659s] omicron-nexus app::sagas::snapshot_create::test::test_action_failure_can_unwind_pantry                                              
  stdout ───                                                                                                                                                 
                                                                                                                                                             
    running 1 test                                                                                                                                           
    test app::sagas::snapshot_create::test::test_action_failure_can_unwind_pantry ... FAILED                                                                 
                                       
    failures:                                                                                                                                                
                                                                                                                                                             
    failures:                                                                                                                                                
        app::sagas::snapshot_create::test::test_action_failure_can_unwind_pantry                                                                             
                                                                                                                                                             
    test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 174 filtered out; finished in 48.43s                                                     
                                                                                                                                                             
  stderr ───                                                                                                                                                 
    log file: /tmp/omicron_nexus-fcf0cf9e9dd8d288-test_action_failure_can_unwind_pantry.24026.0.log                                                          
    note: configured to log to "/tmp/omicron_nexus-fcf0cf9e9dd8d288-test_action_failure_can_unwind_pantry.24026.0.log"                                       
    DB URL: postgresql://root@[::1]:63709/omicron?sslmode=disable                                                                                            
    DB address: [::1]:63709                                                                                                                                  
    log file: /tmp/omicron_nexus-fcf0cf9e9dd8d288-test_action_failure_can_unwind_pantry.24026.2.log                                                          
    note: configured to log to "/tmp/omicron_nexus-fcf0cf9e9dd8d288-test_action_failure_can_unwind_pantry.24026.2.log"                                       
                                                                                                                                                             
    thread 'app::sagas::snapshot_create::test::test_action_failure_can_unwind_pantry' panicked at /home/alan/ws/omicron/nexus/test-utils/src/resource_helpers
.rs:1666:10:                                                                                                                                                 
    expected to find inventory collection: TimedOut(30.033954797s)                                                                                           
    note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace                                                                            
    WARN: dropped CockroachInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)               
    WARN: temporary directory leaked: "/tmp/.tmpfgQnOj"                                                                                                      
        If you would like to access the database for debugging, run the following:                                                                           
                                                                                                                                                             
        # Run the database                                                                                                                                   
        cargo xtask db-dev run --no-populate --store-dir "/tmp/.tmpfgQnOj/data"                                                                              
        # Access the database. Note the port may change if you run multiple databases.                                                                       
        cockroach sql --host=localhost:32221 --insecure                                                                                                      
    WARN: dropped ClickHouse process without cleaning it up first (there may still be a child process running (PID 24434) and a temporary directory leaked, /
tmp/omicron_nexus-fcf0cf9e9dd8d288-test_action_failure_can_unwind_pantry.24026.1-clickhouse-ljNtIf)                                                          
    failed to clean up ClickHouse data dir:                                   
    - /tmp/omicron_nexus-fcf0cf9e9dd8d288-test_action_failure_can_unwind_pantry.24026.1-clickhouse-ljNtIf: File exists (os error 17)                         
    WARN: dropped DendriteInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)                
    WARN: dendrite temporary directory leaked: /tmp/.tmp4Sqapz                                                                                               
    WARN: dropped MgdInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)                     
    WARN: mgd temporary directory leaked: /tmp/.tmpoqwz75                     

[iximeow]

another: https://buildomat.eng.oxide.computer/wg/0/details/01K1BKQVVRQMFCCD1SRNCGV31V/9Sb4hK6peKG1wCDFV7nXJGFeMnOeLEpu9bWJTbW9x0fJy5LF/01K1BKRVP9ZXYY7MSNJFX41TSM

like others,

7467  2025-07-29T18:53:20.645Z    stdout ───
7468  2025-07-29T18:53:20.645Z  
7469  2025-07-29T18:53:20.645Z      running 1 test
7470  2025-07-29T18:53:20.645Z      test integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone has been running for over 60 seconds
7471  2025-07-29T18:53:20.645Z      test integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone ... FAILED
7472  2025-07-29T18:53:20.645Z  
7473  2025-07-29T18:53:20.645Z      failures:
7474  2025-07-29T18:53:20.645Z  
7475  2025-07-29T18:53:20.645Z      failures:
7476  2025-07-29T18:53:20.645Z          integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone
7477  2025-07-29T18:53:20.645Z  
7478  2025-07-29T18:53:20.645Z      test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 456 filtered out; finished in 83.25s
7479  2025-07-29T18:53:20.645Z      
7480  2025-07-29T18:53:20.646Z    stderr ───
7481  2025-07-29T18:53:20.646Z      log file: /var/tmp/omicron_tmp/test_all-9e4853ce34b1528a-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22519.0.log
7482  2025-07-29T18:53:20.646Z      note: configured to log to "/var/tmp/omicron_tmp/test_all-9e4853ce34b1528a-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22519.0.log"
7483  2025-07-29T18:53:20.646Z      DB URL: postgresql://root@[::1]:48254/omicron?sslmode=disable
7484  2025-07-29T18:53:20.646Z      DB address: [::1]:48254
7485  2025-07-29T18:53:20.646Z      log file: /var/tmp/omicron_tmp/test_all-9e4853ce34b1528a-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22519.2.log
7486  2025-07-29T18:53:20.646Z      note: configured to log to "/var/tmp/omicron_tmp/test_all-9e4853ce34b1528a-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22519.2.log"
7487  2025-07-29T18:53:20.646Z      log file: /var/tmp/omicron_tmp/test_all-9e4853ce34b1528a-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22519.3.log
7488  2025-07-29T18:53:20.646Z      note: configured to log to "/var/tmp/omicron_tmp/test_all-9e4853ce34b1528a-test_region_snapshot_replacement_step_after_rop_remove_target_gone.22519.3.log"
7489  2025-07-29T18:53:20.646Z  
7490  2025-07-29T18:53:20.646Z      thread 'integration_tests::crucible_replacements::test_region_snapshot_replacement_step_after_rop_remove_target_gone' panicked at nexus/tests/integration_tests/crucible_replacements.rs:1671:13:
7491  2025-07-29T18:53:20.646Z      assertion failed: self.datastore.read_only_target_addr(&region_snapshot_replace_request).await.unwrap().is_none()

[hawkw]

This happened to me again in #8805: https://github.com/oxidecomputer/omicron/pull/8805/checks?check_run_id=47716229378 / buildomat logs

[andrewjstone]

Another one: https://buildomat.eng.oxide.computer/wg/0/details/01K378BKKZDTX592GY5FMCXPJC/weLRSW5XMfFKa6qgPMFNAtTcfFRBk2pJP9S7BXSNTcCv4fyl/01K378CHRJCT1AARC9JK2AMGHS

[andrewjstone]

Another one, this time on main: https://buildomat.eng.oxide.computer/wg/0/details/01K3J0F790QXB2Q3DWSWN6MB5J/d2IIHiIzShZT40wVNiF7RGc7jJu9Pjegk1JxgRVkwh3kzP2p/01K3J0FKPB6BN6N33GVACDZAHA

[andrewjstone]

another: https://github.com/oxidecomputer/omicron/pull/8878/checks?check_run_id=48919009021

[andrewjstone]

And another: https://github.com/oxidecomputer/omicron/runs/48923895600

[andrewjstone]

https://github.com/oxidecomputer/omicron/pull/8682/checks?check_run_id=48919683430

[jgallagher]

Another: https://buildomat.eng.oxide.computer/wg/0/details/01K3P5ZA97Q9F3AF2751KTAV09/mYS9ScmdtQtkWcv2XxHfEe3TQ60S0fKSUiABwqOZlhe6n9TD/01K3P5ZXWV0TJ5YZDA8M5SH0ZH

[smklein]

Just seen on https://github.com/oxidecomputer/omicron/pull/8932/checks?check_run_id=49050168485