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
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions