8677 2025-08-27T18:35:29.473Z stdout ───
8678 2025-08-27T18:35:29.473Z
8679 2025-08-27T18:35:29.473Z running 1 test
8680 2025-08-27T18:35:29.473Z running commands with args: ["db", "disks", "list"]
8681 2025-08-27T18:35:29.473Z running commands with args: ["db", "dns", "show"]
8682 2025-08-27T18:35:29.473Z running commands with args: ["db", "dns", "diff", "external", "2"]
8683 2025-08-27T18:35:29.473Z running commands with args: ["db", "dns", "names", "external", "2"]
8684 2025-08-27T18:35:29.473Z running commands with args: ["db", "instances"]
8685 2025-08-27T18:35:29.473Z running commands with args: ["db", "sleds"]
8686 2025-08-27T18:35:29.473Z running commands with args: ["db", "sleds", "-F", "discretionary"]
8687 2025-08-27T18:35:29.473Z running commands with args: ["mgs", "inventory"]
8688 2025-08-27T18:35:29.473Z running commands with args: ["nexus", "background-tasks", "doc"]
8689 2025-08-27T18:35:29.473Z running commands with args: ["nexus", "background-tasks", "show", "--no-executing-info"]
8690 2025-08-27T18:35:29.473Z running commands with args: ["nexus", "background-tasks", "show", "saga_recovery", "--no-executing-info"]
8691 2025-08-27T18:35:29.473Z running commands with args: ["nexus", "background-tasks", "show", "blueprint_loader", "blueprint_executor", "--no-executing-info"]
8692 2025-08-27T18:35:29.473Z running commands with args: ["nexus", "background-tasks", "show", "dns_internal", "--no-executing-info"]
8693 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "background-tasks", "show", "dns_external", "--no-executing-info"]
8694 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "background-tasks", "show", "all", "--no-executing-info"]
8695 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "chicken-switches", "show", "current"]
8696 2025-08-27T18:35:29.474Z running commands with args: ["-w", "nexus", "chicken-switches", "set", "--planner-enabled", "true"]
8697 2025-08-27T18:35:29.474Z running commands with args: ["-w", "nexus", "chicken-switches", "set", "--add-zones-with-mupdate-override", "false"]
8698 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "chicken-switches", "show", "current"]
8699 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "sagas", "list"]
8700 2025-08-27T18:35:29.474Z running commands with args: ["--destructive", "nexus", "sagas", "demo-create"]
8701 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "sagas", "list"]
8702 2025-08-27T18:35:29.474Z running commands with args: ["--destructive", "nexus", "background-tasks", "activate", "inventory_collection"]
8703 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "blueprints", "list"]
8704 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "blueprints", "show", "23a99d35-004f-4613-ad4f-26ead0647272"]
8705 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "blueprints", "show", "current-target"]
8706 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "blueprints", "diff", "23a99d35-004f-4613-ad4f-26ead0647272", "current-target"]
8707 2025-08-27T18:35:29.474Z running commands with args: ["nexus", "blueprints", "diff", "23a99d35-004f-4613-ad4f-26ead0647272"]
8708 2025-08-27T18:35:29.474Z running commands with args: ["reconfigurator", "export", "/var/tmp/omicron_tmp/.tmpF8kxRw/reconfigurator-export.out"]
8709 2025-08-27T18:35:29.474Z @@ -1126,11 +1126,11 @@
8710 2025-08-27T18:35:29.474Z number of phantom disks deleted: 0
8711 2025-08-27T18:35:29.474Z number of phantom disk delete errors: 0
8712 2025-08-27T18:35:29.474Z
8713 2025-08-27T18:35:29.474Z task: "physical_disk_adoption"
8714 2025-08-27T18:35:29.474Z configured period: every <REDACTED_DURATION>s
8715 2025-08-27T18:35:29.474Z - last completed activation: <REDACTED ITERATIONS>, triggered by a dependent task completing
8716 2025-08-27T18:35:29.474Z + last completed activation: <REDACTED ITERATIONS>, triggered by a periodic timer firing
8717 2025-08-27T18:35:29.474Z started at <REDACTED_TIMESTAMP> (<REDACTED DURATION>s ago) and ran for <REDACTED DURATION>ms
8718 2025-08-27T18:35:29.474Z last completion reported error: task disabled
8719 2025-08-27T18:35:29.474Z
8720 2025-08-27T18:35:29.474Z task: "read_only_region_replacement_start"
8721 2025-08-27T18:35:29.474Z configured period: every <REDACTED_DURATION>m
8722 2025-08-27T18:35:29.474Z
8723 2025-08-27T18:35:29.474Z test test_omdb_success_cases ... FAILED
8724 2025-08-27T18:35:29.474Z
8725 2025-08-27T18:35:29.474Z failures:
8726 2025-08-27T18:35:29.474Z
8727 2025-08-27T18:35:29.474Z failures:
8728 2025-08-27T18:35:29.474Z test_omdb_success_cases
8729 2025-08-27T18:35:29.474Z
8730 2025-08-27T18:35:29.474Z test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 2 filtered out; finished in 57.86s
8731 2025-08-27T18:35:29.475Z
8732 2025-08-27T18:35:29.475Z stderr ───
8733 2025-08-27T18:35:29.475Z log file: /var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.0.log
8734 2025-08-27T18:35:29.475Z note: configured to log to "/var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.0.log"
8735 2025-08-27T18:35:29.475Z DB URL: postgresql://root@[::1]:55234/omicron?sslmode=disable
8736 2025-08-27T18:35:29.475Z DB address: [::1]:55234
8737 2025-08-27T18:35:29.475Z log file: /var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.2.log
8738 2025-08-27T18:35:29.475Z note: configured to log to "/var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.2.log"
8739 2025-08-27T18:35:29.475Z log file: /var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.3.log
8740 2025-08-27T18:35:29.476Z note: configured to log to "/var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.3.log"
8741 2025-08-27T18:35:29.476Z
8742 2025-08-27T18:35:29.476Z thread 'test_omdb_success_cases' panicked at dev-tools/omdb/tests/test_all_output.rs:326:5:
8743 2025-08-27T18:35:29.476Z assertion failed: string doesn't match the contents of file: "tests/successes.out" see diffset above
8744 2025-08-27T18:35:29.476Z set EXPECTORATE=overwrite if these changes are intentional
8745 2025-08-27T18:35:29.476Z stack backtrace:
8746 2025-08-27T18:35:29.476Z 0: __rustc::rust_begin_unwind
8747 2025-08-27T18:35:29.476Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/panicking.rs:697:5
8748 2025-08-27T18:35:29.476Z 1: core::panicking::panic_fmt
8749 2025-08-27T18:35:29.476Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/panicking.rs:75:14
8750 2025-08-27T18:35:29.476Z 2: expectorate::assert_contents
8751 2025-08-27T18:35:29.476Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/expectorate-1.2.0/src/lib.rs:67:9
8752 2025-08-27T18:35:29.476Z 3: {async_fn#0}
8753 2025-08-27T18:35:29.476Z at ./tests/test_all_output.rs:326:5
8754 2025-08-27T18:35:29.476Z 4: {async_block#0}
8755 2025-08-27T18:35:29.476Z at ./tests/test_all_output.rs:132:1
8756 2025-08-27T18:35:29.476Z 5: poll<&mut dyn core::future::future::Future<Output=()>>
8757 2025-08-27T18:35:29.476Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
8758 2025-08-27T18:35:29.476Z 6: poll<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8759 2025-08-27T18:35:29.476Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
8760 2025-08-27T18:35:29.476Z 7: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
8761 2025-08-27T18:35:29.476Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:742:70
8762 2025-08-27T18:35:29.476Z 8: with_budget<core::task::poll::Poll<()>, tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure#0}::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>>
8763 2025-08-27T18:35:29.476Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/task/coop/mod.rs:167:5
8764 2025-08-27T18:35:29.476Z 9: budget<core::task::poll::Poll<()>, tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure#0}::{closure#0}::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>>
8765 2025-08-27T18:35:29.476Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/task/coop/mod.rs:133:5
8766 2025-08-27T18:35:29.476Z 10: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
8767 2025-08-27T18:35:29.476Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:742:25
8768 2025-08-27T18:35:29.476Z 11: tokio::runtime::scheduler::current_thread::Context::enter
8769 2025-08-27T18:35:29.476Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:432:19
8770 2025-08-27T18:35:29.476Z 12: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
8771 2025-08-27T18:35:29.476Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:741:44
8772 2025-08-27T18:35:29.477Z 13: tokio::runtime::scheduler::current_thread::CoreGuard::enter::{{closure}}
8773 2025-08-27T18:35:29.477Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:829:68
8774 2025-08-27T18:35:29.477Z 14: tokio::runtime::context::scoped::Scoped<T>::set
8775 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context/scoped.rs:40:9
8776 2025-08-27T18:35:29.503Z 15: tokio::runtime::context::set_scheduler::{{closure}}
8777 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context.rs:176:38
8778 2025-08-27T18:35:29.503Z 16: try_with<tokio::runtime::context::Context, tokio::runtime::context::set_scheduler::{closure_env#0}<(alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>), tokio::runtime::scheduler::current_thread::{impl#8}::enter::{closure_env#0}<tokio::runtime::scheduler::current_thread::{impl#8}::block_on::{closure_env#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>, core::option::Option<()>>>, (alloc::boxed::Box<tokio::runtime::scheduler::current_thread::Core, alloc::alloc::Global>, core::option::Option<()>)>
8779 2025-08-27T18:35:29.503Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:315:12
8780 2025-08-27T18:35:29.503Z 17: std::thread::local::LocalKey<T>::with
8781 2025-08-27T18:35:29.503Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:279:20
8782 2025-08-27T18:35:29.503Z 18: tokio::runtime::context::set_scheduler
8783 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context.rs:176:17
8784 2025-08-27T18:35:29.503Z 19: tokio::runtime::scheduler::current_thread::CoreGuard::enter
8785 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:829:27
8786 2025-08-27T18:35:29.503Z 20: tokio::runtime::scheduler::current_thread::CoreGuard::block_on
8787 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:729:24
8788 2025-08-27T18:35:29.503Z 21: {closure#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8789 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:200:33
8790 2025-08-27T18:35:29.503Z 22: tokio::runtime::context::runtime::enter_runtime
8791 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context/runtime.rs:65:16
8792 2025-08-27T18:35:29.503Z 23: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8793 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:188:9
8794 2025-08-27T18:35:29.503Z 24: tokio::runtime::runtime::Runtime::block_on_inner
8795 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/runtime.rs:356:52
8796 2025-08-27T18:35:29.503Z 25: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8797 2025-08-27T18:35:29.503Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/runtime.rs:330:18
8798 2025-08-27T18:35:29.503Z 26: test_omdb_success_cases
8799 2025-08-27T18:35:29.503Z at ./tests/test_all_output.rs:132:1
8800 2025-08-27T18:35:29.503Z 27: test_all_output::test_omdb_success_cases::{{closure}}
8801 2025-08-27T18:35:29.503Z at ./tests/test_all_output.rs:133:70
8802 2025-08-27T18:35:29.503Z 28: core::ops::function::FnOnce::call_once
8803 2025-08-27T18:35:29.503Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5
8804 2025-08-27T18:35:29.503Z 29: core::ops::function::FnOnce::call_once
8805 2025-08-27T18:35:29.503Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5
8806 2025-08-27T18:35:29.503Z note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
8807 2025-08-27T18:35:29.503Z WARN: dropped CockroachInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)
8808 2025-08-27T18:35:29.504Z WARN: temporary directory leaked: "/var/tmp/omicron_tmp/.tmpgfyrri"
8809 2025-08-27T18:35:29.504Z If you would like to access the database for debugging, run the following:
8810 2025-08-27T18:35:29.504Z
8811 2025-08-27T18:35:29.504Z # Run the database
8812 2025-08-27T18:35:29.504Z cargo xtask db-dev run --no-populate --store-dir "/var/tmp/omicron_tmp/.tmpgfyrri/data"
8813 2025-08-27T18:35:29.504Z # Access the database. Note the port may change if you run multiple databases.
8814 2025-08-27T18:35:29.504Z cockroach sql --host=localhost:32221 --insecure
8815 2025-08-27T18:35:29.504Z WARN: dropped ClickHouse process without cleaning it up first (there may still be a child process running (PID 885) and a temporary directory leaked, /var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.1-clickhouse-ZoV2r0)
8816 2025-08-27T18:35:29.504Z failed to clean up ClickHouse data dir:
8817 2025-08-27T18:35:29.504Z - /var/tmp/omicron_tmp/test_all_output-5e362b5e1dad6fc7-test_omdb_success_cases.846.1-clickhouse-ZoV2r0: File exists (os error 17)
8818 2025-08-27T18:35:29.504Z WARN: dropped DendriteInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)
8819 2025-08-27T18:35:29.504Z WARN: dendrite temporary directory leaked: /var/tmp/omicron_tmp/.tmpgKQOvG
8820 2025-08-27T18:35:29.504Z WARN: dropped DendriteInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)
8821 2025-08-27T18:35:29.504Z WARN: dendrite temporary directory leaked: /var/tmp/omicron_tmp/.tmpBBs0Yl
8822 2025-08-27T18:35:29.504Z WARN: dropped MgdInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)
8823 2025-08-27T18:35:29.504Z WARN: mgd temporary directory leaked: /var/tmp/omicron_tmp/.tmpA7vf2i
8824 2025-08-27T18:35:29.504Z WARN: dropped MgdInstance without cleaning it up first (there may still be a child process running and a temporary directory leaked)
8825 2025-08-27T18:35:29.504Z WARN: mgd temporary directory leaked: /var/tmp/omicron_tmp/.tmpBKnpbJ
This test failed on a CI run on #8923:
https://github.com/oxidecomputer/omicron/pull/8923/checks?check_run_id=49021845698
Log showing the specific test failure:
https://buildomat.eng.oxide.computer/wg/0/details/01K3P5ZA97Q9F3AF2751KTAV09/mYS9ScmdtQtkWcv2XxHfEe3TQ60S0fKSUiABwqOZlhe6n9TD/01K3P5ZXWV0TJ5YZDA8M5SH0ZH
Excerpt from the log showing the failure: