search

canonical / multipass

Multipass orchestrates virtual Ubuntu instances
https://multipass.run
GNU General Public License v3.0
7.86k stars 650 forks source link

Multipass VM gets stuck in Unknown or Suspended state #3361

Open asdf072 opened 10 months ago

asdf072 commented 10 months ago

Describe the bug After leaving a multipass VM running for a few days, I tried to shut it down, but the MacOS shell would timeout trying to communicate with the daemon. I can communicate with Multipass (version,list), but multipass start and multipass stop timeout without any effect.

I've tried reinstalling multipass, but that didn't work

To Reproduce How, and what happened?

  1. Start host machine with Canonical Group checked as a Login Item
  2. Tilebar widget works, but stuck in Unknown state
  3. Tried a suggested fix of killing the process, but that leaves the process in Suspended state

Expected behavior Normal

Logs Log chunk from /Library/Logs/Multipass/multipassd.log

[2024-01-08T17:07:25.884] [warning] [Qt] Empty filename passed to function
[2024-01-08T17:07:26.874] [debug] [update] Latest Multipass release available is version 1.12.2
[2024-01-08T17:07:27.218] [info] [VMImageHost] Did not find any supported products in "appliance"
[2024-01-08T17:07:27.224] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2024-01-08T17:07:27.225] [debug] [blueprint provider] Loading "charm-dev" v1
[2024-01-08T17:07:27.226] [debug] [blueprint provider] Loading "docker" v1
[2024-01-08T17:07:27.226] [debug] [blueprint provider] Loading "jellyfin" v1
[2024-01-08T17:07:27.227] [debug] [blueprint provider] Loading "minikube" v1
[2024-01-08T17:07:27.227] [debug] [blueprint provider] Loading "ros-noetic" v1
[2024-01-08T17:07:27.228] [debug] [blueprint provider] Loading "ros2-humble" v1
[2024-01-08T17:07:27.243] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket
[2024-01-08T17:07:27.252] [debug] [qemu-img] [1568] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/ubuntu-22.04-server-cloudimg-arm64.img
[2024-01-08T17:07:27.275] [info] [daemon] Starting Multipass 1.12.2+mac
[2024-01-08T17:07:27.275] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
[2024-01-08T17:07:36.207] [info] [daemon] Received signal 15 (Terminated: 15)
[2024-01-08T17:07:36.208] [info] [daemon] Goodbye!
[2024-01-08T17:08:26.396] [warning] [Qt] Empty filename passed to function
[2024-01-08T17:08:26.725] [warning] [url downloader] Error getting https://multipass.run/static/latest-release.json: Host multipass.run not found - trying cache.
[2024-01-08T17:08:26.725] [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-01-08T17:08:26.730] [warning] [url downloader] Error getting https://cloud-images.ubuntu.com/releases/streams/v1/index.json: Host cloud-images.ubuntu.com not found - trying cache.
[2024-01-08T17:08:27.196] [warning] [url downloader] Error getting https://cloud-images.ubuntu.com/buildd/daily/streams/v1/index.json: Host cloud-images.ubuntu.com not found - trying cache.
[2024-01-08T17:08:29.511] [info] [VMImageHost] Did not find any supported products in "appliance"
[2024-01-08T17:08:29.511] [warning] [url downloader] Error getting https://codeload.github.com/canonical/multipass-blueprints/zip/refs/heads/main: Host codeload.github.com not found - trying cache.
[2024-01-08T17:08:29.516] [debug] [blueprint provider] Loading "anbox-cloud-appliance" v1
[2024-01-08T17:08:29.517] [debug] [blueprint provider] Loading "charm-dev" v1
[2024-01-08T17:08:29.518] [debug] [blueprint provider] Loading "docker" v1
[2024-01-08T17:08:29.518] [debug] [blueprint provider] Loading "jellyfin" v1
[2024-01-08T17:08:29.518] [debug] [blueprint provider] Loading "minikube" v1
[2024-01-08T17:08:29.518] [debug] [blueprint provider] Loading "ros-noetic" v1
[2024-01-08T17:08:29.518] [debug] [blueprint provider] Loading "ros2-humble" v1
[2024-01-08T17:08:29.523] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket
[2024-01-08T17:08:29.771] [debug] [qemu-img] [783] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/ubuntu-22.04-server-cloudimg-arm64.img
[2024-01-08T17:08:30.184] [info] [daemon] Starting Multipass 1.12.2+mac
[2024-01-08T17:08:30.184] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug
[2024-01-08T17:08:35.165] [debug] [ubuntu-lts] process working dir ''
[2024-01-08T17:08:35.165] [info] [ubuntu-lts] process program 'qemu-system-aarch64'
[2024-01-08T17:08:35.165] [info] [ubuntu-lts] 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:0f:71:a2, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda, -device, scsi-hd,drive=hda,bus=scsi0.0, -smp, 4, -m, 4096M, -qmp, stdio, -chardev, null,id=char0, -serial, chardev:char0, -nographic, -cdrom, /var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/cloud-init-config.iso, -loadvm, suspend, -machine, virt-8.0'
[2024-01-08T17:08:35.165] [info] [ubuntu-lts] Resuming from a suspended state
[2024-01-08T17:08:35.165] [info] [ubuntu-lts] process state changed to Starting
[2024-01-08T17:08:35.192] [info] [ubuntu-lts] process state changed to Running
[2024-01-08T17:08:35.192] [debug] [qemu-system-aarch64] [832] 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:0f:71:a2 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 4 -m 4096M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/cloud-init-config.iso -loadvm suspend -machine virt-8.0
[2024-01-08T17:08:35.192] [info] [ubuntu-lts] process started
[2024-01-08T17:08:35.212] [debug] [ubuntu-lts] Waiting for SSH to be up
[2024-01-08T17:08:35.766] [debug] [ubuntu-lts] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 0, "major": 8}, "package": ""}, "capabilities": ["oob"]}}

[2024-01-08T17:08:37.443] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:08:41.460] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:08:41.462] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:08:41.470] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:09:11.992] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:09:11.994] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:09:11.994] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:09:42.668] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:09:42.671] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:09:42.673] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:10:12.876] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:10:12.878] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:10:12.880] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:10:43.469] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:10:43.480] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:10:43.504] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:11:14.789] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:11:14.791] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:11:14.793] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:11:45.465] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:11:45.467] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:11:45.468] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:12:16.011] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:12:16.014] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:12:16.017] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:12:46.519] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:12:46.520] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:12:46.521] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:13:17.090] [debug] [ubuntu-lts] Resetting the network
[2024-01-08T17:13:17.092] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:13:17.094] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:31:29.127] [info] [daemon] Cannot open ssh session on "ubuntu-lts" shutdown: ssh connection failed: 'Timeout connecting to 192.168.64.4'
[2024-01-08T17:31:29.131] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-08T17:31:29.131] [debug] [ubuntu-lts] QMP: {"timestamp": {"seconds": 1704753089, "microseconds": 131376}, "event": "POWERDOWN"}

[2024-01-08T17:31:29.131] [info] [ubuntu-lts] VM powering down
[2024-01-08T23:52:36.901] [debug] [image vault] Checking for images to update…
[2024-01-09T10:27:26.623] [info] [daemon] Received signal 15 (Terminated: 15)
[2024-01-09T10:27:26.624] [info] [daemon] Goodbye!
[2024-01-09T10:27:26.776] [debug] [ubuntu-lts] QMP: {"return": {}}

[2024-01-09T10:27:26.776] [debug] [ubuntu-lts] QMP: {"timestamp": {"seconds": 1704814046, "microseconds": 775969}, "event": "POWERDOWN"}

[2024-01-09T10:27:26.776] [info] [ubuntu-lts] VM powering down

PLIST /Library/LaunchDaemons/com.canonical.multipassd.plist

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
    <key>Label</key>
    <string>com.canonical.multipassd</string>

    <key>EnvironmentVariables</key>
    <dict>
      <key>PATH</key>
      <string>/Library/Application Support/com.canonical.multipass/bin:/usr/bin:/bin:/usr/sbin:/sbin</string>
    </dict>

    <key>ProgramArguments</key>
    <array>
      <string>/Library/Application Support/com.canonical.multipass/bin/multipassd</string>
      <string>--verbosity</string>
      <string>debug</string>
    </array>

    <key>KeepAlive</key>
    <true/>

    <key>Sockets</key>
    <dict>
       <key>Listeners</key>
       <dict>
            <key>SockServiceName</key>
            <string>50051</string>
            <key>SockType</key>
            <string>stream</string>
        </dict>
    </dict>

    <key>StandardOutPath</key>
    <string>/Library/Logs/Multipass/multipassd.log</string>
    <key>StandardErrorPath</key>
    <string>/Library/Logs/Multipass/multipassd.log</string>
</dict>

</plist>

Additional info

ricab commented 10 months ago

Hi @asdf072, I suspect one of three things:

  1. the memory snapshot for the suspended state got corrupted, preventing the instance from resuming successfully
  2. the image itself got corrupted
  3. duplicate/stale entries in dhcpd_leases confusing bootp and preventing the instance from getting an IP (which is necessary for the start transition to finish)

Without more info, I think 3 is more likely, especially now that you say you also observe the instance in an unknown state. There is one message I would expect to see in the logs, but maybe you posted only selected parts? Also, it is weird that stop would timeout too, but maybe the daemon later got confused with concurrent/repeated start/stop requests.

Could you please try the steps I outlined here and let us know if they work for you?

asdf072 commented 10 months ago

I managed to get it stopped temporarily! I stopped the qemu process, reloaded the plist, and the state finally said "Stopped", but then I restarted and I'm back to suspended state.

There are two unrelated dhcpd_releases entries that have that same name, different identifiers. These are from an old VirtualBox install. The one I want (ubuntu-lts) looks fine.

{
    name=secured-tinamou
    ip_address=192.168.64.6
    hw_address=1,52:54:0:6a:a1:de
    identifier=1,52:54:0:6a:a1:de
    lease=0x659dfb25
}
{
    name=excellent-ladybeetle
    ip_address=192.168.64.5
    hw_address=1,52:54:0:2e:f5:1f
    identifier=1,52:54:0:2e:f5:1f
    lease=0x64192600
}
{
    name=ubuntu-lts
    ip_address=192.168.64.4
    hw_address=1,52:54:0:f:71:a2
    identifier=1,52:54:0:f:71:a2
    lease=0x659c245b
}
{
    name=ubuntu
    ip_address=192.168.64.3
    hw_address=1,5a:a5:ea:f9:fc:c
    identifier=1,5a:a5:ea:f9:fc:c
    lease=0x64189690
}
{
    name=ubuntu
    ip_address=192.168.64.2
    hw_address=1,2:83:bb:e1:18:fc
    identifier=1,2:83:bb:e1:18:fc
    lease=0x63852e7f
}

Here's the qemu command running

 1035   ??  S      0:01.52 /Library/Application Support/com.canonical.multipass/bin/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:0f:71:a2 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/ubuntu-22.04-server-cloudimg-arm64.img,if=none,format=qcow2,discard=unmap,id=hda -device scsi-hd,drive=hda,bus=scsi0.0 -smp 4 -m 4096M -qmp stdio -chardev null,id=char0 -serial chardev:char0 -nographic -cdrom /var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/cloud-init-config.iso -loadvm suspend -machine virt-8.0

It's probably nothing, but interesting flag of -loavdvm suspend at the end.

ricab commented 10 months ago

Hmm, perhaps that suspension snapshot is in a bad state. Here's something you can try:

  1. multipass stop ubuntu-lts or kill the qemu process if that doesn't work
  2. sudo launchctl unload /Library/LaunchDaemons/com.canonical.multipassd.plist
  3. sudo /Library/Application\ Support/com.canonical.multipass/bin/qemu-img snapshot -d suspend "/var/root/Library/Application Support/multipassd/qemu/vault/instances/ubuntu-lts/ubuntu-22.04-server-cloudimg-arm64.img"
  4. clean up dhcpd_leases for good measure: remove at least the existing lease for ubuntu-lts and the first entry for ubuntu (whose mac address has a wrong format and who knows if that could trip up bootp's parser)
  5. sudo launchctl load /Library/LaunchDaemons/com.canonical.multipassd.plist
  6. multipass start ubuntu-lts
nilnullzip commented 10 months ago

I have encountered similar problem. I am running macOS Sonoma 14.2.1 on x86 MBP. I updated to the latest multipass 1.13.0+mac using the package downloaded from multipass.run. I had an instance running at the time I upgraded. When I tried to stop it after the upgrade, it would not stop so I force killed the qemu process with activity monitor. Now the instance is in a suspended state and does not respond to start or stop. I found three qemu processes, I gather one for each time I tried to start the instance. The current situation after force killing all qemu processes:

% multipass start foo
start failed: cannot connect to the multipass socket
% sudo ls -l /var/root/Library/Application\ Support/multipassd/qemu/vault/instances/dexorder/ubuntu-22.04-server-cloudimg-amd64.img           
-rw-r--r--  1 root  wheel  29970661376 Jan 16 08:18 /var/root/Library/Application Support/multipassd/qemu/vault/instances/dexorder/ubuntu-22.04-server-cloudimg-amd64.img

Watching on activity monitor I saw qemu start and then quit. Should I just try deleting the snapshot as suggested above?

ricab commented 9 months ago

Hi @nilnullzip, killing the instance may have left it in a bad state, but your case looks like a different situation where not even the daemon is running. Could you please open a new issue, filling the form and uploading logs? Thank you.

kingsleyukr commented 9 months ago

Hi @ricab I got a similar issue (suspended -- unknown) after upgrading my macOS yesterday. Problem is, how can I get my files already in the primary instance. Please is there any possible fix?

Thanks in an anticipation of your response

townsend2010 commented 9 months ago

Hi @kingsleyukr!

Could you please provide logs that capture the time of the upgrade? This will help us better diagnose the issue. Thank you!

kingsleyukr commented 9 months ago

Here are the logs from yesterday: @townsend2010

[2024-02-08T20:53:33.827] [debug] [update] Latest Multipass release available is version 1.13.0 [2024-02-08T20:53:33.965] [info] [update] A New Multipass release is available: 1.13.0 [2024-02-08T20:53:35.319] [info] [VMImageHost] Did not find any supported products in "appliance" [2024-02-08T20:53:35.480] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket [2024-02-08T20:53:35.502] [debug] [qemu-img] [980] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-08T20:53:36.400] [info] [daemon] primary needs starting. Starting now... [2024-02-08T20:53:36.400] [debug] [primary] process working dir '' [2024-02-08T20:53:36.400] [info] [primary] process program 'qemu-system-aarch64' [2024-02-08T20:53:36.400] [info] [primary] process arguments '-machine, virt,highmem=off, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, cortex-a72, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso, -loadvm, suspend, -machine, virt-7.1' [2024-02-08T20:53:36.401] [info] [primary] Resuming from a suspended state [2024-02-08T20:53:36.401] [info] [primary] process state changed to Starting [2024-02-08T20:53:36.414] [info] [primary] process state changed to Running [2024-02-08T20:53:36.414] [debug] [qemu-system-aarch64] [1002] started: qemu-system-aarch64 -machine virt,highmem=off -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu cortex-a72 -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso -loadvm suspend -machine virt-7.1 [2024-02-08T20:53:36.414] [info] [primary] process started [2024-02-08T20:53:36.418] [debug] [primary] Waiting for SSH to be up [2024-02-08T20:53:36.418] [info] [daemon] Starting Multipass 1.11.1+mac [2024-02-08T20:53:36.418] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug [2024-02-08T20:53:38.258] [debug] [primary] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 1, "major": 7}, "package": ""}, "capabilities": ["oob"]}} [2024-02-08T20:53:42.766] [debug] [primary] Resetting the network [2024-02-08T20:54:14.290] [debug] [primary] Resetting the network [2024-02-08T20:54:30.152] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:54:30.404] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:54:44.061] [debug] [primary] Resetting the network [2024-02-08T20:54:46.429] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:54:47.558] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:55:14.133] [debug] [primary] Resetting the network [2024-02-08T20:55:15.055] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:55:15.079] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:55:44.788] [debug] [primary] Resetting the network [2024-02-08T20:55:45.620] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:55:45.643] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:55:52.821] [debug] [primary] QMP: {"timestamp": {"seconds": 1707422152, "microseconds": 815625}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[6]/virtio-backend"}} [2024-02-08T20:55:55.664] [debug] [primary] QMP: {"timestamp": {"seconds": 1707422155, "microseconds": 626120}, "event": "RTC_CHANGE", "data": {"offset": 0, "qom-path": "/machine/unattached/device[4]"}} [2024-02-08T20:56:16.261] [debug] [primary] Resetting the network [2024-02-08T20:56:16.314] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:56:16.315] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:56:47.603] [debug] [primary] Resetting the network [2024-02-08T20:56:47.619] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:56:47.634] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:57:18.705] [debug] [primary] Resetting the network [2024-02-08T20:57:18.709] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:57:18.712] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:57:49.594] [debug] [primary] Resetting the network [2024-02-08T20:57:49.606] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:57:49.607] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:58:20.609] [debug] [primary] Resetting the network [2024-02-08T20:58:20.620] [debug] [primary] QMP: {"return": {}} [2024-02-08T20:58:20.621] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:05:48.258] [info] [daemon] Cannot open ssh session on "primary" shutdown: ssh connection failed: 'Timeout connecting to 192.168.64.2' [2024-02-08T21:05:48.268] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:05:48.268] [debug] [primary] QMP: {"timestamp": {"seconds": 1707422748, "microseconds": 268573}, "event": "POWERDOWN"} [2024-02-08T21:05:48.269] [info] [primary] VM powering down [2024-02-08T21:05:53.447] [debug] [primary] QMP: {"timestamp": {"seconds": 1707422753, "microseconds": 446939}, "event": "SHUTDOWN", "data": {"guest": true, "reason": "guest-shutdown"}} [2024-02-08T21:05:53.447] [info] [primary] VM shut down [2024-02-08T21:05:53.649] [info] [primary] process state changed to NotRunning [2024-02-08T21:05:53.650] [info] [primary] process finished with exit code 0 [2024-02-08T21:07:21.949] [debug] [primary] process working dir '' [2024-02-08T21:07:21.949] [info] [primary] process program 'qemu-system-aarch64' [2024-02-08T21:07:21.949] [info] [primary] process arguments '-machine, virt,highmem=off, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, cortex-a72, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso' [2024-02-08T21:07:21.954] [debug] [qemu-system-aarch64] [9357] started: qemu-system-aarch64 -machine virt,highmem=off -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.ewEJqd [2024-02-08T21:07:22.116] [info] [primary] process state changed to Starting [2024-02-08T21:07:22.119] [info] [primary] process state changed to Running [2024-02-08T21:07:22.119] [debug] [qemu-system-aarch64] [9358] started: qemu-system-aarch64 -machine virt,highmem=off -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu cortex-a72 -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso [2024-02-08T21:07:22.119] [info] [primary] process started [2024-02-08T21:07:22.119] [debug] [primary] Waiting for SSH to be up [2024-02-08T21:07:22.119] [debug] [primary] Resetting the network [2024-02-08T21:07:22.453] [debug] [primary] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 1, "major": 7}, "package": ""}, "capabilities": ["oob"]}} [2024-02-08T21:07:22.504] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:07:22.506] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:07:22.507] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:07:34.064] [debug] [primary] QMP: {"timestamp": {"seconds": 1707422854, "microseconds": 64282}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[6]/virtio-backend"}} [2024-02-08T21:07:52.026] [debug] [primary] QMP: {"timestamp": {"seconds": 1707422872, "microseconds": 25289}, "event": "RTC_CHANGE", "data": {"offset": 0, "qom-path": "/machine/unattached/device[4]"}} [2024-02-08T21:07:52.330] [debug] [primary] Resetting the network [2024-02-08T21:07:52.333] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:07:52.335] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:08:23.335] [debug] [primary] Resetting the network [2024-02-08T21:08:23.339] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:08:23.341] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:08:54.320] [debug] [primary] Resetting the network [2024-02-08T21:08:54.323] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:08:54.325] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:09:25.331] [debug] [primary] Resetting the network [2024-02-08T21:09:25.335] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:09:25.338] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:09:56.289] [debug] [primary] Resetting the network [2024-02-08T21:09:56.293] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:09:56.295] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:10:27.325] [debug] [primary] Resetting the network [2024-02-08T21:10:27.329] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:10:27.331] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:10:58.319] [debug] [primary] Resetting the network [2024-02-08T21:10:58.325] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:10:58.327] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:11:29.373] [debug] [primary] Resetting the network [2024-02-08T21:11:29.377] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:11:29.379] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:12:00.402] [debug] [primary] Resetting the network [2024-02-08T21:12:00.406] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:12:00.408] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:14:25.677] [info] [daemon] Cannot open ssh session on "primary" shutdown: ssh connection failed: 'Timeout connecting to 192.168.64.2' [2024-02-08T21:14:25.685] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:14:25.685] [debug] [primary] QMP: {"timestamp": {"seconds": 1707423265, "microseconds": 685433}, "event": "POWERDOWN"} [2024-02-08T21:14:25.685] [info] [primary] VM powering down [2024-02-08T21:14:29.460] [debug] [primary] QMP: {"timestamp": {"seconds": 1707423269, "microseconds": 460824}, "event": "SHUTDOWN", "data": {"guest": true, "reason": "guest-shutdown"}} [2024-02-08T21:14:29.460] [info] [primary] VM shut down [2024-02-08T21:14:29.661] [info] [primary] process state changed to NotRunning [2024-02-08T21:14:29.661] [info] [primary] process finished with exit code 0 [2024-02-08T21:16:45.942] [debug] [primary] process working dir '' [2024-02-08T21:16:45.942] [info] [primary] process program 'qemu-system-aarch64' [2024-02-08T21:16:45.942] [info] [primary] process arguments '-machine, virt,highmem=off, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, cortex-a72, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso' [2024-02-08T21:16:45.946] [debug] [qemu-system-aarch64] [15601] started: qemu-system-aarch64 -machine virt,highmem=off -nographic -dump-vmstate /private/var/folders/zz/zyxvpxvq6csfxvn_n0000000000000/T/multipassd.DMTqqU [2024-02-08T21:16:46.103] [info] [primary] process state changed to Starting [2024-02-08T21:16:46.106] [info] [primary] process state changed to Running [2024-02-08T21:16:46.106] [debug] [qemu-system-aarch64] [15602] started: qemu-system-aarch64 -machine virt,highmem=off -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu cortex-a72 -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso [2024-02-08T21:16:46.106] [info] [primary] process started [2024-02-08T21:16:46.106] [debug] [primary] Waiting for SSH to be up [2024-02-08T21:16:46.106] [debug] [primary] Resetting the network [2024-02-08T21:16:46.473] [debug] [primary] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 1, "major": 7}, "package": ""}, "capabilities": ["oob"]}} [2024-02-08T21:16:46.521] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:16:46.522] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:16:46.523] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:16:56.786] [debug] [primary] QMP: {"timestamp": {"seconds": 1707423416, "microseconds": 786308}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[6]/virtio-backend"}} [2024-02-08T21:17:13.030] [debug] [primary] QMP: {"timestamp": {"seconds": 1707423433, "microseconds": 28797}, "event": "RTC_CHANGE", "data": {"offset": 0, "qom-path": "/machine/unattached/device[4]"}} [2024-02-08T21:17:17.335] [debug] [primary] Resetting the network [2024-02-08T21:17:17.338] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:17:17.340] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:17:48.250] [debug] [primary] Resetting the network [2024-02-08T21:17:48.254] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:17:48.257] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:18:19.293] [debug] [primary] Resetting the network [2024-02-08T21:18:19.295] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:18:19.296] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:18:50.203] [debug] [primary] Resetting the network [2024-02-08T21:18:50.205] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:18:50.208] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:19:21.119] [debug] [primary] Resetting the network [2024-02-08T21:19:21.123] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:19:21.125] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:19:52.088] [debug] [primary] Resetting the network [2024-02-08T21:19:52.094] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:19:52.095] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:20:23.195] [debug] [primary] Resetting the network [2024-02-08T21:20:23.198] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:20:23.199] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:20:54.214] [debug] [primary] Resetting the network [2024-02-08T21:20:54.216] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:20:54.217] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:21:25.297] [debug] [primary] Resetting the network [2024-02-08T21:21:25.307] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:21:25.309] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:22:04.366] [info] [daemon] Received signal 15 (Terminated: 15) [2024-02-08T21:22:04.368] [info] [daemon] Goodbye! [2024-02-08T21:22:04.377] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:22:04.378] [debug] [primary] QMP: {"timestamp": {"seconds": 1707423724, "microseconds": 378212}, "event": "POWERDOWN"} [2024-02-08T21:22:04.378] [info] [primary] VM powering down [2024-02-08T21:23:25.287] [debug] [update] Latest Multipass release available is version 1.13.0 [2024-02-08T21:23:29.898] [info] [update] A New Multipass release is available: 1.13.0 [2024-02-08T21:23:32.970] [info] [VMImageHost] Did not find any supported products in "appliance" [2024-02-08T21:23:33.842] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket [2024-02-08T21:23:34.382] [debug] [qemu-img] [1177] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-08T21:23:35.804] [info] [daemon] Starting Multipass 1.11.1+mac [2024-02-08T21:23:35.804] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug [2024-02-08T21:24:02.120] [debug] [primary] process working dir '' [2024-02-08T21:24:02.120] [info] [primary] process program 'qemu-system-aarch64' [2024-02-08T21:24:02.121] [info] [primary] process arguments '-machine, virt,highmem=off, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, cortex-a72, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso, -loadvm, suspend, -machine, virt-7.1' [2024-02-08T21:24:02.121] [info] [primary] Resuming from a suspended state [2024-02-08T21:24:02.122] [info] [primary] process state changed to Starting [2024-02-08T21:24:02.151] [info] [primary] process state changed to Running [2024-02-08T21:24:02.151] [debug] [qemu-system-aarch64] [1777] started: qemu-system-aarch64 -machine virt,highmem=off -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu cortex-a72 -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso -loadvm suspend -machine virt-7.1 [2024-02-08T21:24:02.151] [info] [primary] process started [2024-02-08T21:24:02.161] [debug] [primary] Waiting for SSH to be up [2024-02-08T21:24:03.700] [debug] [primary] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 1, "major": 7}, "package": ""}, "capabilities": ["oob"]}} [2024-02-08T21:24:06.925] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:24:08.385] [debug] [primary] Resetting the network [2024-02-08T21:24:08.419] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:24:08.420] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:24:08.540] [debug] [primary] QMP: {"timestamp": {"seconds": 1707423848, "microseconds": 540226}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[6]/virtio-backend"}} [2024-02-08T21:24:39.499] [debug] [primary] Resetting the network [2024-02-08T21:24:39.508] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:24:39.510] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:24:41.109] [debug] [primary] QMP: {"timestamp": {"seconds": 1707423881, "microseconds": 108576}, "event": "RTC_CHANGE", "data": {"offset": 0, "qom-path": "/machine/unattached/device[4]"}} [2024-02-08T21:25:10.556] [debug] [primary] Resetting the network [2024-02-08T21:25:10.557] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:25:10.558] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:25:41.442] [debug] [primary] Resetting the network [2024-02-08T21:25:41.446] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:25:41.448] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:26:12.268] [debug] [primary] Resetting the network [2024-02-08T21:26:12.271] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:26:12.273] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:26:43.109] [debug] [primary] Resetting the network [2024-02-08T21:26:43.112] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:26:43.114] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:27:13.983] [debug] [primary] Resetting the network [2024-02-08T21:27:13.986] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:27:13.988] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:27:44.939] [debug] [primary] Resetting the network [2024-02-08T21:27:44.942] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:27:44.944] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:28:15.745] [debug] [primary] Resetting the network [2024-02-08T21:28:15.749] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:28:15.752] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:28:46.596] [debug] [primary] Resetting the network [2024-02-08T21:28:46.605] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:28:46.606] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:35:11.369] [warning] [daemon] Instance 'primary' is already running, but in an unknown state [2024-02-08T21:35:11.369] [debug] [primary] Waiting for SSH to be up [2024-02-08T21:35:11.370] [debug] [primary] Resetting the network [2024-02-08T21:35:11.380] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:35:11.380] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:35:38.986] [debug] [primary] QMP: {"timestamp": {"seconds": 1707424538, "microseconds": 985142}, "event": "RTC_CHANGE", "data": {"offset": 1, "qom-path": "/machine/unattached/device[4]"}} [2024-02-08T21:35:42.334] [debug] [primary] Resetting the network [2024-02-08T21:35:42.337] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:35:42.340] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:36:13.220] [debug] [primary] Resetting the network [2024-02-08T21:36:13.229] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:36:13.231] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:36:44.243] [debug] [primary] Resetting the network [2024-02-08T21:36:44.245] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:36:44.247] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:37:01.675] [debug] [update] Latest Multipass release available is version 1.13.0 [2024-02-08T21:37:01.696] [info] [update] A New Multipass release is available: 1.13.0 [2024-02-08T21:37:01.697] [info] [VMImageHost] Did not find any supported products in "appliance" [2024-02-08T21:37:01.711] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket [2024-02-08T21:37:01.719] [debug] [qemu-img] [11933] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-08T21:37:01.889] [info] [daemon] Starting Multipass 1.11.1+mac [2024-02-08T21:37:01.889] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug [2024-02-08T21:37:06.700] [info] [daemon] Received signal 15 (Terminated: 15) [2024-02-08T21:37:06.701] [info] [daemon] Goodbye! [2024-02-08T21:37:12.185] [debug] [update] Latest Multipass release available is version 1.13.0 [2024-02-08T21:37:12.243] [info] [update] A New Multipass release is available: 1.13.0 [2024-02-08T21:37:12.246] [info] [VMImageHost] Did not find any supported products in "appliance" [2024-02-08T21:37:12.262] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket [2024-02-08T21:37:12.264] [debug] [qemu-img] [12169] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-08T21:37:12.269] [info] [daemon] Starting Multipass 1.11.1+mac [2024-02-08T21:37:12.269] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug [2024-02-08T21:37:18.971] [info] [daemon] Received signal 15 (Terminated: 15) [2024-02-08T21:37:18.972] [info] [daemon] Goodbye! [2024-02-08T21:37:22.241] [info] [VMImageHost] Did not find any supported products in "appliance" [2024-02-08T21:37:22.401] [debug] [update] Latest Multipass release available is version 1.13.0 [2024-02-08T21:37:22.401] [info] [update] A New Multipass release is available: 1.13.0 [2024-02-08T21:37:22.464] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket [2024-02-08T21:37:22.467] [debug] [qemu-img] [12301] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-08T21:37:22.472] [info] [daemon] Starting Multipass 1.11.1+mac [2024-02-08T21:37:22.472] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug [2024-02-08T21:42:27.898] [debug] [primary] process working dir '' [2024-02-08T21:42:27.898] [info] [primary] process program 'qemu-system-aarch64' [2024-02-08T21:42:27.898] [info] [primary] process arguments '-machine, virt,highmem=off, -accel, hvf, -drive, file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on, -cpu, cortex-a72, -nic, vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2, -device, virtio-scsi-pci,id=scsi0, -drive, file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso, -loadvm, suspend, -machine, virt-7.1' [2024-02-08T21:42:27.899] [info] [primary] Resuming from a suspended state [2024-02-08T21:42:27.899] [info] [primary] process state changed to Starting [2024-02-08T21:42:27.902] [info] [primary] process state changed to Running [2024-02-08T21:42:27.902] [debug] [qemu-system-aarch64] [16121] started: qemu-system-aarch64 -machine virt,highmem=off -accel hvf -drive file=/Library/Application Support/com.canonical.multipass/bin/../Resources/qemu/edk2-aarch64-code.fd,if=pflash,format=raw,readonly=on -cpu cortex-a72 -nic vmnet-shared,model=virtio-net-pci,mac=52:54:00:a0:25:f2 -device virtio-scsi-pci,id=scsi0 -drive file=/var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/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/primary/cloud-init-config.iso -loadvm suspend -machine virt-7.1 [2024-02-08T21:42:27.902] [info] [primary] process started [2024-02-08T21:42:27.904] [debug] [primary] Waiting for SSH to be up [2024-02-08T21:42:28.038] [debug] [primary] QMP: {"QMP": {"version": {"qemu": {"micro": 0, "minor": 1, "major": 7}, "package": ""}, "capabilities": ["oob"]}} [2024-02-08T21:42:30.885] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:42:34.068] [debug] [primary] Resetting the network [2024-02-08T21:42:34.070] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:42:34.072] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:42:34.088] [debug] [primary] QMP: {"timestamp": {"seconds": 1707424954, "microseconds": 88707}, "event": "NIC_RX_FILTER_CHANGED", "data": {"path": "/machine/unattached/device[6]/virtio-backend"}} [2024-02-08T21:42:39.992] [debug] [primary] QMP: {"timestamp": {"seconds": 1707424959, "microseconds": 992163}, "event": "RTC_CHANGE", "data": {"offset": 1, "qom-path": "/machine/unattached/device[4]"}} [2024-02-08T21:43:05.107] [debug] [primary] Resetting the network [2024-02-08T21:43:05.111] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:43:05.113] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:43:36.016] [debug] [primary] Resetting the network [2024-02-08T21:43:36.018] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:43:36.019] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:44:06.944] [debug] [primary] Resetting the network [2024-02-08T21:44:06.947] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:44:06.949] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:44:38.016] [debug] [primary] Resetting the network [2024-02-08T21:44:38.020] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:44:38.022] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:45:08.926] [debug] [primary] Resetting the network [2024-02-08T21:45:08.930] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:45:08.932] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:45:39.923] [debug] [primary] Resetting the network [2024-02-08T21:45:39.926] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:45:39.928] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:46:10.729] [debug] [primary] Resetting the network [2024-02-08T21:46:10.732] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:46:10.734] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:46:41.779] [debug] [primary] Resetting the network [2024-02-08T21:46:41.782] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:46:41.784] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:47:13.184] [debug] [primary] Resetting the network [2024-02-08T21:47:13.188] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:47:13.191] [debug] [primary] QMP: {"return": {}} [2024-02-08T21:49:05.655] [debug] [update] Latest Multipass release available is version 1.13.0 [2024-02-08T21:49:05.691] [info] [update] A New Multipass release is available: 1.13.0 [2024-02-08T21:49:05.691] [info] [VMImageHost] Did not find any supported products in "appliance" [2024-02-08T21:49:05.746] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket [2024-02-08T21:49:05.752] [debug] [qemu-img] [20667] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-08T21:49:05.913] [info] [daemon] Starting Multipass 1.11.1+mac [2024-02-08T21:49:05.913] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug [2024-02-08T21:49:36.244] [info] [VMImageHost] Did not find any supported products in "appliance" [2024-02-08T21:49:36.382] [debug] [update] Latest Multipass release available is version 1.13.0 [2024-02-08T21:49:36.382] [info] [update] A New Multipass release is available: 1.13.0 [2024-02-08T21:49:36.477] [info] [rpc] gRPC listening on unix:/var/run/multipass_socket [2024-02-08T21:49:36.480] [debug] [qemu-img] [21061] started: qemu-img snapshot -l /var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img [2024-02-08T21:49:36.495] [info] [daemon] Starting Multipass 1.11.1+mac [2024-02-08T21:49:36.495] [info] [daemon] Daemon arguments: /Library/Application Support/com.canonical.multipass/bin/multipassd --verbosity debug

townsend2010 commented 9 months ago

Hi @kingsleyukr,

It doesn't look like the logs go back for enough to tell what may have happened when the primary instance was suspended during the macOS update. That said, the network interface is not coming online in the instance which indicates it's not booting for some reason. I can only suggest doing the following in hopes that it will fix whatever has broken the image:

$ sudo launchctl unload /Library/LaunchDaemons/com.canonical.multipassd.plist
$ sudo sudo /Library/Application\ Support/com.canonical.multipass/bin/qemu-img check -r all var/root/Library/Application\ Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
$ sudo launchctl load /Library/LaunchDaemons/com.canonical.multipassd.plist
kingsleyukr commented 9 months ago

Hi @townsend2010 The issue started from yesterday night that was why I only sent the logs from that day. Thanks for the feedback. When I ran the commands I get this error, is that for windows?

qemu-img: Could not open 'var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img': Could not open 'var/root/Library/Application Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img': No such file or directory

cannot connect to the multipass socket

townsend2010 commented 9 months ago

Oops, I left off a leading /. It should be:

$ sudo /Library/Application\ Support/com.canonical.multipass/bin/qemu-img check -r all /var/root/Library/Application\ Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
kingsleyukr commented 9 months ago

Thanks @townsend2010 I got these afterwards

8539 errors were found on the image. Data may be corrupted, or further writes to the image may corrupt it. 84351/81920 = 102.97% allocated, 21.56% fragmented, 8.36% compressed clusters Image end offset: 6442516480

Also, running multipass list ===> cannot connect to the multipass socket

townsend2010 commented 9 months ago

Hi @kingsleyukr,

Unfortunately, it appears the image is corrupted and there is nothing that can be done about this at this point. If possible, I would really like to see your logs prior to the logs you sent previously. This may help diagnose why this occurred so we can try to fix it. I also think macOS may be playing into this. My reasoning is if an instance is being suspended and there is a fair amount of memory to dump to disk, it takes some time to do this, but when macOS is shutting down, it may not be patient and will kill the process before it is done and that will corrupt the image.

Lastly, in order to be able to use Multipass again, you will have to manually delete the suspend image and then delete the instance from within Multipass:

$ sudo launchctl unload /Library/LaunchDaemons/com.canonical.multipassd.plist
$ sudo /Library/Application\ Support/com.canonical.multipass/bin/qemu-img snapshot -d suspend /var/root/Library/Application\ Support/multipassd/qemu/vault/instances/primary/ubuntu-22.04-server-cloudimg-arm64.img
$ sudo launchctl load -w /Library/LaunchDaemons/com.canonical.multipassd.plist
kingsleyukr commented 9 months ago

thanks @townsend2010 however the options didn't work as the image is already corrupted. I just had to delete and purge the instances and relaunched a new instance. Perhaps the data there can't be retrieved anyhow

Thanks for the effort