oxidecomputer / propolis

VMM userspace for illumos bhyve
Mozilla Public License 2.0
178 stars 22 forks source link

Hang on Helios guest restart. #559

Closed rcgoodfellow closed 11 months ago

rcgoodfellow commented 1 year ago

I have a Helios machine running inside Propolis. Issued a reboot after a pkg update in the guest and things seem to be stuck.

Here is the log from propolis-server.

03:19:45.480Z INFO propolis-server: allocating from reservoir (131008MiB) for guest memory
03:19:45.480Z INFO propolis-server: Starting server...
03:19:45.480Z INFO propolis-server: listening
    local_addr = [::]:15043
03:19:46.462Z INFO propolis-server: accepted connection
    local_addr = [::]:15043
    remote_addr = [::1]:43956
03:19:46.463Z INFO propolis-server: new DNS resolver
    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]
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
03:19:51.465Z WARN propolis-server: Failed to determine Nexus: endpoint no record found for Query { name: Name("_nexus._tcp.control-plane.oxide.internal."), query_type: SRV, query_class: IN }
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
03:19:51.466Z INFO propolis-server: initializing new VM
    bootrom = /var/ovmf/OVMF_CODE.fd
    properties = InstanceProperties {\n    id: e892f8ef-7015-401b-80b1-de821fee7970,\n    name: "g3",\n    description: "a falcon vm",\n    image_id: 00000000-0000-0000-0000-000000000000,\n    bootrom_id: 00000000-0000-0000-0000-000000000000,\n    memory: 4096,\n    vcpus: 4,\n}
    spec = V0(\n    InstanceSpecV0 {\n        devices: DeviceSpecV0 {\n            board: Board {\n                cpus: 4,\n                memory_mb: 4096,\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                "com3": SerialPort {\n                    num: Com3,\n                },\n                "com1": SerialPort {\n                    num: Com1,\n                },\n                "com2": SerialPort {\n                    num: Com2,\n                },\n            },\n            pci_pci_bridges: {},\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                "port4": SoftNpuPort {\n                    name: "port4",\n                    backend_name: "a4x2_g3_sn_vnic7",\n                },\n                "port5": SoftNpuPort {\n                    name: "port5",\n                    backend_name: "a4x2_g3_sn_vnic8",\n                },\n                "port1": SoftNpuPort {\n                    name: "port1",\n                    backend_name: "a4x2_g3_sn_vnic1",\n                },\n                "port3": SoftNpuPort {\n                    name: "port3",\n                    backend_name: "a4x2_g3_sn_vnic4",\n                },\n                "port2": SoftNpuPort {\n                    name: "port2",\n                    backend_name: "a4x2_g3_sn_vnic2",\n                },\n                "port0": SoftNpuPort {\n                    name: "port0",\n                    backend_name: "a4x2_g3_sn_vnic0",\n                },\n            },\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/ry/src/testbed/a4x2/cargo-bay/g3",\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/rpool/falcon/topo/a4x2/g3",\n                        readonly: false,\n                    },\n                ),\n            },\n            network_backends: {\n                "a4x2_g3_sn_vnic1": Dlpi(\n                    DlpiNetworkBackend {\n                        vnic_name: "a4x2_g3_sn_vnic1",\n                    },\n                ),\n                "vnic-0.8.0-backend": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: "a4x2_g3_vn_vnic3",\n                    },\n                ),\n                "a4x2_g3_sn_vnic4": Dlpi(\n                    DlpiNetworkBackend {\n                        vnic_name: "a4x2_g3_sn_vnic4",\n                    },\n                ),\n                "a4x2_g3_sn_vnic7": Dlpi(\n                    DlpiNetworkBackend {\n                        vnic_name: "a4x2_g3_sn_vnic7",\n                    },\n                ),\n                "a4x2_g3_sn_vnic0": Dlpi(\n                    DlpiNetworkBackend {\n                        vnic_name: "a4x2_g3_sn_vnic0",\n                    },\n                ),\n                "vnic-0.10.0-backend": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: "a4x2_g3_vn_vnic6",\n                    },\n                ),\n                "a4x2_g3_sn_vnic8": Dlpi(\n                    DlpiNetworkBackend {\n                        vnic_name: "a4x2_g3_sn_vnic8",\n                    },\n                ),\n                "a4x2_g3_sn_vnic2": Dlpi(\n                    DlpiNetworkBackend {\n                        vnic_name: "a4x2_g3_sn_vnic2",\n                    },\n                ),\n                "vnic-0.9.0-backend": Virtio(\n                    VirtioNetworkBackend {\n                        vnic_name: "a4x2_g3_vn_vnic4",\n                    },\n                ),\n            },\n        },\n    },\n)
    use_reservoir = true
03:19:51.473Z INFO propolis-server: Creating vNIC vnic-0.10.0
03:19:51.573Z INFO propolis-server: Creating vNIC vnic-0.8.0
03:19:51.711Z INFO propolis-server: Creating vNIC vnic-0.9.0
03:19:51.784Z INFO propolis-server: softnpu: data links [
        "a4x2_g3_sn_vnic0",
        "a4x2_g3_sn_vnic1",
        "a4x2_g3_sn_vnic2",
        "a4x2_g3_sn_vnic4",
        "a4x2_g3_sn_vnic7",
        "a4x2_g3_sn_vnic8",
    ]
03:19:51.787Z INFO propolis-server: Creating storage device block0 with properties VirtioDisk(VirtioDisk { backend_name: "main_disk", pci_path: PciPath { bus: 0, device: 4, function: 0 } })
03:19:51.787Z INFO propolis-server: Creating file disk backend
    path = /dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
03:19:51.828Z INFO propolis-server (vcpu_tasks): Starting vCPU thread
    vcpu = 0
03:19:51.828Z INFO propolis-server (vcpu_tasks): Starting vCPU thread
    vcpu = 1
03:19:51.828Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 0
03:19:51.828Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 1
03:19:51.828Z INFO propolis-server (vcpu_tasks): Starting vCPU thread
    vcpu = 2
03:19:51.828Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 2
03:19:51.828Z INFO propolis-server (vcpu_tasks): Starting vCPU thread
    vcpu = 3
03:19:51.828Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 3
03:19:51.828Z INFO propolis-server (vm_state_worker): State worker launched
03:19:51.828Z INFO propolis-server (serial task): Entered serial task
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
03:19:51.828Z INFO propolis-server: request completed
    latency_us = 5365415
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    response_code = 201
    uri = /instance
03:19:51.830Z INFO propolis-server (vm_controller): Requested state Run via API
03:19:51.830Z INFO propolis-server (external_request_queue): Queuing external request
    disposition = Enqueue
    request = Start
03:19:51.830Z INFO propolis-server (vm_state_worker): State worker handling event
    event = External(Start)
03:19:51.830Z INFO propolis-server (vm_state_worker): Starting instance
    reason = ExplicitRequest
03:19:51.830Z INFO propolis-server: request completed
    latency_us = 198
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = bd667f9e-aaf4-4081-84d3-3033f48a7b02
    response_code = 204
    uri = /instance/state
03:19:51.830Z INFO propolis-server (vm_controller): Resetting vCPU 0
03:19:51.830Z INFO propolis-server (vm_controller): Resetting BSP vCPU 0
03:19:51.830Z INFO propolis-server (vm_controller): Resetting vCPU 1
03:19:51.830Z INFO propolis-server (vm_controller): Resetting vCPU 2
03:19:51.830Z INFO propolis-server (vm_controller): Resetting vCPU 3
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-bhyve-atpic
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-bhyve-atpit
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-bhyve-hpet
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-bhyve-ioapic
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-bhyve-rtc
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to bhyve-vcpu-0
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to bhyve-vcpu-1
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to bhyve-vcpu-2
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to bhyve-vcpu-3
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to chipset-i440fx
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to pci-piix4-hb
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to pci-piix3-lpc
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to pci-piix3-pm
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-bhyve-pmtimer
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-uart-com3
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-uart-com1
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-uart-com2
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-ps2ctrl
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to qemu-lpc-debug
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to pci-virtio-viona-0.10.0
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to pci-virtio-viona-0.8.0
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to pci-virtio-viona-0.9.0
03:19:51.830Z INFO propolis-server (vm_controller): Sending startup complete to lpc-uart-softnpu-uart
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to pci-virtio-9pfs-softnpu-p9fs
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to softnpu
03:19:51.831Z INFO propolis-server: softnpu: running management handler
03:19:51.831Z INFO propolis-server: starting ingress packet handler for port 0
03:19:51.831Z INFO propolis-server: starting ingress packet handler for port 1
03:19:51.831Z INFO propolis-server: management handler thread started
03:19:51.831Z INFO propolis-server: ingress packet handler is running for port 0
03:19:51.831Z INFO propolis-server: starting ingress packet handler for port 2
03:19:51.831Z INFO propolis-server: ingress packet handler is running for port 1
03:19:51.831Z INFO propolis-server: starting ingress packet handler for port 3
03:19:51.831Z INFO propolis-server: starting ingress packet handler for port 4
03:19:51.831Z INFO propolis-server: ingress packet handler is running for port 2
03:19:51.831Z INFO propolis-server: starting ingress packet handler for port 5
03:19:51.831Z INFO propolis-server: ingress packet handler is running for port 3
03:19:51.831Z INFO propolis-server: ingress packet handler is running for port 4
03:19:51.831Z INFO propolis-server: ingress packet handler is running for port 5
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to pci-virtio-softnpu-port-0.7.0
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to pci-virtio-9pfs
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to pci-virtio-block-0.4.0
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to qemu-fwcfg
03:19:51.831Z INFO propolis-server (vm_controller): Sending startup complete to qemu-ramfb
03:19:51.831Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 1
03:19:51.831Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 0
03:19:51.831Z INFO propolis-server (vm_state_worker): State worker handled event
    outcome = Continue
03:19:51.831Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 2
03:19:51.831Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 3
03:19:51.831Z INFO propolis-server: accepted connection
    local_addr = [::]:15043
    remote_addr = [::1]:34916
03:19:51.832Z INFO propolis-server: request completed
    latency_us = 129
    local_addr = [::]:15043
    method = GET
    remote_addr = [::1]:34916
    req_id = ca2f025a-76e1-4dd9-a873-95dae8efcb10
    response_code = 101
    uri = /instance/serial
03:19:52.015Z INFO propolis-server (ramfb): ramfb change
    config = Config { addr: 3197108224, fourcc: 875713112, flags: 0, width: 800, height: 600, stride: 3200 }
    state = valid
03:19:52.015Z INFO propolis-server (ramfb): notifying
03:19:52.015Z INFO propolis-server (vnc-server): pixel format set to fourcc=0x34325258
03:21:27.983Z WARN propolis-server: read: exact: "/home/ry/src/testbed/a4x2/cargo-bay/g3/omicron/out/dendrite-stub/bin": Os { code: 21, kind: IsADirectory, 03:21:34.899Z INFO propolis-server (serial task): Removing closed serial connection 0.
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
03:21:34.899Z WARN propolis-server (serial task): Failed while closing stream 0: Connection closed normally
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
16:35:49.326Z INFO propolis-server: accepted connection
    local_addr = [::]:15043
    remote_addr = [::ffff:127.0.0.1]:48587
16:35:49.326Z INFO propolis-server: request completed
    latency_us = 83
    local_addr = [::]:15043
    method = GET
    remote_addr = [::ffff:127.0.0.1]:48587
    req_id = 35bb382c-d0d7-457e-9b48-644408b26de3
    response_code = 101
    uri = /instance/serial
16:36:00.307Z WARN propolis-server: attach fid in use: 1
16:47:00.460Z INFO propolis-server (vm_state_worker): State worker handling event
    event = Guest(VcpuSuspendTripleFault(1))
16:47:00.460Z INFO propolis-server (vm_state_worker): Resetting due to triple fault on vCPU 1
16:47:00.460Z INFO propolis-server (vm_state_worker): Resetting instance
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-atpic
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-atpit
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-hpet
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-ioapic
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-rtc
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-0
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-1
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-2
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-3
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to chipset-i440fx
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-piix4-hb
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-piix3-lpc
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-piix3-pm
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-pmtimer
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-com3
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-com1
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-com2
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-ps2ctrl
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to qemu-lpc-debug
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-viona-0.10.0
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-viona-0.8.0
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-viona-0.9.0
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-softnpu-uart
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-9pfs-softnpu-p9fs
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to softnpu
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-softnpu-port-0.7.0
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-9pfs
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-block-0.4.0
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to qemu-fwcfg
16:47:00.460Z INFO propolis-server (vm_controller): Sending pause request to qemu-ramfb
16:47:00.460Z INFO propolis-server (vm_controller): Waiting for entities to pause
16:47:00.460Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-atpic
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-atpit
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-hpet
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-ioapic
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-rtc
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-0
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-1
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-2
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-3
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-piix4-hb
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-piix3-lpc
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-pmtimer
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-piix3-pm
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity chipset-i440fx
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-com3
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-com1
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-com2
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-ps2ctrl
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity qemu-lpc-debug
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-viona-0.10.0
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-viona-0.8.0
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-viona-0.9.0
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-softnpu-uart
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-9pfs-softnpu-p9fs
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity softnpu
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-softnpu-port-0.7.0
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-9pfs
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-block-0.4.0
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity qemu-fwcfg
16:47:00.461Z INFO propolis-server (vm_controller): Got paused future from entity qemu-ramfb
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-atpic
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-atpit
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-hpet
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-ioapic
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-rtc
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-0
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-1
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-2
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-3
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to chipset-i440fx
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-piix4-hb
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-piix3-lpc
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-piix3-pm
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-pmtimer
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-com3
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-com1
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-com2
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-ps2ctrl
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to qemu-lpc-debug
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-viona-0.10.0
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-viona-0.8.0
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-viona-0.9.0
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-softnpu-uart
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-9pfs-softnpu-p9fs
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to softnpu
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-softnpu-port-0.7.0
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-9pfs
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-block-0.4.0
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to qemu-fwcfg
16:47:00.461Z INFO propolis-server (vm_controller): Sending reset request to qemu-ramfb
16:47:00.462Z INFO propolis-server (vm_controller): Resetting vCPU 0
16:47:00.462Z INFO propolis-server (vm_controller): Resetting BSP vCPU 0
16:47:00.462Z INFO propolis-server (vm_controller): Resetting vCPU 1
16:47:00.462Z INFO propolis-server (vm_controller): Resetting vCPU 2
16:47:00.462Z INFO propolis-server (vm_controller): Resetting vCPU 3
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-atpic
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-atpit
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-hpet
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-ioapic
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-rtc
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-0
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-1
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-2
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-3
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to chipset-i440fx
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-piix4-hb
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-piix3-lpc
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-piix3-pm
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-pmtimer
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-com3
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-com1
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-com2
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-ps2ctrl
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to qemu-lpc-debug
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-viona-0.10.0
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-viona-0.8.0
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-viona-0.9.0
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-softnpu-uart
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-9pfs-softnpu-p9fs
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to softnpu
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-softnpu-port-0.7.0
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-9pfs
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-block-0.4.0
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to qemu-fwcfg
16:47:00.462Z INFO propolis-server (vm_controller): Sending resume request to qemu-ramfb
16:47:00.462Z INFO propolis-server (vm_state_worker): State worker handled event
    outcome = Continue
16:47:00.462Z INFO propolis-server (vm_state_worker): State worker handling event
    event = Guest(VcpuSuspendTripleFault(0))
16:47:00.462Z INFO propolis-server (vm_state_worker): Resetting due to triple fault on vCPU 0
16:47:00.462Z INFO propolis-server (vm_state_worker): Resetting instance
16:47:00.462Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 0
16:47:00.462Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 1
16:47:00.462Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 2
16:47:00.462Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 3
16:47:00.462Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-atpic
16:47:00.462Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-atpit
16:47:00.462Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-hpet
16:47:00.462Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-ioapic
16:47:00.462Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-rtc
16:47:00.462Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-0
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-1
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-2
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to bhyve-vcpu-3
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to chipset-i440fx
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-piix4-hb
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-piix3-lpc
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-piix3-pm
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to lpc-bhyve-pmtimer
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-com3
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-com1
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-com2
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to lpc-ps2ctrl
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to qemu-lpc-debug
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-viona-0.10.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-viona-0.8.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-viona-0.9.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to lpc-uart-softnpu-uart
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-9pfs-softnpu-p9fs
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to softnpu
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-softnpu-port-0.7.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-9pfs
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to pci-virtio-block-0.4.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to qemu-fwcfg
16:47:00.463Z INFO propolis-server (vm_controller): Sending pause request to qemu-ramfb
16:47:00.463Z INFO propolis-server (vm_controller): Waiting for entities to pause
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-atpic
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-atpit
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-hpet
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-ioapic
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-rtc
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-0
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-1
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-2
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity bhyve-vcpu-3
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-piix4-hb
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-piix3-lpc
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-bhyve-pmtimer
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-piix3-pm
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity chipset-i440fx
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-com3
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-com1
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-com2
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-ps2ctrl
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity qemu-lpc-debug
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-viona-0.10.0
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-viona-0.8.0
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-viona-0.9.0
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity lpc-uart-softnpu-uart
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-9pfs-softnpu-p9fs
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity softnpu
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-softnpu-port-0.7.0
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-9pfs
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity pci-virtio-block-0.4.0
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity qemu-fwcfg
16:47:00.463Z INFO propolis-server (vm_controller): Got paused future from entity qemu-ramfb
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-atpic
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-atpit
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-hpet
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-ioapic
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-rtc
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-0
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-1
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-2
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to bhyve-vcpu-3
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to chipset-i440fx
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-piix4-hb
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-piix3-lpc
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-piix3-pm
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-bhyve-pmtimer
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-com3
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-com1
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-com2
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-ps2ctrl
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to qemu-lpc-debug
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-viona-0.10.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-viona-0.8.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-viona-0.9.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to lpc-uart-softnpu-uart
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-9pfs-softnpu-p9fs
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to softnpu
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-softnpu-port-0.7.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-9pfs
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to pci-virtio-block-0.4.0
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to qemu-fwcfg
16:47:00.463Z INFO propolis-server (vm_controller): Sending reset request to qemu-ramfb
16:47:00.463Z INFO propolis-server (vm_controller): Resetting vCPU 0
16:47:00.463Z INFO propolis-server (vm_controller): Resetting BSP vCPU 0
16:47:00.463Z INFO propolis-server (vm_controller): Resetting vCPU 1
16:47:00.463Z INFO propolis-server (vm_controller): Resetting vCPU 2
16:47:00.463Z INFO propolis-server (vm_controller): Resetting vCPU 3
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-atpic
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-atpit
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-hpet
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-ioapic
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-rtc
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-0
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-1
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-2
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to bhyve-vcpu-3
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to chipset-i440fx
16:47:00.463Z INFO propolis-server (vm_controller): Sending resume request to pci-piix4-hb
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-piix3-lpc
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-piix3-pm
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to lpc-bhyve-pmtimer
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-com3
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-com1
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-com2
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to lpc-ps2ctrl
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to qemu-lpc-debug
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-viona-0.10.0
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-viona-0.8.0
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-viona-0.9.0
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to lpc-uart-softnpu-uart
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-9pfs-softnpu-p9fs
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to softnpu
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-softnpu-port-0.7.0
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-9pfs
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to pci-virtio-block-0.4.0
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to block-file-/dev/zvol/rdsk/rpool/falcon/topo/a4x2/g3
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to qemu-fwcfg
16:47:00.464Z INFO propolis-server (vm_controller): Sending resume request to qemu-ramfb
16:47:00.464Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 0
16:47:00.464Z INFO propolis-server (vm_state_worker): State worker handled event
    outcome = Continue
16:47:00.464Z INFO propolis-server (vm_state_worker): State worker handling event
    event = Guest(VcpuSuspendTripleFault(3))
16:47:00.464Z INFO propolis-server (vm_state_worker): Resetting due to triple fault on vCPU 3
16:47:00.464Z INFO propolis-server (vm_state_worker): Resetting instance
16:47:00.464Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 2
16:47:00.464Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 3
16:47:00.464Z INFO propolis-server (vcpu_tasks): vCPU released from hold
    vcpu = 1
16:47:00.464Z INFO propolis-server (vcpu_tasks): vCPU paused
    vcpu = 0
16:51:03.252Z INFO propolis-server (serial task): Removing closed serial connection 1.
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
16:51:03.253Z WARN propolis-server (serial task): Failed while closing stream 1: Connection closed normally
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
16:51:05.031Z INFO propolis-server: accepted connection
    local_addr = [::]:15043
    remote_addr = [::ffff:127.0.0.1]:57693
16:51:05.031Z INFO propolis-server: request completed
    latency_us = 69
    local_addr = [::]:15043
    method = GET
    remote_addr = [::ffff:127.0.0.1]:57693
    req_id = f696b729-85d5-4ddf-b3a9-8a851fd237be
    response_code = 101
    uri = /instance/serial
16:53:25.489Z INFO propolis-server (serial task): Removing closed serial connection 2.
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
16:53:25.490Z WARN propolis-server (serial task): Failed while closing stream 2: Connection closed normally
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
16:55:03.465Z INFO propolis-server: accepted connection
    local_addr = [::]:15043
    remote_addr = [::ffff:127.0.0.1]:55625
16:55:03.465Z INFO propolis-server: request completed
    latency_us = 73
    local_addr = [::]:15043
    method = GET
    remote_addr = [::ffff:127.0.0.1]:55625
    req_id = 05a0d722-af18-4137-9840-909121a22eeb
    response_code = 101
    uri = /instance/serial
16:59:15.705Z INFO propolis-server (serial task): Removing closed serial connection 3.
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
16:59:15.705Z WARN propolis-server (serial task): Failed while closing stream 3: Connection closed normally
    local_addr = [::]:15043
    method = PUT
    remote_addr = [::1]:43956
    req_id = 11b57ba2-925d-4b4c-9208-154102775f74
    uri = /instance
pfmooney commented 1 year ago

Part of the challenge here is that vCPUs will race to declare themselves the source of a triple-fault when any one of them incurs one. This has been written up in illumos#16016. Addressing that issue would solve the case of multiple triple-fault events being queued in the state machine.

It is still not clear why we were unable to make forward progress in processing those events (through two reboots in quick succession) during the event in question.