search

oxidecomputer / omicron

Omicron: Oxide control plane
Mozilla Public License 2.0
252 stars 40 forks source link

test failed in CI: test_instance_ephemeral_ip_from_correct_pool #7072

Open jgallagher opened 1 week ago

jgallagher commented 1 week ago

This test failed on a CI run on https://github.com/oxidecomputer/omicron/pull/6996:

https://github.com/oxidecomputer/omicron/pull/6996/checks?check_run_id=32997420847

Log showing the specific test failure:

https://buildomat.eng.oxide.computer/wg/0/details/01JCNQZ3ZPYBZG21K4SHG2NAT4/cB71BeZO4zYrsy689IeJAbnxqqyVcSK9G8eKIZdE1Cwmmbsm/01JCNQZT856DJ4SVBCAWWE4PJY

Excerpt from the log showing the failure:

6436    2024-11-14T17:02:04.657Z    --- STDOUT:              omicron-nexus::test_all integration_tests::instances::test_instance_ephemeral_ip_from_correct_pool ---
6437    2024-11-14T17:02:04.657Z    
6438    2024-11-14T17:02:04.657Z    running 1 test
6439    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: System }, version: Some(RouterVersion { router_id: 75d51566-8eb8-41ec-9cf4-ec509ccdeba0, version: 4 }), routes: {ResolvedVpcRoute { dest: V6(Ipv6Net { addr: ::, width: 0 }), target: InternetGateway(Some(f59521de-4f81-4519-a1eb-54f09ba4cfb6)) }, ResolvedVpcRoute { dest: V6(Ipv6Net { addr: fd45:4421:3f54::, width: 64 }), target: VpcSubnet(V6(Ipv6Net { addr: fd45:4421:3f54::, width: 64 })) }, ResolvedVpcRoute { dest: V4(Ipv4Net { addr: 172.30.0.0, width: 22 }), target: VpcSubnet(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, ResolvedVpcRoute { dest: V4(Ipv4Net { addr: 0.0.0.0, width: 0 }), target: InternetGateway(Some(f59521de-4f81-4519-a1eb-54f09ba4cfb6)) }} }
6440    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6441    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: System }, version: Some(RouterVersion { router_id: 75d51566-8eb8-41ec-9cf4-ec509ccdeba0, version: 5 }), routes: {ResolvedVpcRoute { dest: V6(Ipv6Net { addr: fd45:4421:3f54::, width: 64 }), target: VpcSubnet(V6(Ipv6Net { addr: fd45:4421:3f54::, width: 64 })) }, ResolvedVpcRoute { dest: V6(Ipv6Net { addr: ::, width: 0 }), target: InternetGateway(Some(f59521de-4f81-4519-a1eb-54f09ba4cfb6)) }, ResolvedVpcRoute { dest: V4(Ipv4Net { addr: 172.30.0.0, width: 22 }), target: VpcSubnet(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, ResolvedVpcRoute { dest: V4(Ipv4Net { addr: 0.0.0.0, width: 0 }), target: InternetGateway(Some(f59521de-4f81-4519-a1eb-54f09ba4cfb6)) }} }
6442    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6443    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: System }, version: Some(RouterVersion { router_id: 75d51566-8eb8-41ec-9cf4-ec509ccdeba0, version: 6 }), routes: {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: fd45:4421:3f54::, width: 64 }), target: VpcSubnet(V6(Ipv6Net { addr: fd45:4421:3f54::, width: 64 })) }, ResolvedVpcRoute { dest: V6(Ipv6Net { addr: ::, width: 0 }), target: InternetGateway(Some(f59521de-4f81-4519-a1eb-54f09ba4cfb6)) }, ResolvedVpcRoute { dest: V4(Ipv4Net { addr: 0.0.0.0, width: 0 }), target: InternetGateway(Some(f59521de-4f81-4519-a1eb-54f09ba4cfb6)) }} }
6444    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6445    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6446    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6447    2024-11-14T17:02:04.657Z    test integration_tests::instances::test_instance_ephemeral_ip_from_correct_pool has been running for over 60 seconds
6448    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6449    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6450    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6451    2024-11-14T17:02:04.657Z    sled b6d65341-167c-41df-9b5c-41cded99c229 successfully installed routes ResolvedVpcRouteSet { id: RouterId { vni: Vni(13395715), kind: Custom(V4(Ipv4Net { addr: 172.30.0.0, width: 22 })) }, version: None, routes: {} }
6452    2024-11-14T17:02:04.657Z    test integration_tests::instances::test_instance_ephemeral_ip_from_correct_pool ... FAILED
6453    2024-11-14T17:02:04.658Z    
6454    2024-11-14T17:02:04.658Z    failures:
6455    2024-11-14T17:02:04.658Z    
6456    2024-11-14T17:02:04.658Z    failures:
6457    2024-11-14T17:02:04.658Z        integration_tests::instances::test_instance_ephemeral_ip_from_correct_pool
6458    2024-11-14T17:02:04.658Z    
6459    2024-11-14T17:02:04.658Z    test result: FAILED. 0 passed; 1 failed; 0 ignored; 0 measured; 397 filtered out; finished in 159.09s
6460    2024-11-14T17:02:04.658Z    
6461    2024-11-14T17:02:04.658Z    
6462    2024-11-14T17:02:04.658Z    --- STDERR:              omicron-nexus::test_all integration_tests::instances::test_instance_ephemeral_ip_from_correct_pool ---
6463    2024-11-14T17:02:04.658Z    log file: /var/tmp/omicron_tmp/test_all-2d920668872ead29-test_instance_ephemeral_ip_from_correct_pool.134374.0.log
6464    2024-11-14T17:02:04.658Z    note: configured to log to "/var/tmp/omicron_tmp/test_all-2d920668872ead29-test_instance_ephemeral_ip_from_correct_pool.134374.0.log"
6465    2024-11-14T17:02:04.658Z    DB URL: postgresql://root@[::1]:33983/omicron?sslmode=disable
6466    2024-11-14T17:02:04.658Z    DB address: [::1]:33983
6467    2024-11-14T17:02:04.658Z    log file: /var/tmp/omicron_tmp/test_all-2d920668872ead29-test_instance_ephemeral_ip_from_correct_pool.134374.2.log
6468    2024-11-14T17:02:04.658Z    note: configured to log to "/var/tmp/omicron_tmp/test_all-2d920668872ead29-test_instance_ephemeral_ip_from_correct_pool.134374.2.log"
6469    2024-11-14T17:02:04.658Z    log file: /var/tmp/omicron_tmp/test_all-2d920668872ead29-test_instance_ephemeral_ip_from_correct_pool.134374.3.log
6470    2024-11-14T17:02:04.658Z    note: configured to log to "/var/tmp/omicron_tmp/test_all-2d920668872ead29-test_instance_ephemeral_ip_from_correct_pool.134374.3.log"
6471    2024-11-14T17:02:04.658Z    thread 'integration_tests::instances::test_instance_ephemeral_ip_from_correct_pool' panicked at nexus/tests/integration_tests/instances.rs:6129:19:
6472    2024-11-14T17:02:04.658Z    instance 31bfba3b-e21a-4b54-b140-5418c564ccfe did not transition to Stopped after 120s: timed out after 120.895399649s
6473    2024-11-14T17:02:04.658Z    stack backtrace:
6474    2024-11-14T17:02:04.658Z       0: rust_begin_unwind
6475    2024-11-14T17:02:04.658Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/std/src/panicking.rs:665:5
6476    2024-11-14T17:02:04.658Z       1: core::panicking::panic_fmt
6477    2024-11-14T17:02:04.658Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/panicking.rs:74:14
6478    2024-11-14T17:02:04.658Z       2: {async_fn#0}
6479    2024-11-14T17:02:04.659Z                 at ./tests/integration_tests/instances.rs:6129:19
6480    2024-11-14T17:02:04.659Z       3: {async_fn#0}
6481    2024-11-14T17:02:04.659Z                 at ./tests/integration_tests/instances.rs:6080:6
6482    2024-11-14T17:02:04.659Z       4: {async_fn#0}
6483    2024-11-14T17:02:04.659Z                 at ./tests/integration_tests/instances.rs:5472:74
6484    2024-11-14T17:02:04.659Z       5: {async_fn#0}
6485    2024-11-14T17:02:04.659Z                 at ./tests/integration_tests/instances.rs:5418:56
6486    2024-11-14T17:02:04.659Z       6: {async_block#0}
6487    2024-11-14T17:02:04.659Z                 at ./tests/integration_tests/instances.rs:5315:1
6488    2024-11-14T17:02:04.659Z       7: poll<&mut dyn core::future::future::Future<Output=()>>
6489    2024-11-14T17:02:04.659Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/future/future.rs:123:9
6490    2024-11-14T17:02:04.659Z       8: poll<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
6491    2024-11-14T17:02:04.659Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/future/future.rs:123:9
6492    2024-11-14T17:02:04.659Z       9: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
6493    2024-11-14T17:02:04.659Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:696:57
6494    2024-11-14T17:02:04.659Z      10: 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=()>>>>>
6495    2024-11-14T17:02:04.659Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/coop.rs:107:5
6496    2024-11-14T17:02:04.659Z      11: 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=()>>>>>
6497    2024-11-14T17:02:04.659Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/coop.rs:73:5
6498    2024-11-14T17:02:04.659Z      12: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
6499    2024-11-14T17:02:04.659Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:696:25
6500    2024-11-14T17:02:04.659Z      13: tokio::runtime::scheduler::current_thread::Context::enter
6501    2024-11-14T17:02:04.659Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:423:19
6502    2024-11-14T17:02:04.659Z      14: {closure#0}<core::pin::Pin<&mut core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>>
6503    2024-11-14T17:02:04.659Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:695:36
6504    2024-11-14T17:02:04.659Z      15: tokio::runtime::scheduler::current_thread::CoreGuard::enter::{{closure}}
6505    2024-11-14T17:02:04.659Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:774:68
6506    2024-11-14T17:02:04.659Z      16: tokio::runtime::context::scoped::Scoped<T>::set
6507    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/context/scoped.rs:40:9
6508    2024-11-14T17:02:04.660Z      17: tokio::runtime::context::set_scheduler::{{closure}}
6509    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/context.rs:180:26
6510    2024-11-14T17:02:04.660Z      18: 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<()>)>
6511    2024-11-14T17:02:04.660Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/std/src/thread/local.rs:283:12
6512    2024-11-14T17:02:04.660Z      19: std::thread::local::LocalKey<T>::with
6513    2024-11-14T17:02:04.660Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/std/src/thread/local.rs:260:9
6514    2024-11-14T17:02:04.660Z      20: tokio::runtime::context::set_scheduler
6515    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/context.rs:180:9
6516    2024-11-14T17:02:04.660Z      21: tokio::runtime::scheduler::current_thread::CoreGuard::enter
6517    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:774:27
6518    2024-11-14T17:02:04.660Z      22: tokio::runtime::scheduler::current_thread::CoreGuard::block_on
6519    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:683:19
6520    2024-11-14T17:02:04.660Z      23: {closure#0}<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
6521    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:191:28
6522    2024-11-14T17:02:04.660Z      24: tokio::runtime::context::runtime::enter_runtime
6523    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/context/runtime.rs:65:16
6524    2024-11-14T17:02:04.660Z      25: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
6525    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/scheduler/current_thread/mod.rs:179:9
6526    2024-11-14T17:02:04.660Z      26: tokio::runtime::runtime::Runtime::block_on_inner
6527    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/runtime.rs:361:47
6528    2024-11-14T17:02:04.660Z      27: block_on<core::pin::Pin<&mut dyn core::future::future::Future<Output=()>>>
6529    2024-11-14T17:02:04.660Z                 at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.40.0/src/runtime/runtime.rs:335:13
6530    2024-11-14T17:02:04.660Z      28: test_instance_ephemeral_ip_from_correct_pool
6531    2024-11-14T17:02:04.660Z                 at ./tests/integration_tests/instances.rs:5315:1
6532    2024-11-14T17:02:04.660Z      29: test_all::integration_tests::instances::test_instance_ephemeral_ip_from_correct_pool::{{closure}}
6533    2024-11-14T17:02:04.660Z                 at ./tests/integration_tests/instances.rs:5318:2
6534    2024-11-14T17:02:04.664Z      30: core::ops::function::FnOnce::call_once
6535    2024-11-14T17:02:04.664Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/ops/function.rs:250:5
6536    2024-11-14T17:02:04.664Z      31: core::ops::function::FnOnce::call_once
6537    2024-11-14T17:02:04.664Z                 at /rustc/eeb90cda1969383f56a2637cbd3037bdf598841c/library/core/src/ops/function.rs:250:5