MacOS upgrade to Multipass 1.12: cannot connect to the multipass socket [solved?]

asdf072 · June 21, 2023, 8:49pm

I updated to multipass 1.12, and I now get a “cannot connect to multipass socket” for any commands. I tried uninstalling/reinstalling with brew and package installer. I tried to set /var/run/multipass_socket with chmod a+w. Is there something I’m missing?

[2023-06-21T15:58:21.224] [warning] [Qt] Empty filename passed to function
[2023-06-21T15:58:22.169] [debug] [update] Latest Multipass release available is version 1.12.0
[2023-06-21T15:58:22.824] [info] [VMImageHost] Did not find any supported products in "appliance"
[2023-06-21T15:58:22.827] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2023-06-21T15:58:22.828] [debug] [blueprint provider] Loading "charm-dev" v1
[2023-06-21T15:58:22.828] [debug] [blueprint provider] Loading "docker" v1
[2023-06-21T15:58:22.829] [debug] [blueprint provider] Loading "jellyfin" v1
[2023-06-21T15:58:22.829] [debug] [blueprint provider] Loading "minikube" v1
[2023-06-21T15:58:22.830] [debug] [blueprint provider] Loading "ros-noetic" v1
[2023-06-21T15:58:22.834] [debug] [blueprint provider] Loading "ros2-humble" v1
[2023-06-21T15:58:22.843] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket
[2023-06-21T15:58:22.848] [debug] [qemu-img] [808] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/ubuntu-22.04-server-cloudimg-arm64.img
[2023-06-21T15:58:22.925] [info] [sshfs-mount-handler] initializing mount /Users/shane/vagrant => /vagrant in 'ubuntu-lts'
[2023-06-21T15:58:22.925] [info] [daemon] Starting Multipass 1.12.0+mac
[2023-06-21T15:58:22.925] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
E0621 15:58:23.202677000 6135115776 tcp_server_posix.cc:245]           Failed getpeername: Invalid argument
[2023-06-21T16:15:22.967] [info] [daemon] Received signal 15 (Terminated: 15)
[2023-06-21T16:15:22.968] [info] [daemon] Goodbye!

Solved: I happened to have a MacOS update to 13.4.1, and everything works now. I have no idea why. Maybe the socket file was rewritten.

georgeliaojia · June 22, 2023, 7:53am

Hi @asdf072 , I am glad MacOS upgrade solved that. About the error, it normally means that the server process multipassd was not present, so the client process multipass can not connect, the last 4th and 3rd line of the log indicated that the mutipassd launching failed. Why it failed on that version of MacOS is not clear to me though. Anyway, thanks for reporting this.

bbatuhan · June 25, 2023, 11:19pm

Hello! I’m having the same issue after following the instructions in “How to use multipass remotely | macOS”. I tried uninstalling/reinstalling both through the .pkg file and brew cask. After a clean install, I can see that Multipass works with no problems, but after following the instructions on how to expose the local instance to the network my multipass_socket file in /var/run disappears. Logs for reference:

[2023-06-26T02:05:29.456] [warning] [Qt] Empty filename passed to function
[2023-06-26T02:05:29.893] [debug] [update] Latest Multipass release available is version 1.12.0
[2023-06-26T02:05:33.006] [info] [VMImageHost] Did not find any supported products in “appliance”
[2023-06-26T02:05:33.009] [debug] [blueprint provider] Loading “anbox-cloud-appliance” v1
[2023-06-26T02:05:33.009] [debug] [blueprint provider] Loading “charm-dev” v1
[2023-06-26T02:05:33.010] [debug] [blueprint provider] Loading “docker” v1
[2023-06-26T02:05:33.010] [debug] [blueprint provider] Loading “jellyfin” v1
[2023-06-26T02:05:33.011] [debug] [blueprint provider] Loading “minikube” v1
[2023-06-26T02:05:33.011] [debug] [blueprint provider] Loading “ros-noetic” v1
[2023-06-26T02:05:33.011] [debug] [blueprint provider] Loading “ros2-humble” v1
[2023-06-26T02:05:33.023] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket
[2023-06-26T02:05:33.024] [warning] [Qt] QIODevice::write (QFile, “/var/root/Library/Caches/multipassd/qemu/vault/multipassd-image-records.json”): device not open
[2023-06-26T02:05:33.024] [info] [daemon] Starting Multipass 1.12.0+mac
[2023-06-26T02:05:33.024] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
E0626 02:05:33.874993000 6181285888 tcp_server_posix.cc:245] Failed getpeername: Invalid argument
[2023-06-26T02:11:23.144] [info] [daemon] Received signal 15 (Terminated: 15)
[2023-06-26T02:11:23.144] [info] [daemon] Goodbye!
[2023-06-26T02:11:28.677] [warning] [Qt] Empty filename passed to function
[2023-06-26T02:11:28.864] [info] [VMImageHost] Did not find any supported products in “appliance”
[2023-06-26T02:11:29.168] [debug] [update] Latest Multipass release available is version 1.12.0
[2023-06-26T02:11:29.174] [debug] [blueprint provider] Loading “anbox-cloud-appliance” v1
[2023-06-26T02:11:29.175] [debug] [blueprint provider] Loading “charm-dev” v1
[2023-06-26T02:11:29.176] [debug] [blueprint provider] Loading “docker” v1
[2023-06-26T02:11:29.176] [debug] [blueprint provider] Loading “jellyfin” v1
[2023-06-26T02:11:29.177] [debug] [blueprint provider] Loading “minikube” v1
[2023-06-26T02:11:29.177] [debug] [blueprint provider] Loading “ros-noetic” v1
[2023-06-26T02:11:29.177] [debug] [blueprint provider] Loading “ros2-humble” v1
[2023-06-26T02:11:29.182] [info] [rpc] gRPC listening on localhost:51001
[2023-06-26T02:11:29.183] [warning] [Qt] QIODevice::write (QFile, “/var/root/Library/Caches/multipassd/qemu/vault/multipassd-image-records.json”): device not open
[2023-06-26T02:11:29.183] [info] [daemon] Starting Multipass 1.12.0+mac
[2023-06-26T02:11:29.183] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug --address localhost:51001

Could someone help me debug this issue please?

townsend · June 26, 2023, 3:34pm

Hi @bbatuhan!

I answered your question here.

Thanks!

qkboy · July 11, 2023, 6:24am

Actually, it can met this error everytime when we switch different virtual machine hypervisor driver.
$ multipass set local.driver=qemu
$ multipass list
list failed: cannot connect to the multipass socket

There are some error log in /Library/Logs/Multipass/multipassd.log
[2023-07-10T21:05:34.318] [info] [daemon] Starting Multipass 1.12.0+mac
[2023-07-10T21:05:34.318] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
E0710 21:05:34.534287000 123145352540160 tcp_server_posix.cc:245] Failed getpeername: Invalid argument

Restart mac os can workaround it.

MacOS version Ventura 13.4.1

ricab · July 11, 2023, 10:24am

Hi @qkboy, I’m sorry you’re experiencing this. It is a known bug that we’ve already fixed and will release soon. In the meantime, hopefully the workaround in the bug report will be helpfull.

asdf072 · October 10, 2023, 2:11pm

The MacOS update was not the fix. It was a bug with the menu bar helper app. This has been fixed in MP

jimmywa · November 7, 2023, 8:02am

The problem could be resovled by below commands:

sudo launchctl unload /Library/LaunchDaemons/com.canonical.multipassd.plist
sudo launchctl load /Library/LaunchDaemons/com.canonical.multipassd.plist

balupton · February 25, 2024, 8:18am

I’m getting this. Tried reinstalling multipass as well. Menubar app is running.


> multipass shell -v redacted

start failed: cannot connect to the multipass socket

> multipass --version

multipass 1.13.1+mac

multipassd 1.13.1+mac

Deleted the log, opened mutlipass, tired to start the shell via the menubar, menubar crashes, here is the log:


[2024-02-25T16:38:03.146] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1

[2024-02-25T16:38:03.147] [debug] [blueprint provider] Loading "charm-dev" v1

[2024-02-25T16:38:03.148] [debug] [blueprint provider] Loading "docker" v1

[2024-02-25T16:38:03.148] [debug] [blueprint provider] Loading "jellyfin" v1

[2024-02-25T16:38:03.149] [debug] [blueprint provider] Loading "minikube" v1

[2024-02-25T16:38:03.149] [debug] [blueprint provider] Loading "ros-noetic" v1

[2024-02-25T16:38:03.150] [debug] [blueprint provider] Loading "ros2-humble" v1

[2024-02-25T16:38:03.156] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket

[2024-02-25T16:38:03.156] [debug] [async task] fetch manifest periodically

[2024-02-25T16:38:03.168] [debug] [qemu-img] [60742] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.168] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T16:38:03.219] [debug] [qemu-img] [60743] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.238] [debug] [qemu-img] [60744] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.245] [debug] [qemu-img] [60745] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.252] [info] [daemon] Starting Multipass 1.13.1+mac

[2024-02-25T16:38:03.252] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug

[2024-02-25T16:38:04.494] [debug] [update] Latest Multipass release available is version 1.13.1

Rebooted my system and now multipass doesn’t crash when failing to start, so here are some better logs:


[2024-02-25T16:38:03.146] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1

[2024-02-25T16:38:03.147] [debug] [blueprint provider] Loading "charm-dev" v1

[2024-02-25T16:38:03.148] [debug] [blueprint provider] Loading "docker" v1

[2024-02-25T16:38:03.148] [debug] [blueprint provider] Loading "jellyfin" v1

[2024-02-25T16:38:03.149] [debug] [blueprint provider] Loading "minikube" v1

[2024-02-25T16:38:03.149] [debug] [blueprint provider] Loading "ros-noetic" v1

[2024-02-25T16:38:03.150] [debug] [blueprint provider] Loading "ros2-humble" v1

[2024-02-25T16:38:03.156] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket

[2024-02-25T16:38:03.156] [debug] [async task] fetch manifest periodically

[2024-02-25T16:38:03.168] [debug] [qemu-img] [60742] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.168] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T16:38:03.219] [debug] [qemu-img] [60743] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.238] [debug] [qemu-img] [60744] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.245] [debug] [qemu-img] [60745] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T16:38:03.252] [info] [daemon] Starting Multipass 1.13.1+mac

[2024-02-25T16:38:03.252] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug

[2024-02-25T16:38:04.494] [debug] [update] Latest Multipass release available is version 1.13.1

[2024-02-25T16:53:03.463] [debug] [async task] fetch manifest periodically

[2024-02-25T16:53:03.493] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T17:08:03.471] [debug] [async task] fetch manifest periodically

[2024-02-25T17:08:03.490] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T17:23:03.454] [debug] [async task] fetch manifest periodically

[2024-02-25T17:23:03.473] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T17:38:03.444] [debug] [async task] fetch manifest periodically

[2024-02-25T17:38:03.512] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T17:53:03.415] [debug] [async task] fetch manifest periodically

[2024-02-25T17:53:03.534] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T18:08:03.416] [debug] [async task] fetch manifest periodically

[2024-02-25T18:08:03.452] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T18:23:03.431] [debug] [async task] fetch manifest periodically

[2024-02-25T18:23:03.456] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T18:38:03.405] [debug] [async task] fetch manifest periodically

[2024-02-25T18:38:03.415] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T18:53:03.395] [debug] [async task] fetch manifest periodically

[2024-02-25T18:53:03.413] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T19:08:03.385] [debug] [async task] fetch manifest periodically

[2024-02-25T19:08:03.406] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T19:23:03.371] [debug] [async task] fetch manifest periodically

[2024-02-25T19:23:03.380] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T19:38:03.361] [debug] [async task] fetch manifest periodically

[2024-02-25T19:38:03.378] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T19:53:03.349] [debug] [async task] fetch manifest periodically

[2024-02-25T19:53:03.357] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T20:08:03.325] [debug] [async task] fetch manifest periodically

[2024-02-25T20:08:03.348] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T20:23:03.317] [debug] [async task] fetch manifest periodically

[2024-02-25T20:23:03.339] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T20:38:03.326] [debug] [async task] fetch manifest periodically

[2024-02-25T20:38:03.337] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T20:53:03.329] [debug] [async task] fetch manifest periodically

[2024-02-25T20:53:03.350] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T21:08:03.306] [debug] [async task] fetch manifest periodically

[2024-02-25T21:08:03.339] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T21:09:49.395] [info] [daemon] Received signal 15 (Terminated: 15)

[2024-02-25T21:09:49.397] [info] [daemon] Goodbye!

[2024-02-25T21:12:12.372] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1

[2024-02-25T21:12:12.374] [debug] [blueprint provider] Loading "charm-dev" v1

[2024-02-25T21:12:12.375] [debug] [blueprint provider] Loading "docker" v1

[2024-02-25T21:12:12.375] [debug] [blueprint provider] Loading "jellyfin" v1

[2024-02-25T21:12:12.376] [debug] [blueprint provider] Loading "minikube" v1

[2024-02-25T21:12:12.376] [debug] [blueprint provider] Loading "ros-noetic" v1

[2024-02-25T21:12:12.377] [debug] [blueprint provider] Loading "ros2-humble" v1

[2024-02-25T21:12:12.437] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket

[2024-02-25T21:12:12.437] [debug] [async task] fetch manifest periodically

[2024-02-25T21:12:12.459] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T21:12:12.460] [debug] [qemu-img] [1168] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T21:12:12.837] [warning] [url downloader] Error getting https://multipass.run/static/latest-release.json: Connection closed - trying cache.

[2024-02-25T21:12:12.858] [info] [update] Failed to fetch update info: failed to download from 'https://multipass.run/static/latest-release.json': Error opening https://multipass.run/static/latest-release.json

[2024-02-25T21:12:12.962] [debug] [qemu-img] [1174] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T21:12:12.990] [debug] [qemu-img] [1175] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T21:12:13.008] [debug] [qemu-img] [1176] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-25T21:12:13.015] [info] [daemon] Starting Multipass 1.13.1+mac

[2024-02-25T21:12:13.015] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug

[2024-02-25T21:27:12.691] [debug] [async task] fetch manifest periodically

[2024-02-25T21:27:12.726] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T21:42:12.647] [debug] [async task] fetch manifest periodically

[2024-02-25T21:42:12.662] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T21:57:12.624] [debug] [async task] fetch manifest periodically

[2024-02-25T21:57:12.637] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T22:12:12.602] [debug] [async task] fetch manifest periodically

[2024-02-25T22:12:12.614] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T22:27:12.582] [debug] [async task] fetch manifest periodically

[2024-02-25T22:27:12.604] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T22:42:12.576] [debug] [async task] fetch manifest periodically

[2024-02-25T22:42:12.586] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T22:57:12.565] [debug] [async task] fetch manifest periodically

[2024-02-25T22:57:12.579] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T23:12:12.575] [debug] [async task] fetch manifest periodically

[2024-02-25T23:12:12.592] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T23:27:12.564] [debug] [async task] fetch manifest periodically

[2024-02-25T23:27:12.574] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T23:42:12.570] [debug] [async task] fetch manifest periodically

[2024-02-25T23:42:12.579] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-25T23:57:12.562] [debug] [async task] fetch manifest periodically

[2024-02-25T23:57:12.573] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T00:12:12.555] [debug] [async task] fetch manifest periodically

[2024-02-26T00:12:12.564] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T00:27:12.511] [debug] [async task] fetch manifest periodically

[2024-02-26T00:27:12.530] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T00:42:12.474] [debug] [async task] fetch manifest periodically

[2024-02-26T00:42:12.487] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T00:57:12.442] [debug] [async task] fetch manifest periodically

[2024-02-26T00:57:12.451] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T01:12:12.435] [debug] [async task] fetch manifest periodically

[2024-02-26T01:12:12.444] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T01:27:12.399] [debug] [async task] fetch manifest periodically

[2024-02-26T01:27:12.407] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T01:42:12.364] [debug] [async task] fetch manifest periodically

[2024-02-26T01:42:12.378] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T01:57:12.346] [debug] [async task] fetch manifest periodically

[2024-02-26T01:57:12.356] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T02:12:12.367] [debug] [async task] fetch manifest periodically

[2024-02-26T02:12:12.376] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T02:27:12.380] [debug] [async task] fetch manifest periodically

[2024-02-26T02:27:12.391] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T02:42:12.375] [debug] [async task] fetch manifest periodically

[2024-02-26T02:42:12.395] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T02:57:12.339] [debug] [async task] fetch manifest periodically

[2024-02-26T02:57:12.361] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T03:12:12.331] [debug] [async task] fetch manifest periodically

[2024-02-26T03:12:12.339] [debug] [image vault] Checking for images to update…

[2024-02-26T03:12:12.342] [error] [daemon] Error updating images: Remote "release" is unknown or unreachable. If image mirror is enabled, please confirm it is valid.

[2024-02-26T03:12:12.343] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T03:27:12.296] [debug] [async task] fetch manifest periodically

[2024-02-26T03:27:12.310] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T03:42:12.278] [debug] [async task] fetch manifest periodically

[2024-02-26T03:42:12.289] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T03:57:12.269] [debug] [async task] fetch manifest periodically

[2024-02-26T03:57:12.298] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T04:12:12.251] [debug] [async task] fetch manifest periodically

[2024-02-26T04:12:12.263] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T04:27:12.202] [debug] [async task] fetch manifest periodically

[2024-02-26T04:27:12.213] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T04:42:12.168] [debug] [async task] fetch manifest periodically

[2024-02-26T04:42:12.179] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T04:57:12.151] [debug] [async task] fetch manifest periodically

[2024-02-26T04:57:12.161] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T05:12:12.113] [debug] [async task] fetch manifest periodically

[2024-02-26T05:12:12.124] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T05:27:12.103] [debug] [async task] fetch manifest periodically

[2024-02-26T05:27:12.114] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T05:42:12.063] [debug] [async task] fetch manifest periodically

[2024-02-26T05:42:12.077] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T05:57:12.036] [debug] [async task] fetch manifest periodically

[2024-02-26T05:57:12.053] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T06:12:12.033] [debug] [async task] fetch manifest periodically

[2024-02-26T06:12:12.039] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T06:27:12.013] [debug] [async task] fetch manifest periodically

[2024-02-26T06:27:12.024] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T06:42:11.994] [debug] [async task] fetch manifest periodically

[2024-02-26T06:42:12.008] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T06:46:54.558] [debug] [redacted] process working dir ''

[2024-02-26T06:46:54.558] [info] [redacted] process program 'qemu-system-aarch64'

[2024-02-26T06:46:54.559] [info] [redacted] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b, -nic, vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 2048M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso, -loadvm, suspend, -machine, virt-8.0'

[2024-02-26T06:46:54.559] [info] [redacted] Resuming from a suspended state

[2024-02-26T06:46:54.559] [info] [redacted] process state changed to Starting

[2024-02-26T06:46:54.575] [info] [redacted] process state changed to Running

[2024-02-26T06:46:54.575] [debug] [qemu-system-aarch64] [90076] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b -nic vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 2048M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso -loadvm suspend -machine virt-8.0

[2024-02-26T06:46:54.575] [info] [redacted] process started

[2024-02-26T06:46:54.578] [debug] [redacted] Waiting for SSH to be up

[2024-02-26T06:46:55.395] [debug] [redacted] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-26T06:46:58.332] [warning] [redacted] qemu-system-aarch64: Received an unexpected compressed page

qemu-system-aarch64: error while loading state section id 2(ram)

[2024-02-26T06:46:58.332] [warning] [qemu-system-aarch64]

[2024-02-26T06:46:58.332] [warning] [redacted] qemu-system-aarch64: Error -22 while loading VM state

[2024-02-26T06:46:58.333] [warning] [qemu-system-aarch64]

[2024-02-26T06:46:58.340] [info] [redacted] process state changed to NotRunning

[2024-02-26T06:46:58.340] [info] [redacted] process finished with exit code 1

[2024-02-26T06:47:15.655] [debug] [redacted] Resetting the network

[2024-02-26T06:47:16.465] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1

[2024-02-26T06:47:16.465] [debug] [blueprint provider] Loading "charm-dev" v1

[2024-02-26T06:47:16.466] [debug] [blueprint provider] Loading "docker" v1

[2024-02-26T06:47:16.466] [debug] [blueprint provider] Loading "jellyfin" v1

[2024-02-26T06:47:16.466] [debug] [blueprint provider] Loading "minikube" v1

[2024-02-26T06:47:16.467] [debug] [blueprint provider] Loading "ros-noetic" v1

[2024-02-26T06:47:16.467] [debug] [blueprint provider] Loading "ros2-humble" v1

[2024-02-26T06:47:16.469] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket

[2024-02-26T06:47:16.469] [debug] [async task] fetch manifest periodically

[2024-02-26T06:47:16.473] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T06:47:16.475] [debug] [qemu-img] [90093] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:47:16.514] [debug] [qemu-img] [90094] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:47:16.522] [debug] [qemu-img] [90095] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:47:16.539] [debug] [qemu-img] [90096] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:47:16.545] [info] [daemon] Starting Multipass 1.13.1+mac

[2024-02-26T06:47:16.545] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug

[2024-02-26T06:47:17.701] [debug] [update] Latest Multipass release available is version 1.13.1

[2024-02-26T06:47:47.520] [debug] [redacted] process working dir ''

[2024-02-26T06:47:47.520] [info] [redacted] process program 'qemu-system-aarch64'

[2024-02-26T06:47:47.520] [info] [redacted] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b, -nic, vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 2048M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso, -loadvm, suspend, -machine, virt-8.0'

[2024-02-26T06:47:47.520] [info] [redacted] Resuming from a suspended state

[2024-02-26T06:47:47.520] [info] [redacted] process state changed to Starting

[2024-02-26T06:47:47.525] [info] [redacted] process state changed to Running

[2024-02-26T06:47:47.526] [debug] [qemu-system-aarch64] [90243] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b -nic vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 2048M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso -loadvm suspend -machine virt-8.0

[2024-02-26T06:47:47.526] [info] [redacted] process started

[2024-02-26T06:47:47.527] [debug] [redacted] Waiting for SSH to be up

[2024-02-26T06:47:47.813] [debug] [redacted] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-26T06:47:49.490] [warning] [redacted] qemu-system-aarch64: Received an unexpected compressed page

qemu-system-aarch64: error while loading state section id 2(ram)

[2024-02-26T06:47:49.490] [warning] [qemu-system-aarch64]

[2024-02-26T06:47:49.490] [warning] [redacted] qemu-system-aarch64: Error -22 while loading VM state

[2024-02-26T06:47:49.490] [warning] [qemu-system-aarch64]

[2024-02-26T06:47:49.494] [info] [redacted] process state changed to NotRunning

[2024-02-26T06:47:49.494] [info] [redacted] process finished with exit code 1

[2024-02-26T06:48:08.605] [debug] [redacted] Resetting the network

[2024-02-26T06:48:09.465] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1

[2024-02-26T06:48:09.466] [debug] [blueprint provider] Loading "charm-dev" v1

[2024-02-26T06:48:09.467] [debug] [blueprint provider] Loading "docker" v1

[2024-02-26T06:48:09.467] [debug] [blueprint provider] Loading "jellyfin" v1

[2024-02-26T06:48:09.467] [debug] [blueprint provider] Loading "minikube" v1

[2024-02-26T06:48:09.468] [debug] [blueprint provider] Loading "ros-noetic" v1

[2024-02-26T06:48:09.468] [debug] [blueprint provider] Loading "ros2-humble" v1

[2024-02-26T06:48:09.473] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket

[2024-02-26T06:48:09.473] [debug] [async task] fetch manifest periodically

[2024-02-26T06:48:09.478] [debug] [qemu-img] [90254] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:48:09.479] [info] [VMImageHost] Did not find any supported products in "appliance"

[2024-02-26T06:48:09.492] [debug] [qemu-img] [90255] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:48:09.502] [debug] [qemu-img] [90256] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:48:09.509] [debug] [qemu-img] [90257] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img

[2024-02-26T06:48:09.517] [info] [daemon] Starting Multipass 1.13.1+mac

[2024-02-26T06:48:09.517] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug

[2024-02-26T06:48:10.349] [debug] [update] Latest Multipass release available is version 1.13.1

Ok, I found this https://github.com/canonical/multipass/issues/3168#issuecomment-1645718979 which recommended this sudo qemu-img check /var/root/Library/Application\ Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img which returned this:

3101 errors were found on the image.
Data may be corrupted, or further writes to the image may corrupt it.

76308 leaked clusters were found on the image.
This means waste of disk space, but no harm to data.
220763/327680 = 67.37% allocated, 19.10% fragmented, 5.32% compressed clusters
Image end offset: 15427895296

Running it with -r all returned:

The following inconsistencies were found and repaired:

    76308 leaked clusters
    3450 corruptions

Double checking the fixed image now...
No errors were found on the image.
220763/327680 = 67.37% allocated, 19.10% fragmented, 5.32% compressed clusters
Image end offset: 15427895296

However, starting it still failed.

luisp · February 26, 2024, 1:38pm

Hi @balupton, thanks for reporting. You did well, the disk image was corrupted and you fixed it. But, inspecting the logs, I see that there are connection errors. Do you have some network software running like VPN, firewall? Thanks!

balupton · February 27, 2024, 5:50am

It use to work fine except for the last week. One of the things that changed during that period was I briefly installed Cloudflare Warp, however I uninstalled it right away. I just installed it again, and used its own unintaller, and no difference. Also tried disabling AdGuard for Mac (which offers a DNS service) and disabling the macOS Firewall, both offered no change, and have been running for years without issue with Multipass.

Here are debug logs of the daemon, and from trying to start the instance, and it also captures the crash:

> sudo /Library/Application\ Support/com.canonical.multipass/bin/multipassd --verbosity debug
Password:
[2024-02-27T13:52:55.745] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2024-02-27T13:52:55.746] [debug] [blueprint provider] Loading "charm-dev" v1
[2024-02-27T13:52:55.747] [debug] [blueprint provider] Loading "docker" v1
[2024-02-27T13:52:55.747] [debug] [blueprint provider] Loading "jellyfin" v1
[2024-02-27T13:52:55.748] [debug] [blueprint provider] Loading "minikube" v1
[2024-02-27T13:52:55.748] [debug] [blueprint provider] Loading "ros-noetic" v1
[2024-02-27T13:52:55.748] [debug] [blueprint provider] Loading "ros2-humble" v1
[2024-02-27T13:52:55.752] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket
[2024-02-27T13:52:55.752] [debug] [async task] fetch manifest periodically
[2024-02-27T13:52:55.757] [info] [VMImageHost] Did not find any supported products in "appliance"
[2024-02-27T13:52:55.759] [debug] [qemu-img] [39370] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-27T13:52:56.073] [debug] [qemu-img] [39371] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-27T13:52:56.095] [debug] [qemu-img] [39372] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-27T13:52:56.113] [debug] [qemu-img] [39373] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-27T13:52:56.128] [info] [daemon] Starting Multipass 1.13.1+mac
[2024-02-27T13:52:56.128] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
[2024-02-27T13:52:56.914] [debug] [update] Latest Multipass release available is version 1.13.1
[2024-02-27T13:53:08.765] [debug] [redacted] process working dir ''
[2024-02-27T13:53:08.765] [info] [redacted] process program 'qemu-system-aarch64'
[2024-02-27T13:53:08.765] [info] [redacted] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b, -nic, vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 2048M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso, -loadvm, suspend, -machine, virt-8.0'
[2024-02-27T13:53:08.765] [info] [redacted] Resuming from a suspended state
[2024-02-27T13:53:08.765] [info] [redacted] process state changed to Starting
[2024-02-27T13:53:08.769] [info] [redacted] process state changed to Running
[2024-02-27T13:53:08.769] [debug] [qemu-system-aarch64] [39512] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b -nic vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 2048M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso -loadvm suspend -machine virt-8.0
[2024-02-27T13:53:08.770] [info] [redacted] process started
[2024-02-27T13:53:08.770] [debug] [redacted] Waiting for SSH to be up
[2024-02-27T13:53:10.646] [debug] [redacted] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-27T13:53:12.527] [warning] [redacted] qemu-system-aarch64: Received an unexpected compressed page
qemu-system-aarch64: error while loading state section id 2(ram)

[2024-02-27T13:53:12.527] [warning] [qemu-system-aarch64] 
[2024-02-27T13:53:12.527] [warning] [redacted] qemu-system-aarch64: Error -22 while loading VM state

[2024-02-27T13:53:12.527] [warning] [qemu-system-aarch64] 
[2024-02-27T13:53:12.530] [info] [redacted] process state changed to NotRunning
[2024-02-27T13:53:12.530] [info] [redacted] process finished with exit code 1
[2024-02-27T13:53:29.778] [debug] [redacted] Resetting the network
fish: Job 1, 'sudo /Library/Application\ Supp…' terminated by signal SIGSEGV (Address boundary error)

luisp · February 27, 2024, 1:44pm

Hi @balupton, can you launch a new instance? I would like to know this way if the failure comes from the specific instance you are running. Thanks!

balupton · February 28, 2024, 7:55am

@luisp

> sudo /Library/Application\ Support/com.canonical.multipass/bin/multipassd --verbosity debug
Password:
[2024-02-28T15:47:56.386] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2024-02-28T15:47:56.387] [debug] [blueprint provider] Loading "charm-dev" v1
[2024-02-28T15:47:56.388] [debug] [blueprint provider] Loading "docker" v1
[2024-02-28T15:47:56.388] [debug] [blueprint provider] Loading "jellyfin" v1
[2024-02-28T15:47:56.389] [debug] [blueprint provider] Loading "minikube" v1
[2024-02-28T15:47:56.389] [debug] [blueprint provider] Loading "ros-noetic" v1
[2024-02-28T15:47:56.390] [debug] [blueprint provider] Loading "ros2-humble" v1
[2024-02-28T15:47:56.405] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket
[2024-02-28T15:47:56.405] [debug] [async task] fetch manifest periodically
[2024-02-28T15:47:56.407] [info] [VMImageHost] Did not find any supported products in "appliance"
[2024-02-28T15:47:56.413] [debug] [qemu-img] [87160] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:47:56.782] [debug] [qemu-img] [87161] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:47:56.803] [debug] [qemu-img] [87162] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:47:56.820] [debug] [qemu-img] [87163] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:47:56.833] [info] [daemon] Starting Multipass 1.13.1+mac
[2024-02-28T15:47:56.833] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
[2024-02-28T15:47:57.638] [debug] [update] Latest Multipass release available is version 1.13.1
[2024-02-28T15:49:15.031] [debug] [qemu-system-aarch64] [87415] started: qemu-system-aarch64 --version
[2024-02-28T15:50:31.816] [debug] [image vault] Verifying hash "2e36cc82a9ebb7df3090e4575e66b33ecf12554cced3bcb6349b3eba3a3fc3d6"
[2024-02-28T15:50:36.849] [debug] [qemu-img] [87495] started: qemu-img info --output=json /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20240223/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:50:36.887] [debug] [qemu-img] [87496] started: qemu-img amend -o compat=1.1 /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20240223/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:50:36.901] [debug] [qemu-img] [87497] started: qemu-img info /var/root/Library/Caches/multipassd/qemu/vault/images/jammy-20240223/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:50:36.914] [debug] [qemu-img] [87498] started: qemu-img resize /var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img 5368709120
[2024-02-28T15:50:36.932] [debug] [qemu-img] [87499] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:50:36.944] [debug] [qemu-img] [87500] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:50:36.955] [debug] [ecstatic-springbok] process working dir ''
[2024-02-28T15:50:36.955] [info] [ecstatic-springbok] process program 'qemu-system-aarch64'
[2024-02-28T15:50:36.955] [info] [ecstatic-springbok] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:32:bb:f5, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 1024M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/cloud-init-config.iso'
[2024-02-28T15:50:36.957] [debug] [qemu-system-aarch64] [87501] started: qemu-system-aarch64 -machine virt,gic-version=3 -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.FGlyPg
[2024-02-28T15:50:37.030] [info] [ecstatic-springbok] process state changed to Starting
[2024-02-28T15:50:37.032] [info] [ecstatic-springbok] process state changed to Running
[2024-02-28T15:50:37.032] [debug] [qemu-system-aarch64] [87503] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:32:bb:f5 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 1024M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/cloud-init-config.iso
[2024-02-28T15:50:37.032] [info] [ecstatic-springbok] process started
[2024-02-28T15:50:37.033] [debug] [ecstatic-springbok] Waiting for SSH to be up
[2024-02-28T15:50:37.458] [debug] [ecstatic-springbok] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-28T15:50:37.512] [debug] [ecstatic-springbok] QMP: {"return": {}}

[2024-02-28T15:50:51.650] [debug] [ecstatic-springbok] QMP: {"timestamp": {"seconds": 1709106651, "microseconds": 650665}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[6]/virtio-backend"}}

[2024-02-28T15:50:57.410] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:50:59.412] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:00.498] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:01.597] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:02.662] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:03.727] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:04.792] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:05.865] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:06.964] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:08.042] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:09.119] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:10.184] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:11.258] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:12.339] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:13.416] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:14.478] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:15.553] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:16.622] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:17.681] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:18.748] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:19.817] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:20.895] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:21.971] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:23.033] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:24.089] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:25.144] [debug] [ssh session] Executing '[ -e /var/lib/cloud/instance/boot-finished ]'
[2024-02-28T15:51:27.738] [debug] [ecstatic-springbok] QMP: {"timestamp": {"seconds": 1709106687, "microseconds": 737846}, "event": "RTC_CHANGE", "data": {"offset": 1, "qom-path": "/machine/unattached/device[4]"}}

[2024-02-28T15:52:33.335] [debug] [redacted] process working dir ''
[2024-02-28T15:52:33.335] [info] [redacted] process program 'qemu-system-aarch64'
[2024-02-28T15:52:33.335] [info] [redacted] process arguments '-machine, virt,gic-version=3, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, host, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b, -nic, vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 1, -m, 2048M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso, -loadvm, suspend, -machine, virt-8.0'
[2024-02-28T15:52:33.335] [info] [redacted] Resuming from a suspended state
[2024-02-28T15:52:33.335] [info] [redacted] process state changed to Starting
[2024-02-28T15:52:33.339] [info] [redacted] process state changed to Running
[2024-02-28T15:52:33.340] [debug] [qemu-system-aarch64] [87665] started: qemu-system-aarch64 -machine virt,gic-version=3 -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu host -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a5:a4:8b -nic vmnet-bridged,ifname=en0,model=virtio-net-pci,mac=52:54:00:17:b4:47 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 1 -m 2048M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/redacted/cloud-init-config.iso -loadvm suspend -machine virt-8.0
[2024-02-28T15:52:33.340] [info] [redacted] process started
[2024-02-28T15:52:33.342] [debug] [redacted] Waiting for SSH to be up
[2024-02-28T15:52:33.561] [debug] [redacted] QMP: {"QMP": {"version": {"qemu": {"micro": 1, "minor": 2, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-02-28T15:52:35.407] [warning] [redacted] qemu-system-aarch64: Received an unexpected compressed page
qemu-system-aarch64: error while loading state section id 2(ram)
qemu-system-aarch64: Error -22 while loading VM state

[2024-02-28T15:52:35.407] [warning] [qemu-system-aarch64] 
[2024-02-28T15:52:35.410] [info] [redacted] process state changed to NotRunning
[2024-02-28T15:52:35.410] [info] [redacted] process finished with exit code 1
[2024-02-28T15:52:54.354] [debug] [redacted] Resetting the network
fish: Job 1, 'sudo /Library/Application\ Supp…' terminated by signal SIGSEGV (Address boundary error)

> multipass launch lts
Launched: ecstatic-springbok
15:51:30:balupton@balupton-mini.local:/Users/balupton
>  multipass exec ecstatic-springbok -- lsb_release -a
No LSB modules are available.
Distributor ID:	Ubuntu
Description:	Ubuntu 22.04.4 LTS
Release:	22.04
Codename:	jammy
>  multipass exec redacted -- lsb_release -a
start failed: cannot connect to the multipass socket

> sudo /Library/Application\ Support/com.canonical.multipass/bin/multipassd --verbosity debug
Password:
[2024-02-28T15:55:55.179] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2024-02-28T15:55:55.180] [debug] [blueprint provider] Loading "charm-dev" v1
[2024-02-28T15:55:55.180] [debug] [blueprint provider] Loading "docker" v1
[2024-02-28T15:55:55.181] [debug] [blueprint provider] Loading "jellyfin" v1
[2024-02-28T15:55:55.181] [debug] [blueprint provider] Loading "minikube" v1
[2024-02-28T15:55:55.182] [debug] [blueprint provider] Loading "ros-noetic" v1
[2024-02-28T15:55:55.182] [debug] [blueprint provider] Loading "ros2-humble" v1
[2024-02-28T15:55:55.188] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket
[2024-02-28T15:55:55.188] [debug] [async task] fetch manifest periodically
[2024-02-28T15:55:55.191] [debug] [qemu-img] [87884] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:55:55.192] [info] [VMImageHost] Did not find any supported products in "appliance"
[2024-02-28T15:55:55.219] [debug] [qemu-img] [87885] started: qemu-img amend -o compat=1.1 /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:55:55.234] [debug] [qemu-img] [87886] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img
[2024-02-28T15:55:55.245] [warning] [qemu-img] qemu-img: Could not open '/var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img': Failed to get shared "write" lock
Is another process using the image [/var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img]?

[2024-02-28T15:55:56.093] [debug] [update] Latest Multipass release available is version 1.13.1
[error] [daemon] Caught an unhandled exception: Internal error: qemu-img failed (Process returned exit code: 1) with output:
qemu-img: Could not open '/var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img': Failed to get shared "write" lock
Is another process using the image [/var/root/Library/Application Support/multipassd/qemu/vault/instances/ecstatic-springbok/ubuntu-22.04-server-cloudimg-arm64.img]?

>  multipass exec primary -- lsb_release -a
exec failed: cannot connect to the multipass socket
exec failed: cannot connect to the multipass socket

Any advice on getting the data out of that instance, so I can copy it over to a new one?

luisp · February 29, 2024, 1:26pm

Hi @balupton, yes, there is a way. Please see this comment on a bug report. You’ll need the qemu-nbd utility. The solution provided there runs on Linux, but on macOS the procedure is analogous. To install qemu-nbd, you’ll have to use Homebrew and install the full QEMU: brew install qemu. Let me know if you need help with something. Thanks!

balupton · July 8, 2024, 10:16pm

So any idea why this corruption occurred, and is the source of the corruption fixed? What can I do in the future to mitigate or recover from such corruptions?

shinobicatdude · October 14, 2024, 3:41pm

Hi all, I’m having a similar issue. I’m new to both Multipass and macOS. Here are some of the logs (the ones that looks pertinent)

[2024-10-14T09:36:23.178] [warning] [primary] Could not open option rom ‘kvmvapic.bin’: No such file or directory

[2024-10-14T09:36:23.178] [warning] [qemu-system-x86_64]
[2024-10-14T09:36:23.194] [debug] [primary] QMP: {“return”: {}}

[2024-10-14T09:36:23.477] [debug] [primary] QMP: {“timestamp”: {“seconds”: 1728920183, “microseconds”: 477137}, “event”: “RTC_CHANGE”, “data”: {“offset”: 0, “qom-path”: “/machine/unattached/device[3]/rtc”}}

[2024-10-14T09:36:24.477] [debug] [primary] QMP: {“timestamp”: {“seconds”: 1728920183, “microseconds”: 566456}, “event”: “RTC_CHANGE”, “data”: {“offset”: 0, “qom-path”: “/machine/unattached/device[3]/rtc”}}

[2024-10-14T09:36:33.100] [debug] [primary] QMP: {“timestamp”: {“seconds”: 1728920193, “microseconds”: 100796}, “event”: “NIC_RX_FILTER_CHANGED”, “data”: {“path”: “/machine/unattached/device[21]/virtio-backend”}}

[2024-10-14T09:37:19.434] [debug] [primary] QMP: {“timestamp”: {“seconds”: 1728920239, “microseconds”: 433911}, “event”: “RTC_CHANGE”, “data”: {“offset”: 0, “qom-path”: “/machine/unattached/device[3]/rtc”}}

To my untrained eye, it looks like that kvmvapic.bin might be the problem, but I don’t know what to do with that information.

Oh, a few details I forgot. The image times out as it says. I’ve ben using --timout to limit how long it stews for because it takes about 5 minutes otherwise. After it does this and says it timed out, the image is running, but in an ‘unknown state’. It will continue to be that way until I stop it.

andreitoterman · October 15, 2024, 6:41pm

Hey, @shinobicatdude! What version of macOS and Multipass are you using?