Time out and unknown state

[bscherer-sdvi]

Describe the bug
Cannot connect to VM, 'Open Shell' and ssh times out. Logs indicate network is being reset regularly. Logs say VM is in an unknown state as well as 'multipass ls'.

To Reproduce
How, and what happened?

1. Rebooted my laptop (2022 M1 Max MBP Ventura 13.2.1)
2. Tried ssh'ing into my ubuntu 20.04 VM

Expected behavior
What did you expect to happen?
To have ssh access to my VM

Logs
Please provide logs from the daemon, see accessing logs on where to find them on your platform.
Ill attach logs to the issue

Additional info

• OS: MacOS 13.2.1

• % multipass version multipass 1.11.1+mac multipassd 1.11.1+mac

• multipass info --all

Name:           primary
State:          Stopped
IPv4:           --
Release:        --
Image hash:     f6b5b3a980f2 (Ubuntu 22.04 LTS)
CPU(s):         --
Load:           --
Disk usage:     --
Memory usage:   --
Mounts:         /Users/brendanscherer => Home
                    UID map: 501:default
                    GID map: 20:default

Name:           brendan-vm
State:          Unknown
IPv4:           --
Release:        --
Image hash:     0f1a20bcda28 (Ubuntu 20.04 LTS)
CPU(s):         --
Load:           --
Disk usage:     --
Memory usage:   --
Mounts:         --

• multipass get local.driver
  qemu

multipassd.log

Additional context
In the logs there are references to qemu crashing

[sharder996]

Hi @bscherer-sdvi, this looks like another case of #2387. If you can, try disabling your firewall and see if that makes any difference.

[bscherer-sdvi]

My firewall is disabled

[bscherer-sdvi]

I also tried running the firewall in debug mode per a comment in that linked issue, but that doesnt seem to work either. I wonder if 13.2.1 has exacerbated this problem as I ran this VM for almost a year with multiple reboots and updates and hadnt had an issue until the past week or so

[townsend2010]

Hi @bscherer-sdvi!

After more closely reviewing the logs you provided, it appears your instance got corrupted somehow:

...
[2023-03-08T18:00:26.814] [warning] [brendan-vm] qcow2: Marking image as corrupt: Preventing invalid write on metadata (overlaps with active L2 table); further corruption events will be suppressed

[2023-03-08T18:00:26.814] [warning] [qemu-system-aarch64] 
[2023-03-08T18:00:26.814] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 814321}, "event": "BLOCK_IMAGE_CORRUPTED", "data": {"device": "hda", "msg": "Preventing invalid write on metadata (overlaps with active L2 table)", "offset": 7671808, "node-name": "#block369", "fatal": true, "size": 20480}}
{"timestamp": {"seconds": 1678320026, "microseconds": 814399}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}

[2023-03-08T18:00:26.814] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 814414}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1678320026, "microseconds": 814423}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1678320026, "microseconds": 814430}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1678320026, "microseconds": 814439}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}

[2023-03-08T18:00:26.814] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 814446}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}

[2023-03-08T18:00:26.816] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 816704}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}

[2023-03-08T18:00:26.816] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 816759}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}

[2023-03-08T18:00:26.816] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 816811}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}

[2023-03-08T18:00:26.816] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 816876}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Input/output error", "operation": "write", "action": "report"}}

[2023-03-08T18:00:26.817] [debug] [brendan-vm] QMP: {"timestamp": {"seconds": 1678320026, "microseconds": 817373}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Operation not supported by device", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1678320026, "microseconds": 817386}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Operation not supported by device", "operation": "write", "action": "report"}}
{"timestamp": {"seconds": 1678320026, "microseconds": 817394}, "event": "BLOCK_IO_ERROR", "data": {"device": "hda", "nospace": false, "node-name": "#block369", "reason": "Operation not supported by device", "operation": "write", "action": "report"}}
...

It's not clear to me how this happened as I don't see any unusual messages proceeding this. If you really want to try recovering this, although I'm not guaranteeing it will work, you can try the following:

1. $ sudo launchctl unload /Library/LaunchDaemons/com.canonical.multipassd.plist
2. $ sudo /Library/Application\ Support/com.canonical.multipass/bin/qemu-img snapshot -d suspend /var/root/Library/Application\ Support/multipassd/qemu/vault/instances/brendan-vm/ubuntu-20.04-server-cloudimg-arm64.img
3. $ sudo /Library/Application\ Support/com.canonical.multipass/bin/qemu-img check -r all /var/root/Library/Application\ Support/multipassd/qemu/vault/instances/brendan-vm/ubuntu-20.04-server-cloudimg-arm64.img
4. $ sudo launchctl load -w /Library/LaunchDaemons/com.canonical.multipassd.plist

I hope this helps and sorry for your troubles!

[jsprat2000]

multipassd.log

I'm having a similar issue. Once I do multipass launch, the instance fails to complete and I get the error "timed out waiting for response". I reviewed the logs and I don't see similar errors ass the one above.

[sharder996]

Hi @jsprat2000, since your issue is being triggered from a different set of conditions and resulting in different logs, can you make a new issue with all the pertinent information?

Thanks!