Skip to content

test failed in CI: test_omdb_success_cases #8926

@jgallagher

Description

@jgallagher

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:

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    Test FlakeTests that work. Wait, no. Actually yes. Hang on. Something is broken.

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions