Problems with LXD 4.3 - How to revert to 4.2?

I have LXD installed via Snap on Ubuntu 20.04. This morning it automatically upgraded it to version 4.3. Unfortunately I am having many problems with this new version. How do I go back to version 4.2?

Thanks!

What problems are you running into?

4.3 comes with a DB update so downgrading to 4.2 would require reverting the database as well, it’s possible but figuring out what’s not working may be much faster.

The performance is very sluggish when typing lxc commands. Also VMs sometimes stop. If I type lxc list it shows stopped, but in htop I see the process is still running. So I type lxc start I get an error message:-

Error: Failed to run: /snap/lxd/current/bin/lxd forklimits limit=memlock:unlimited:unlimited – /snap/lxd/15938/bin/qemu-system-aarch64 -S -name PiDebian -uuid 3ba93ea2-fa57-4e17-87d5-72a23cd9f907 -daemonize -cpu host -nographic -serial chardev:console -nodefaults -no-reboot -no-user-config -sandbox on,obsolete=deny,elevateprivileges=allow,spawn=deny,resourcecontrol=deny -readconfig /var/snap/lxd/common/lxd/logs/PiDebian/qemu.conf -pidfile /var/snap/lxd/common/lxd/logs/PiDebian/qemu.pid -D /var/snap/lxd/common/lxd/logs/PiDebian/qemu.log -chroot /var/snap/lxd/common/lxd/virtual-machines/PiDebian -smbios type=2,manufacturer=Canonical Ltd.,product=LXD -runas lxd: qemu-system-aarch64: cannot create PID file: Cannot lock pid file: Resource temporarily unavailable: exit status 1
Try lxc info --show-log PiDebian for more info

lxc info --show-log PiDebian
Name: PiDebian
Location: none
Remote: unix://
Architecture: aarch64
Created: 2020/07/02 17:49 UTC
Status: Stopped
Type: virtual-machine
Profiles: default
Pid: 2128
Resources:
Processes: 0
Snapshots:
BeforeDocker (taken at 2020/07/03 17:04 UTC) (stateless)

Log:

If “kill pid number” then I can start it again with lxc start.

Sounds like memory problems on your system, what does dmesg look like?

If rebooting is an option, I’d strongly recommend it when getting such odd errors.

I also would strongly recommend against issuing lxc start if you can see the qemu process still running as you may end up starting it twice corrupting the VM’s disk (locking should prevent it but better not risk it).

The host is a Raspberry Pi 4 with 4GB of RAM. I reboot it. Then I wait 3 mins. Then I type lxc list. This takes a while - I assume the service is started and the BTRFS file system is mounted.

Then I wait another 3 mins and type lxc start vm. The vm starts. I wait another 3 mins. Then I type lxc list and it shows as stopped. But in htop I see the 3 processes running for this VM.

I am unable to ssh into it and if I type lxc console vx then I get “Error: Instance is not running”

Here is the dmesg output (top omitted for brevity):-

[ 12.624313] random: 7 urandom warning(s) missed due to ratelimiting
[ 13.831024] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[ 13.871015] br0: port 1(eth0) entered blocking state
[ 13.871026] br0: port 1(eth0) entered disabled state
[ 13.871215] device eth0 entered promiscuous mode
[ 13.875899] bcmgenet: Skipping UMAC reset
[ 13.877276] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[ 13.877458] bcmgenet fd580000.ethernet eth0: Link is Down
[ 18.974037] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 18.974067] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 18.974156] br0: port 1(eth0) entered blocking state
[ 18.974164] br0: port 1(eth0) entered listening state
[ 23.005955] br0: port 1(eth0) entered learning state
[ 38.109976] br0: port 1(eth0) entered forwarding state
[ 38.110467] IPv6: ADDRCONF(NETDEV_CHANGE): br0: link becomes ready
[ 186.066522] new mount options do not match the existing superblock, will be ignored
[ 190.685946] bpfilter: Loaded bpfilter_umh pid 1835
[ 190.686893] Started bpfilter
[ 191.108546] BTRFS: device label default devid 1 transid 145349 /dev/loop6
[ 191.109580] BTRFS info (device loop6): disk space caching is enabled
[ 191.109587] BTRFS info (device loop6): has skinny extents
[ 191.274889] BTRFS info (device loop6): enabling ssd optimizations
[ 342.810967] NET: Registered protocol family 40
[ 343.806145] br0: port 2(tape926ec9f) entered blocking state
[ 343.806155] br0: port 2(tape926ec9f) entered disabled state
[ 343.806416] device tape926ec9f entered promiscuous mode
[ 345.186665] br0: port 2(tape926ec9f) entered blocking state
[ 345.186675] br0: port 2(tape926ec9f) entered listening state
[ 360.416178] br0: port 2(tape926ec9f) entered learning state
[ 375.520227] br0: port 2(tape926ec9f) entered forwarding state
[ 375.520234] br0: topology change detected, sending tcn bpdu

Can you show the output of ‘lxc info vm --show-log’?

By the this happens every time, so I repeated the process and below are outputs from both:-

lxc info --show-log PiDebian

Name: PiDebian
Location: none
Remote: unix://
Architecture: aarch64
Created: 2020/07/02 17:49 UTC
Status: Stopped
Type: virtual-machine
Profiles: default
Pid: 2057
Resources:
Processes: 0
Snapshots:
BeforeDocker (taken at 2020/07/03 17:04 UTC) (stateless)

Log:

dmesg

[ 12.004747] random: 7 urandom warning(s) missed due to ratelimiting
[ 13.731672] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[ 13.771397] br0: port 1(eth0) entered blocking state
[ 13.771408] br0: port 1(eth0) entered disabled state
[ 13.771592] device eth0 entered promiscuous mode
[ 13.775447] bcmgenet: Skipping UMAC reset
[ 13.776850] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[ 13.777029] bcmgenet fd580000.ethernet eth0: Link is Down
[ 18.878345] bcmgenet fd580000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 18.878375] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 18.878462] br0: port 1(eth0) entered blocking state
[ 18.878469] br0: port 1(eth0) entered listening state
[ 23.006271] br0: port 1(eth0) entered learning state
[ 38.110268] br0: port 1(eth0) entered forwarding state
[ 38.110722] IPv6: ADDRCONF(NETDEV_CHANGE): br0: link becomes ready
[ 97.691019] new mount options do not match the existing superblock, will be ignored
[ 102.155224] bpfilter: Loaded bpfilter_umh pid 1865
[ 102.155831] Started bpfilter
[ 102.585816] BTRFS: device label default devid 1 transid 145454 /dev/loop6
[ 102.587132] BTRFS info (device loop6): disk space caching is enabled
[ 102.587142] BTRFS info (device loop6): has skinny extents
[ 102.759607] BTRFS info (device loop6): enabling ssd optimizations
[ 189.020001] NET: Registered protocol family 40
[ 189.901427] br0: port 2(tapd64f3b59) entered blocking state
[ 189.901437] br0: port 2(tapd64f3b59) entered disabled state
[ 189.901636] device tapd64f3b59 entered promiscuous mode
[ 190.961590] br0: port 2(tapd64f3b59) entered blocking state
[ 190.961601] br0: port 2(tapd64f3b59) entered listening state
[ 206.042070] br0: port 2(tapd64f3b59) entered learning state
[ 221.145672] br0: port 2(tapd64f3b59) entered forwarding state
[ 221.145679] br0: topology change detected, sending tcn bpdu

lxc list
±-------------±--------±-----±-----±----------------±----------+
| NAME | STATE | IPV4 | IPV6 | TYPE | SNAPSHOTS |
±-------------±--------±-----±-----±----------------±----------+
| PiAlpine | STOPPED | | | VIRTUAL-MACHINE | 0 |
±-------------±--------±-----±-----±----------------±----------+
| PiDebian | STOPPED | | | VIRTUAL-MACHINE | 1 |
±-------------±--------±-----±-----±----------------±----------+

Weird, I just tested here on my rpi4 and VMs appear to be behaving as normal.

Can you show the full ps fauxww output as well as lxc config show --expanded PiDebian?

lxc config show --expanded PiDebian

architecture: aarch64
config:
image.architecture: arm64
image.description: Debian buster arm64 (20200702_06:12)
image.os: Debian
image.release: buster
image.serial: “20200702_06:12”
image.type: disk-kvm.img
limits.cpu: “2”
limits.memory: 512MB
security.secureboot: “false”
volatile.base_image: 1369ef99062ecf5cb50475194d04f58c7c6bf62b1c04f4cc91794fb26832157a
volatile.eth0.host_name: tap2a1e692a
volatile.eth0.hwaddr: 00:16:3e:6b:02:42
volatile.last_state.power: RUNNING
volatile.vm.uuid: 3ba93ea2-fa57-4e17-87d5-72a23cd9f907
devices:
eth0:
name: eth0
nictype: bridged
parent: br0
type: nic
root:
path: /
pool: default
type: disk
ephemeral: false
profiles:

  • default
    stateful: false
    description: “”

ps fauxww

USER         PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root           2  0.0  0.0      0     0 ?        S    19:38   0:00 [kthreadd]
root           3  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [rcu_gp]
root           4  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [rcu_par_gp]
root           7  0.3  0.0      0     0 ?        I    19:38   0:03  \_ [kworker/u8:0-btrfs-endio-write]
root           8  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [mm_percpu_wq]
root           9  0.3  0.0      0     0 ?        S    19:38   0:03  \_ [ksoftirqd/0]
root          10  0.0  0.0      0     0 ?        I    19:38   0:00  \_ [rcu_sched]
root          11  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [migration/0]
root          12  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [idle_inject/0]
root          14  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [cpuhp/0]
root          15  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [cpuhp/1]
root          16  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [idle_inject/1]
root          17  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [migration/1]
root          18  0.2  0.0      0     0 ?        S    19:38   0:02  \_ [ksoftirqd/1]
root          21  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [cpuhp/2]
root          22  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [idle_inject/2]
root          23  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [migration/2]
root          24  0.4  0.0      0     0 ?        S    19:38   0:03  \_ [ksoftirqd/2]
root          27  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [cpuhp/3]
root          28  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [idle_inject/3]
root          29  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [migration/3]
root          30  0.1  0.0      0     0 ?        S    19:38   0:01  \_ [ksoftirqd/3]
root          33  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [kdevtmpfs]
root          34  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [netns]
root          35  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [rcu_tasks_kthre]
root          36  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [kauditd]
root          37  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [khungtaskd]
root          38  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [oom_reaper]
root          39  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [writeback]
root          40  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [kcompactd0]
root          41  0.0  0.0      0     0 ?        SN   19:38   0:00  \_ [ksmd]
root          43  0.1  0.0      0     0 ?        I    19:38   0:01  \_ [kworker/u8:1-btrfs-endio-write]
root         136  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [kintegrityd]
root         137  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [kblockd]
root         138  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [blkcg_punt_bio]
root         139  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [tpm_dev_wq]
root         140  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [ata_sff]
root         141  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [md]
root         142  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [edac-poller]
root         143  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [devfreq_wq]
root         144  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [watchdogd]
root         145  0.0  0.0      0     0 ?        I    19:38   0:00  \_ [kworker/1:1-events]
root         147  0.8  0.0      0     0 ?        S    19:38   0:06  \_ [kswapd0]
root         148  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [ecryptfs-kthrea]
root         151  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [kthrotld]
root         152  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [irq/42-aerdrv]
root         154  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [DWC Notificatio]
root         155  0.0  0.0      0     0 ?        I    19:38   0:00  \_ [kworker/2:2-mm_percpu_wq]
root         156  0.0  0.0      0     0 ?        S<   19:38   0:00  \_ [vchiq-slot/0]
root         157  0.0  0.0      0     0 ?        S<   19:38   0:00  \_ [vchiq-recy/0]
root         158  0.0  0.0      0     0 ?        S<   19:38   0:00  \_ [vchiq-sync/0]
root         159  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [ipv6_addrconf]
root         170  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [kstrp]
root         174  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [kworker/u9:0]
root         179  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [cryptd]
root         242  0.0  0.0      0     0 ?        I    19:38   0:00  \_ [kworker/0:2-events]
root         243  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [spi0]
root         244  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [irq/28-brcmstb_]
root         245  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [sdhci]
root         246  0.0  0.0      0     0 ?        S    19:38   0:00  \_ [irq/27-mmc0]
root         247  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [charger_manager]
root         270  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [mmc_complete]
root         272  0.2  0.0      0     0 ?        D<   19:38   0:02  \_ [kworker/0:1H+kblockd]
root         274  0.1  0.0      0     0 ?        I<   19:38   0:00  \_ [kworker/3:1H-kblockd]
root         300  0.2  0.0      0     0 ?        I<   19:38   0:02  \_ [kworker/2:1H-kblockd]
root         304  0.2  0.0      0     0 ?        I<   19:38   0:02  \_ [kworker/1:1H-kblockd]
root         305  0.0  0.0      0     0 ?        I<   19:38   0:00  \_ [kworker/1:2H-kblockd]
root         588  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [raid5wq]
root         645  0.0  0.0      0     0 ?        D    19:39   0:00  \_ [jbd2/mmcblk0p2-]
root         646  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [ext4-rsv-conver]
root         742  0.0  0.0      0     0 ?        I    19:39   0:00  \_ [kworker/3:2-events]
root         779  0.0  0.0      0     0 ?        S    19:39   0:00  \_ [vchiq-keep/0]
root         780  0.0  0.0      0     0 ?        S<   19:39   0:00  \_ [SMIO]
root         836  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [cfg80211]
root         900  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [brcmf_wq/mmc1:0]
root         901  0.0  0.0      0     0 ?        S    19:39   0:00  \_ [brcmf_wdog/mmc1]
root        1085  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [kaluad]
root        1086  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [kmpath_rdacd]
root        1087  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [kmpathd]
root        1088  0.0  0.0      0     0 ?        I<   19:39   0:00  \_ [kmpath_handlerd]
root        1099  0.0  0.0      0     0 ?        S<   19:39   0:00  \_ [loop0]
root        1104  0.0  0.0      0     0 ?        S<   19:39   0:00  \_ [loop1]
root        1106  0.0  0.0      0     0 ?        S<   19:39   0:00  \_ [loop2]
root        1108  0.0  0.0      0     0 ?        S<   19:39   0:00  \_ [loop3]
root        1109  0.0  0.0      0     0 ?        S<   19:39   0:00  \_ [loop4]
root        1110  0.0  0.0      0     0 ?        S<   19:39   0:00  \_ [loop5]
root        1766  0.2  0.0      0     0 ?        I    19:44   0:01  \_ [kworker/u8:2-btrfs-endio-write]
root        1767  0.0  0.0      0     0 ?        D    19:44   0:00  \_ [kworker/0:0+events_freezable]
root        1776  0.0  0.0      0     0 ?        I    19:44   0:00  \_ [kworker/2:0-events]
root        1794  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [kworker/3:0H-kblockd]
root        1795  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [kworker/0:0H-kblockd]
root        1960  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [kworker/1:0H-kblockd]
root        1995  0.0  0.0      0     0 ?        I    19:44   0:00  \_ [kworker/3:0-events]
root        2007  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [kworker/2:0H-kblockd]
root        2054  0.0  0.0      0     0 ?        I    19:44   0:00  \_ [kworker/1:0-mm_percpu_wq]
root        2159  0.2  0.0      0     0 ?        I    19:44   0:01  \_ [kworker/u8:3-flush-btrfs-1]
root        2164  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [dio/mmcblk0p2]
root        2168  0.0  0.0      0     0 ?        I    19:44   0:00  \_ [kworker/0:3-mm_percpu_wq]
root        2186  0.0  0.0   1912   416 ?        S    19:44   0:00  \_ bpfilter_umh
root        2199  0.0  0.0      0     0 ?        I    19:44   0:00  \_ [kworker/2:3-events]
root        2214  3.6  0.0      0     0 ?        D<   19:44   0:16  \_ [loop6]
root        2215  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-worker]
root        2216  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-worker-hi]
root        2217  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-delalloc]
root        2218  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-flush_del]
root        2219  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-cache]
root        2220  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-submit]
root        2221  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-fixup]
root        2222  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-endio]
root        2223  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-endio-met]
root        2224  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-endio-met]
root        2225  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-endio-rai]
root        2226  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-endio-rep]
root        2227  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-rmw]
root        2228  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-endio-wri]
root        2229  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-freespace]
root        2230  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-delayed-m]
root        2231  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-readahead]
root        2232  0.0  0.0      0     0 ?        I<   19:44   0:00  \_ [btrfs-qgroup-re]
root        2234  0.0  0.0      0     0 ?        S    19:44   0:00  \_ [btrfs-cleaner]
root        2235  0.1  0.0      0     0 ?        S    19:44   0:00  \_ [btrfs-transacti]
root        2272  0.3  0.0      0     0 ?        I    19:44   0:01  \_ [kworker/u8:4-btrfs-freespace-write]
root        2273  0.6  0.0      0     0 ?        I    19:44   0:02  \_ [kworker/u8:5-btrfs-endio-write]
root        2274  0.1  0.0      0     0 ?        D    19:46   0:00  \_ [kworker/u8:6+flush-179:0]
root        2275  0.2  0.0      0     0 ?        I    19:46   0:00  \_ [kworker/u8:7-btrfs-endio-meta]
root        2276  0.1  0.0      0     0 ?        I    19:46   0:00  \_ [kworker/u8:8-btrfs-endio-write]
root        2277  0.0  0.0      0     0 ?        I    19:46   0:00  \_ [kworker/u8:9-btrfs-endio-meta]
root        2278  0.4  0.0      0     0 ?        D    19:46   0:01  \_ [kworker/u8:10+btrfs-submit]
root        2279  0.0  0.0      0     0 ?        I    19:46   0:00  \_ [kworker/u8:11-btrfs-endio-meta]
root        2280  0.0  0.0      0     0 ?        I    19:46   0:00  \_ [kworker/u8:12-btrfs-endio-write]
root        2281  0.4  0.0      0     0 ?        D    19:46   0:01  \_ [kworker/u8:13+events_unbound]
root        2468  0.4  0.0      0     0 ?        I    19:48   0:01  \_ [kworker/u8:14-btrfs-endio-write]
root        2470  0.0  0.0      0     0 ?        I    19:48   0:00  \_ [kworker/u8:15]
root        2477  0.0  0.0      0     0 ?        S    19:48   0:00  \_ [vhost-2473]
root        2482  0.0  0.0      0     0 ?        S    19:48   0:00  \_ [vhost-2473]
root        2506  0.0  0.0      0     0 ?        I<   19:49   0:00  \_ [kworker/0:2H-kblockd]
root        2518  0.0  0.0      0     0 ?        I<   19:50   0:00  \_ [kworker/2:2H-kblockd]
root        2520  0.0  0.0      0     0 ?        I<   19:50   0:00  \_ [kworker/3:2H-kblockd]
root        2569  0.0  0.0      0     0 ?        I    19:51   0:00  \_ [kworker/3:1-mm_percpu_wq]
root        2570  0.0  0.0      0     0 ?        I    19:51   0:00  \_ [kworker/1:2-events]
root        2572  0.0  0.0      0     0 ?        I    19:52   0:00  \_ [kworker/0:1-events]
root           1  0.3  0.2 167660 10396 ?        Ss   19:38   0:03 /sbin/init fixrtc splash
root         720  0.0  0.1  67620  6996 ?        S<s  19:39   0:00 /lib/systemd/systemd-journald
root         744  0.0  0.1  20084  4792 ?        Ss   19:39   0:00 /lib/systemd/systemd-udevd
root        1089  0.0  0.4 280224 16604 ?        SLsl 19:39   0:00 /sbin/multipathd -d -s
systemd+    1130  0.0  0.1  90124  6444 ?        Ssl  19:39   0:00 /lib/systemd/systemd-timesyncd
systemd+    1177  0.0  0.1  18256  6900 ?        Ss   19:39   0:00 /lib/systemd/systemd-networkd
systemd+    1183  0.0  0.3  24080 12144 ?        Ss   19:39   0:00 /lib/systemd/systemd-resolved
root        1221  0.0  0.1 237620  6804 ?        Ssl  19:39   0:00 /usr/lib/accountsservice/accounts-daemon
message+    1222  0.0  0.1   8188  4204 ?        Ss   19:39   0:00 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only
root        1225  0.0  0.0  80924  2996 ?        Ssl  19:39   0:00 /usr/sbin/irqbalance --foreground
root        1226  0.0  0.4  29076 16676 ?        Ss   19:39   0:00 /usr/bin/python3 /usr/bin/networkd-dispatcher --run-startup-triggers
syslog      1228  0.0  0.1 221160  4436 ?        Ssl  19:39   0:00 /usr/sbin/rsyslogd -n -iNONE
root        1229  0.5  0.6 1139376 24980 ?       Ssl  19:39   0:04 /usr/lib/snapd/snapd
root        1231  0.0  0.1  16620  6772 ?        Ss   19:39   0:00 /lib/systemd/systemd-logind
root        1232  0.0  0.1  12356  4656 ?        Ss   19:39   0:00 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant
root        1250  0.0  0.0   8328  2512 ?        Ss   19:39   0:00 /usr/sbin/cron -f
root        1268  0.0  0.4 107784 19064 ?        Ssl  19:39   0:00 /usr/bin/python3 /usr/share/unattended-upgrades/unattended-upgrade-shutdown --wait-for-signal
daemon      1270  0.0  0.0   3584  1824 ?        Ss   19:39   0:00 /usr/sbin/atd -f
root        1274  0.0  0.0   6828  1884 ttyS0    Ss+  19:39   0:00 /sbin/agetty -o -p -- \u --keep-baud 115200,38400,9600 ttyS0 vt220
root        1276  0.0  0.0   5304  1412 tty1     Ss+  19:39   0:00 /sbin/agetty -o -p -- \u --noclear tty1 linux
root        1284  0.0  0.1  12184  6532 ?        Ss   19:39   0:00 sshd: /usr/sbin/sshd -D [listener] 0 of 10-100 startups
root        1768  0.0  0.1  15460  7708 ?        Ss   19:44   0:00  \_ sshd: wolfgang [priv]
wolfgang    1887  0.0  0.1  15332  4828 ?        S    19:44   0:00  |   \_ sshd: wolfgang@pts/0
wolfgang    1890  0.0  0.1   9916  4944 pts/0    Ss   19:44   0:00  |       \_ -bash
wolfgang    2573  0.5  0.0  10508  3132 pts/0    R+   19:52   0:00  |           \_ ps fauxww
root        1835  0.0  0.2  15460  7772 ?        Ss   19:44   0:00  \_ sshd: wolfgang [priv]
wolfgang    1950  0.0  0.1  15332  4876 ?        S    19:44   0:00      \_ sshd: wolfgang@pts/1
wolfgang    1951  0.0  0.1   9916  4716 pts/1    Ss   19:44   0:00          \_ -bash
wolfgang    1961  2.0  0.0   7308  3228 pts/1    S+   19:44   0:09              \_ htop
root        1288  0.0  0.1 232916  6176 ?        Ssl  19:39   0:00 /usr/lib/policykit-1/polkitd --no-debug
wolfgang    1771  0.1  0.2  19564 10160 ?        Ss   19:44   0:00 /lib/systemd/systemd --user
wolfgang    1772  0.0  0.1 169732  5088 ?        S    19:44   0:00  \_ (sd-pam)
root        2001  0.0  0.0   1912  1308 ?        Ss   19:44   0:00 /bin/sh /snap/lxd/15938/commands/daemon.start
root        2137  9.9  4.4 1879776 171312 ?      Sl   19:44   0:45  \_ lxd --logfile /var/snap/lxd/common/lxd/logs/lxd.log --group lxd
root        2514 77.7  0.4 455120 19056 ?        Sl   19:49   1:58      \_ qemu-img dd -f qcow2 -O raw bs=8192 if=/var/snap/lxd/common/lxd/images/82c207779f6beda3ff7d716cd566ee21c44624d336705b3ab8d97a7dd6dcdf8f.rootfs of=/var/snap/lxd/common/lxd/storage-pools/default/images/82c207779f6beda3ff7d716cd566ee21c44624d336705b3ab8d97a7dd6dcdf8f/root.img
root        2126  0.0  0.0  85148  1132 ?        Sl   19:44   0:00 lxcfs /var/snap/lxd/common/var/lib/lxcfs -p /var/snap/lxd/common/lxcfs.pid
lxd         2473 11.3 10.8 1467840 420780 ?      Sl   19:48   0:27 /snap/lxd/15938/bin/qemu-system-aarch64 -S -name PiDebian -uuid 3ba93ea2-fa57-4e17-87d5-72a23cd9f907 -daemonize -cpu host -nographic -serial chardev:console -nodefaults -no-reboot -no-user-config -sandbox on,obsolete=deny,elevateprivileges=allow,spawn=deny,resourcecontrol=deny -readconfig /var/snap/lxd/common/lxd/logs/PiDebian/qemu.conf -pidfile /var/snap/lxd/common/lxd/logs/PiDebian/qemu.pid -D /var/snap/lxd/common/lxd/logs/PiDebian/qemu.log -chroot /var/snap/lxd/common/lxd/virtual-machines/PiDebian -smbios type=2,manufacturer=Canonical Ltd.,product=LXD -runas lxd

That’s pretty weird…

Can you show cat /var/snap/lxd/common/lxd/logs/PiDebian/qemu.log.

Also, run lxc monitor --type=logging --pretty in a separate terminal and then in your main one, run lxc info PiDebian then provide the output from both, maybe that will shed some light on what’s going on there.

The qemu.log file is empty with a size of 0 bytes:-

root@PiLXD:/var/snap/lxd/common/lxd/logs/PiDebian# ls -al
total 16
drwx------ 2 root root 4096 Jul 3 19:48 .
drwx------ 19 root root 4096 Jul 3 19:44 …
-rw-r----- 1 root root 3459 Jul 3 19:48 qemu.conf
-rw-r----- 1 root root 0 Jul 3 19:48 qemu.log
srwxr-x— 1 root root 0 Jul 3 19:48 qemu.monitor
-rw------- 1 root root 5 Jul 3 19:48 qemu.pid
srwxr-x— 1 root root 0 Jul 3 19:48 qemu.spice

lxc info PiDebian
Name: PiDebian
Location: none
Remote: unix://
Architecture: aarch64
Created: 2020/07/02 17:49 UTC
Status: Stopped
Type: virtual-machine
Profiles: default
Pid: 2473
Resources:
Processes: 0
Snapshots:
BeforeDocker (taken at 2020/07/03 17:04 UTC) (stateless)

lxc monitor --type=logging --pretty
To start your first instance, try: lxc launch ubuntu:18.04

DBUG[07-03|20:08:32] New event listener: 51966818-aec3-40cc-9147-01881d9c97b3
DBUG[07-03|20:08:50] Handling ip=@ method=GET url=/1.0 user=
DBUG[07-03|20:08:50] Handling method=GET url=/1.0/instances/PiDebian user= ip=@
DBUG[07-03|20:08:50] Handling ip=@ method=GET url=/1.0/instances/PiDebian/state user=
DBUG[07-03|20:08:50] Handling ip=@ method=GET url="/1.0/instances/PiDebian/snapshots?recursion=1" user=
DBUG[07-03|20:08:50] GetInstanceUsage started pool=default project=default driver=btrfs instance=PiDebian/BeforeDocker
DBUG[07-03|20:08:50] GetInstanceUsage finished driver=btrfs instance=PiDebian/BeforeDocker pool=default project=default

By the way my 3 other VMs boot fine. So only this VM (Debian) is causing this problem.

That’s pretty weird. Does a new VM also work properly?

For that Debian VM, can you try: nc -v -U /var/snap/lxd/common/lxd/logs/PiDebian/qemu.monitor

nc -v -U /var/snap/lxd/common/lxd/logs/PiDebian/qemu.monitor yields no output :frowning:

Another weird thing. If I reboot the Pi 4, start one of those other 3 VMs first. Then wait a minute and then boot the Debian VM then it boots fine.

That is very weird…

The nc -U call not returning anything hints that LXD is probably connected to qemu, that or qemu is completely unresponsive, it’s kinda hard to tell…

If you want to try to debug it further when it’s stuck, you can run that nc -v -U from above and then reload LXD with systemctl reload snap.lxd.daemon. That will disconnect LXD from QMP and should connect you instead.

You’ll see something like:

{"QMP": {"version": {"qemu": {"micro": 0, "minor": 0, "major": 5}, "package": "v5.0.0-dirty"}, "capabilities": ["oob"]}}

At which point you can enter:

{"execute":"qmp_capabilities"}
{"execute":"query-status"}

On a properly working qemu, that would get you:

{"return": {"status": "running", "singlestep": false, "running": true}}

I’m assuming you’ve also already tried pinging the IP address of that VM to see if it’s responsive even when LXD shows it stopped?

Just now I tried pinging it and no response. It is still running in htop though. It is idling with not much cpu usage but it is still using the full 512MB of memory.