failing to start a VM produces a "cannot drop a runtime in a context where blocking is not allowed" panic

[gjcolombo]

Repro steps: start a VM with an invalid configuration (e.g. an attached NIC that refers to a nonexistent host VNIC).

Expected: initialization fails and returns a nice error message to the instance_ensure caller.

Observed: Propolis panics with a tokio "can't drop a runtime in this context" error.

---

The dropped runtime is the per-VMM runtime that gets created during VM initialization and used to initialize the VMM, run per-component tasks, and the like. This doesn't happen during orderly VM shutdown because Vm::complete_rundown calls shutdown_background on this runtime.

[davepacheco]

For searchability, I wanted to post some data I had from some occurrences of this. I had had a4x2 fail to start. 2 of the 7 Propolis instances hit this.

stderr:

$ cat .falcon/g2.err 
thread 'tokio-rt-api' panicked at /home/build/.cargo/registry/src/index.crates.io-6f17d22bba15001f/tokio-1.38.1/src/runtime/blocking/shutdown.rs:51:21:
Cannot drop a runtime in a context where blocking is not allowed. This happens when a runtime is dropped from within an asynchronous context.
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

stdout:

dap@ivanova a4x2 $ cat .falcon/g2.out 
{"msg":"metric registration is disabled, no metric data will be produced by this server","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:39.334746442-07:00","hostname":"ivanova","pid":3882}
{"msg":"reservoir too small (0MiB) to use for guest memory","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:39.334899464-07:00","hostname":"ivanova","pid":3882}
{"msg":"Starting server...","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:39.335175288-07:00","hostname":"ivanova","pid":3882}
{"msg":"listening","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:39.338306807-07:00","hostname":"ivanova","pid":3882,"local_addr":"[::]:64792"}
{"msg":"accepted connection","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:39.575550093-07:00","hostname":"ivanova","pid":3882,"local_addr":"[::]:64792","remote_addr":"[::1]:62599"}
{"msg":"new DNS resolver","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:39.655992489-07:00","hostname":"ivanova","pid":3882,"uri":"/instance","method":"PUT","req_id":"690b4df0-fdeb-4003-bbda-5c6085b6495b","remote_addr":"[::1]:62599","local_addr":"[::]:64792","addresses":"[[::1:0:0:0:1]:53, [::2:0:0:0:1]:53, [::3:0:0:0:1]:53, [::4:0:0:0:1]:53, [::5:0:0:0:1]:53]"}
{"msg":"Failed to resolve Nexus endpoint","v":0,"name":"propolis-server","level":40,"time":"2025-04-09T09:13:39.659401732-07:00","hostname":"ivanova","pid":3882,"uri":"/instance","method":"PUT","req_id":"690b4df0-fdeb-4003-bbda-5c6085b6495b","remote_addr":"[::1]:62599","local_addr":"[::]:64792","error":"Resolve(ResolveError { kind: Proto(ProtoError { kind: Io(Os { code: 148, kind: HostUnreachable, message: \"No route to host\" }) }) })"}
{"msg":"initializing new VM","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:39.660561066-07:00","hostname":"ivanova","pid":3882,"component":"vm_state_driver","bootrom":"/var/ovmf/OVMF_CODE.fd","use_reservoir":false,"properties":"InstanceProperties {\n    id: cd230087-0268-4b3c-9c94-dcb0f740d3e4,\n    name: \"g2\",\n    description: \"a falcon vm\",\n    metadata: InstanceMetadata {\n        silo_id: 00000000-0000-0000-0000-000000000000,\n        project_id: 00000000-0000-0000-0000-000000000000,\n        sled_id: 00000000-0000-0000-0000-000000000000,\n        sled_serial: \"falcon\",\n        sled_revision: 0,\n        sled_model: \"falcon\",\n    },\n    image_id: 00000000-0000-0000-0000-000000000000,\n    bootrom_id: 00000000-0000-0000-0000-000000000000,\n    memory: 8192,\n    vcpus: 8,\n}","spec":"V0(\n    InstanceSpecV0 {\n        devices: DeviceSpecV0 {\n            board: Board {\n                cpus: 8,\n                memory_mb: 8192,\n                chipset: I440Fx(\n                    I440Fx {\n                        enable_pcie: false,\n                    },\n                ),\n            },\n            storage_devices: {\n                \"block0\": VirtioDisk(\n                    VirtioDisk {\n                        backend_name: \"main_disk\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 4,\n                            function: 0,\n                        },\n                    },\n                ),\n            },\n            network_devices: {\n                \"vnic-0.10.0\": VirtioNic(\n                    VirtioNic {\n                        backend_name: \"vnic-0.10.0-backend\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 10,\n                            function: 0,\n                        },\n                    },\n                ),\n                \"vnic-0.8.0\": VirtioNic(\n                    VirtioNic {\n                        backend_name: \"vnic-0.8.0-backend\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 8,\n                            function: 0,\n                        },\n                    },\n                ),\n                \"vnic-0.9.0\": VirtioNic(\n                    VirtioNic {\n                        backend_name: \"vnic-0.9.0-backend\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 9,\n                            function: 0,\n                        },\n                    },\n                ),\n            },\n            serial_ports: {\n                \"com1\": SerialPort {\n                    num: Com1,\n                },\n                \"com3\": SerialPort {\n                    num: Com3,\n                },\n                \"com2\": SerialPort {\n                    num: Com2,\n                },\n            },\n            pci_pci_bridges: {},\n            qemu_pvpanic: Some(\n                QemuPvpanic {\n                    enable_isa: true,\n                },\n            ),\n            softnpu_pci_port: Some(\n                SoftNpuPciPort {\n                    pci_path: PciPath {\n                        bus: 0,\n                        device: 7,\n                        function: 0,\n                    },\n                },\n            ),\n            softnpu_ports: {},\n            softnpu_p9: Some(\n                SoftNpuP9 {\n                    pci_path: PciPath {\n                        bus: 0,\n                        device: 6,\n                        function: 0,\n                    },\n                },\n            ),\n            p9fs: Some(\n                P9fs {\n                    source: \"/home/dap/testbed/testbed-repo/a4x2/cargo-bay/g2\",\n                    target: \"/opt/cargo-bay\",\n                    chunk_size: 65536,\n                    pci_path: PciPath {\n                        bus: 0,\n                        device: 5,\n                        function: 0,\n                    },\n                },\n            ),\n        },\n        backends: BackendSpecV0 {\n            storage_backends: {\n                \"main_disk\": File(\n                    FileStorageBackend {\n                        path: \"/dev/zvol/rdsk/bigtank/falcon/topo/a4x2/g2\",\n                        readonly: false,\n                    },\n                ),\n            },\n            network_backends: {\n                \"vnic-0.9.0-backend\": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: \"a4x2_g2_vn_vnic1\",\n                    },\n                ),\n                \"vnic-0.10.0-backend\": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: \"a4x2_g2_vn_vnic2\",\n                    },\n                ),\n                \"vnic-0.8.0-backend\": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: \"a4x2_g2_vn_vnic0\",\n                    },\n                ),\n            },\n        },\n    },\n)"}
{"msg":"publishing new instance state","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:47.757973051-07:00","hostname":"ivanova","pid":3882,"component":"vm_state_driver","migration":"InstanceMigrateStatusResponse { migration_in: None, migration_out: None }","state":"Failed","gen":2}
{"msg":"failed to activate new VM","v":0,"name":"propolis-server","level":50,"time":"2025-04-09T09:13:47.758088323-07:00","hostname":"ivanova","pid":3882,"component":"vm_state_driver","error":"creating VM objects for new instance: Not enough space (os error 12)"}
{"msg":"request completed","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:47.758122523-07:00","hostname":"ivanova","pid":3882,"uri":"/instance","method":"PUT","req_id":"690b4df0-fdeb-4003-bbda-5c6085b6495b","remote_addr":"[::1]:62599","local_addr":"[::]:64792","error_message_external":"Internal Server Error","error_message_internal":"VM initialization failed: Not enough space (os error 12)","latency_us":8105576,"response_code":"500"}
{"msg":"new DNS resolver","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:48.760960606-07:00","hostname":"ivanova","pid":3882,"uri":"/instance","method":"PUT","req_id":"6b850218-aee5-4963-b9ca-873adc88c8aa","remote_addr":"[::1]:62599","local_addr":"[::]:64792","addresses":"[[::1:0:0:0:1]:53, [::2:0:0:0:1]:53, [::3:0:0:0:1]:53, [::4:0:0:0:1]:53, [::5:0:0:0:1]:53]"}
{"msg":"Failed to resolve Nexus endpoint","v":0,"name":"propolis-server","level":40,"time":"2025-04-09T09:13:48.76207314-07:00","hostname":"ivanova","pid":3882,"uri":"/instance","method":"PUT","req_id":"6b850218-aee5-4963-b9ca-873adc88c8aa","remote_addr":"[::1]:62599","local_addr":"[::]:64792","error":"Resolve(ResolveError { kind: Proto(ProtoError { kind: Io(Os { code: 148, kind: HostUnreachable, message: \"No route to host\" }) }) })"}
{"msg":"initializing new VM","v":0,"name":"propolis-server","level":30,"time":"2025-04-09T09:13:48.763207644-07:00","hostname":"ivanova","pid":3882,"component":"vm_state_driver","bootrom":"/var/ovmf/OVMF_CODE.fd","use_reservoir":false,"properties":"InstanceProperties {\n    id: cd230087-0268-4b3c-9c94-dcb0f740d3e4,\n    name: \"g2\",\n    description: \"a falcon vm\",\n    metadata: InstanceMetadata {\n        silo_id: 00000000-0000-0000-0000-000000000000,\n        project_id: 00000000-0000-0000-0000-000000000000,\n        sled_id: 00000000-0000-0000-0000-000000000000,\n        sled_serial: \"falcon\",\n        sled_revision: 0,\n        sled_model: \"falcon\",\n    },\n    image_id: 00000000-0000-0000-0000-000000000000,\n    bootrom_id: 00000000-0000-0000-0000-000000000000,\n    memory: 8192,\n    vcpus: 8,\n}","spec":"V0(\n    InstanceSpecV0 {\n        devices: DeviceSpecV0 {\n            board: Board {\n                cpus: 8,\n                memory_mb: 8192,\n                chipset: I440Fx(\n                    I440Fx {\n                        enable_pcie: false,\n                    },\n                ),\n            },\n            storage_devices: {\n                \"block0\": VirtioDisk(\n                    VirtioDisk {\n                        backend_name: \"main_disk\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 4,\n                            function: 0,\n                        },\n                    },\n                ),\n            },\n            network_devices: {\n                \"vnic-0.8.0\": VirtioNic(\n                    VirtioNic {\n                        backend_name: \"vnic-0.8.0-backend\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 8,\n                            function: 0,\n                        },\n                    },\n                ),\n                \"vnic-0.9.0\": VirtioNic(\n                    VirtioNic {\n                        backend_name: \"vnic-0.9.0-backend\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 9,\n                            function: 0,\n                        },\n                    },\n                ),\n                \"vnic-0.10.0\": VirtioNic(\n                    VirtioNic {\n                        backend_name: \"vnic-0.10.0-backend\",\n                        pci_path: PciPath {\n                            bus: 0,\n                            device: 10,\n                            function: 0,\n                        },\n                    },\n                ),\n            },\n            serial_ports: {\n                \"com1\": SerialPort {\n                    num: Com1,\n                },\n                \"com2\": SerialPort {\n                    num: Com2,\n                },\n                \"com3\": SerialPort {\n                    num: Com3,\n                },\n            },\n            pci_pci_bridges: {},\n            qemu_pvpanic: Some(\n                QemuPvpanic {\n                    enable_isa: true,\n                },\n            ),\n            softnpu_pci_port: Some(\n                SoftNpuPciPort {\n                    pci_path: PciPath {\n                        bus: 0,\n                        device: 7,\n                        function: 0,\n                    },\n                },\n            ),\n            softnpu_ports: {},\n            softnpu_p9: Some(\n                SoftNpuP9 {\n                    pci_path: PciPath {\n                        bus: 0,\n                        device: 6,\n                        function: 0,\n                    },\n                },\n            ),\n            p9fs: Some(\n                P9fs {\n                    source: \"/home/dap/testbed/testbed-repo/a4x2/cargo-bay/g2\",\n                    target: \"/opt/cargo-bay\",\n                    chunk_size: 65536,\n                    pci_path: PciPath {\n                        bus: 0,\n                        device: 5,\n                        function: 0,\n                    },\n                },\n            ),\n        },\n        backends: BackendSpecV0 {\n            storage_backends: {\n                \"main_disk\": File(\n                    FileStorageBackend {\n                        path: \"/dev/zvol/rdsk/bigtank/falcon/topo/a4x2/g2\",\n                        readonly: false,\n                    },\n                ),\n            },\n            network_backends: {\n                \"vnic-0.10.0-backend\": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: \"a4x2_g2_vn_vnic2\",\n                    },\n                ),\n                \"vnic-0.8.0-backend\": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: \"a4x2_g2_vn_vnic0\",\n                    },\n                ),\n                \"vnic-0.9.0-backend\": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: \"a4x2_g2_vn_vnic1\",\n                    },\n                ),\n            },\n        },\n    },\n)"}

The core file:

> ::status
debugging core file of propolis-server (64-bit) from ivanova
file: /usr/bin/propolis-server
initial argv: propolis-server run .falcon/g2.toml [::]:0
threading model: native threads
status: process terminated by SIGABRT (Abort), pid=3882 uid=0 code=-1
> $G
C++ symbol demangling enabled
> $C
fffffc7febbf9210 libc.so.1`_lwp_kill+0xa()
fffffc7febbf9240 libc.so.1`raise+0x22(6)
fffffc7febbf9290 libc.so.1`abort+0x58()
fffffc7febbf92a0 0x2867629()
fffffc7febbf92b0 0x2867619()
fffffc7febbf9310 rust_panic+0xd()
fffffc7febbf9440 std::panicking::rust_panic_with_hook::h8fd5c6d4789f4220+0x2d6()
fffffc7febbf9480 std::panicking::begin_panic_handler::{{closure}}::h1269eb099f9c3b9d+0x6a()
fffffc7febbf9490 0x284da19()
fffffc7febbf94c0 0x284fdf6()
fffffc7febbf9500 0x2895b02()
fffffc7febbf9560 0x2565f0c()
fffffc7febbf9670 tokio::runtime::blocking::pool::BlockingPool::shutdown::hc5cf3777824a81b8+0x15d()
fffffc7febbf96a0 core::ptr::drop_in_place$LT$tokio..runtime..runtime..Runtime$GT$::h7f8394086440ae9c +0x61()
fffffc7febbfc0a0 propolis_server::server::instance_ensure_common::{{closure}}::h2ae2a1ba08823ea9+0x249d()
fffffc7febbff1e0 _$LT$FuncType$u20$as$u20$dropshot..handler..HttpHandlerFunc$LT$Context$C$$LP$T0$C$$RP$$C$ResponseType$GT$$GT$::handle_request::_$u7b$$u7b$closure$u7d$$u7d$::h22ca64eaa193fbba +0x42a()
fffffc7febbff6a0 <dropshot::handler::HttpRouteHandler<Context,HandlerType,FuncParams,ResponseType> as dropshot::handler::RouteHandler<Context>>::handle_request::{{closure}}::hb94c87ee9fb8129e+0x391()
fffffc7febbffa70 dropshot::server::http_request_handle::_$u7b$$u7b$closure$u7d$$u7d$::_$u7b$$u7b$closure$u7d$$u7d$::hf81265ad45d7821b +0x111()
fffffc7febbffad0 tokio::runtime::task::core::Core<T,S>::poll::h51f2a2539bf90288+0x39()
fffffc7febbffb30 tokio::runtime::task::harness::Harness<T,S>::poll::h99537afd99077072+0x5b()
fffffc7febbffb80 tokio::runtime::scheduler::multi_thread::worker::Context::run_task::hbd14507c792cc8ad+0x22b()
fffffc7febbffc50 tokio::runtime::scheduler::multi_thread::worker::Context::run::hb246847f547206e4+0xbcb()
fffffc7febbffcb0 tokio::runtime::context::scoped::Scoped<T>::set::h9a171f4a0241a61e+0x2b()
fffffc7febbffd60 tokio::runtime::context::runtime::enter_runtime::hb8f7bc73e8ac8580+0x177()
fffffc7febbffd90 tokio::runtime::scheduler::multi_thread::worker::run::h211d63619a934e41+0x4b()
fffffc7febbffe00 tokio::runtime::task::core::Core<T,S>::poll::h95b26eb4612039c2+0x72()
fffffc7febbffe60 tokio::runtime::task::harness::Harness<T,S>::poll::heec12de9959310fc+0xab()
fffffc7febbfff30 std::sys_common::backtrace::__rust_begin_short_backtrace::hdcc4eac51b55b90e+0x13d()
fffffc7febbfff80 core::ops::function::FnOnce::call_once{{vtable.shim}}::h31259197020b465b+0x7e()
fffffc7febbfffb0 std::sys::pal::unix::thread::Thread::new::thread_start::hc6a6dcaabc211891+0x1b()
fffffc7febbfffe0 libc.so.1`_thrp_setup+0x77(fffffc7feefb0a40)
fffffc7febbffff0 libc.so.1`_lwp_start()