test failed in CI: test_instance_serial #9420
Description
This test failed on a CI run on #9393:
https://github.com/oxidecomputer/omicron/pull/9393/checks?check_run_id=55736781951
Log showing the specific test failure:
Excerpt from the log showing the failure:
8006 2025-11-18T19:45:32.216Z FAIL [ 358.357s] (1406/2458) omicron-nexus::test_all integration_tests::instances::test_instance_serial
8007 2025-11-18T19:45:32.216Z stdout ───
8008 2025-11-18T19:45:32.217Z
8009 2025-11-18T19:45:32.217Z running 1 test
8010 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8011 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: System }, version: Some(RouterVersion { router_id: 4b524902-7f59-4d5c-9572-9e4e98a066e8, version: 3 }), routes: {ResolvedVpcRoute { dest: V4(Ipv4Net { addr: 0.0.0.0, width: 0 }), target: InternetGateway(Instance(e5783d96-5c3b-4b1d-86ce-333549ad5b25)) }, ResolvedVpcRoute { dest: V4(Ipv4Net { addr: 172.30.0.0, width: 22 }), target: VpcSubnet(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, ResolvedVpcRoute { dest: V6(Ipv6Net { addr: fd10:7351:3629::, width: 64 }), target: VpcSubnet(V6(Ipv6Net { addr: fd10:7351:3629::, width: 64 })) }, ResolvedVpcRoute { dest: V6(Ipv6Net { addr: ::, width: 0 }), target: InternetGateway(Instance(e5783d96-5c3b-4b1d-86ce-333549ad5b25)) }} }
8012 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8013 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8014 2025-11-18T19:45:32.217Z test integration_tests::instances::test_instance_serial has been running for over 60 seconds
8015 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8016 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8017 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8018 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8019 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8020 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8021 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8022 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8023 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8024 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8025 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8026 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8027 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8028 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8029 2025-11-18T19:45:32.217Z sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(7479734), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
8030 2025-11-18T19:45:32.217Z test integration_tests::instances::test_instance_serial ... FAILED
8031 2025-11-18T19:45:32.217Z
8032 2025-11-18T19:45:32.217Z failures:
8033 2025-11-18T19:45:32.217Z
8034 2025-11-18T19:45:32.217Z failures:
8035 2025-11-18T19:45:32.217Z integration_tests::instances::test_instance_serial
8036 2025-11-18T19:45:32.217Z
8037 2025-11-18T19:45:32.217Z test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 551 filtered out; finished in 357.90s
8038 2025-11-18T19:45:32.217Z
8039 2025-11-18T19:45:32.217Z stderr ───
8040 2025-11-18T19:45:32.217Z log file: /var/tmp/omicron_tmp/test_all-878a1aac48a1d5e0-test_instance_serial.27733.0.log
8041 2025-11-18T19:45:32.217Z note: configured to log to "/var/tmp/omicron_tmp/test_all-878a1aac48a1d5e0-test_instance_serial.27733.0.log"
8042 2025-11-18T19:45:32.217Z DB URL: postgresql://root@[::1]:39979/omicron?sslmode=disable
8043 2025-11-18T19:45:32.217Z DB address: [::1]:39979
8044 2025-11-18T19:45:32.217Z log file: /var/tmp/omicron_tmp/test_all-878a1aac48a1d5e0-test_instance_serial.27733.2.log
8045 2025-11-18T19:45:32.218Z note: configured to log to "/var/tmp/omicron_tmp/test_all-878a1aac48a1d5e0-test_instance_serial.27733.2.log"
8046 2025-11-18T19:45:32.218Z
8047 2025-11-18T19:45:32.218Z thread 'integration_tests::instances::test_instance_serial' panicked at nexus/tests/integration_tests/instances.rs:8101:19:
8048 2025-11-18T19:45:32.218Z instance a6caa472-c344-4a8f-8bdb-3a47609c4288 did not transition to Stopped after 320s: timed out after 320.101356253s
8049 2025-11-18T19:45:32.218Z stack backtrace:
8050 2025-11-18T19:45:32.218Z 0: __rustc::rust_begin_unwind
8051 2025-11-18T19:45:32.218Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/panicking.rs:697:5
8052 2025-11-18T19:45:32.218Z 1: core::panicking::panic_fmt
8053 2025-11-18T19:45:32.218Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/panicking.rs:75:14
8054 2025-11-18T19:45:32.218Z 2: {async_fn#0}
8055 2025-11-18T19:45:32.218Z at ./tests/integration_tests/instances.rs:8101:19
8056 2025-11-18T19:45:32.218Z 3: {async_fn#0}
8057 2025-11-18T19:45:32.218Z at ./tests/integration_tests/instances.rs:8052:6
8058 2025-11-18T19:45:32.218Z 4: {async_fn#0}
8059 2025-11-18T19:45:32.218Z at ./tests/integration_tests/instances.rs:6944:14
8060 2025-11-18T19:45:32.218Z 5: {async_block#0}
8061 2025-11-18T19:45:32.218Z at ./tests/integration_tests/instances.rs:6824:1
8062 2025-11-18T19:45:32.218Z 6: poll<&mut dyn core::future::future::Future<Output=()>>
8063 2025-11-18T19:45:32.218Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
8064 2025-11-18T19:45:32.218Z 7: poll<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8065 2025-11-18T19:45:32.218Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/future/future.rs:124:9
8066 2025-11-18T19:45:32.218Z 8: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
8067 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:742:70
8068 2025-11-18T19:45:32.218Z 9: 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=()>>>>>
8069 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/task/coop/mod.rs:167:5
8070 2025-11-18T19:45:32.218Z 10: 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=()>>>>>
8071 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/task/coop/mod.rs:133:5
8072 2025-11-18T19:45:32.218Z 11: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
8073 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:742:25
8074 2025-11-18T19:45:32.218Z 12: tokio::runtime::scheduler::current_thread::Context::enter
8075 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:432:19
8076 2025-11-18T19:45:32.218Z 13: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
8077 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:741:44
8078 2025-11-18T19:45:32.218Z 14: tokio::runtime::scheduler::current_thread::CoreGuard::enter::{{closure}}
8079 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:829:68
8080 2025-11-18T19:45:32.218Z 15: tokio::runtime::context::scoped::Scoped<T>::set
8081 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context/scoped.rs:40:9
8082 2025-11-18T19:45:32.218Z 16: tokio::runtime::context::set_scheduler::{{closure}}
8083 2025-11-18T19:45:32.218Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context.rs:176:38
8084 2025-11-18T19:45:32.219Z 17: 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<()>)>
8085 2025-11-18T19:45:32.219Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:315:12
8086 2025-11-18T19:45:32.219Z 18: std::thread::local::LocalKey<T>::with
8087 2025-11-18T19:45:32.219Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/std/src/thread/local.rs:279:20
8088 2025-11-18T19:45:32.219Z 19: tokio::runtime::context::set_scheduler
8089 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context.rs:176:17
8090 2025-11-18T19:45:32.219Z 20: tokio::runtime::scheduler::current_thread::CoreGuard::enter
8091 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:829:27
8092 2025-11-18T19:45:32.219Z 21: tokio::runtime::scheduler::current_thread::CoreGuard::block_on
8093 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:729:24
8094 2025-11-18T19:45:32.219Z 22: {closure#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8095 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:200:33
8096 2025-11-18T19:45:32.219Z 23: tokio::runtime::context::runtime::enter_runtime
8097 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/context/runtime.rs:65:16
8098 2025-11-18T19:45:32.219Z 24: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8099 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/scheduler/current_thread/mod.rs:188:9
8100 2025-11-18T19:45:32.219Z 25: tokio::runtime::runtime::Runtime::block_on_inner
8101 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/runtime.rs:356:52
8102 2025-11-18T19:45:32.219Z 26: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
8103 2025-11-18T19:45:32.219Z at /home/build/.cargo/registry/src/index.crates.io-1949cf8c6b5b557f/tokio-1.47.0/src/runtime/runtime.rs:330:18
8104 2025-11-18T19:45:32.219Z 27: test_instance_serial
8105 2025-11-18T19:45:32.223Z at ./tests/integration_tests/instances.rs:6824:1
8106 2025-11-18T19:45:32.223Z 28: test_all::integration_tests::instances::test_instance_serial::{{closure}}
8107 2025-11-18T19:45:32.223Z at ./tests/integration_tests/instances.rs:6825:67
8108 2025-11-18T19:45:32.223Z 29: core::ops::function::FnOnce::call_once
8109 2025-11-18T19:45:32.223Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5
8110 2025-11-18T19:45:32.223Z 30: core::ops::function::FnOnce::call_once
8111 2025-11-18T19:45:32.223Z at /rustc/29483883eed69d5fb4db01964cdf2af4d86e9cb2/library/core/src/ops/function.rs:250:5