snap.lxd.daemon.service reports unexpected response type 6

[John George]

Snap install and lxd init errors after clean install of 19.04 on LPAR.

ubuntu@s5lp7:~$ lsb_release -rd
Description: Ubuntu Disco Dingo (development branch)
Release: 19.04

sudo mkdir /etc/systemd/system/snapd.service.d
sudo tee /etc/systemd/system/snapd.service.d/snap_proxy.conf <<EOF
[Service]
Environment=http_proxy=http://squid.internal:3128
Environment=https_proxy=http://squid.internal:3128
EOF
sudo systemctl daemon-reload
sudo systemctl restart snapd.service

ubuntu@s5lp7:~$ sudo snap install lxd
2019-04-11T16:55:20Z INFO Waiting for restart...
lxd 3.12 from Canonical✓ installed

ubuntu@s5lp7:~$ sudo lxd init
[sudo] password for ubuntu:
Would you like to use LXD clustering? (yes/no) [default=no]:
Do you want to configure a new storage pool? (yes/no) [default=yes]:
Name of the new storage pool [default=default]:
Name of the storage backend to use (btrfs, ceph, dir, lvm, zfs) [default=zfs]:
Create a new ZFS pool? (yes/no) [default=yes]:
Would you like to use an existing block device? (yes/no) [default=no]:
Size in GB of the new loop device (1GB minimum) [default=15GB]:
Would you like to connect to a MAAS server? (yes/no) [default=no]:
Would you like to create a new local network bridge? (yes/no) [default=yes]:
What should the new bridge be called? [default=lxdbr0]:
What IPv4 address should be used? (CIDR subnet notation, “auto” or “none”) [default=auto]:
What IPv6 address should be used? (CIDR subnet notation, “auto” or “none”) [default=auto]: none
Would you like LXD to be available over the network? (yes/no) [default=no]:
Would you like stale cached images to be updated automatically? (yes/no) [default=yes]
Would you like a YAML "lxd init" preseed to be printed? (yes/no) [default=no]:

Error: Failed to create network 'lxdbr0': unexpected response type 6

ubuntu@s5lp7:~$ id
uid=1000(ubuntu) gid=1000(ubuntu) groups=1000(ubuntu),4(adm),24(cdrom),27(sudo),30(dip),46(plugdev),117(lpadmin),118(sambashare),998(lxd)
ubuntu@s5lp7:~$ lxc list
Error: cannot fetch node config from database: unexpected response type 6

ubuntu@s5lp7:~$ systemctl status snap.lxd.daemon.unix.socket
● snap.lxd.daemon.unix.socket - Socket unix for snap application lxd.daemon
   Loaded: loaded (/etc/systemd/system/snap.lxd.daemon.unix.socket; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2019-04-11 21:06:34 UTC; 1h 40min ago
   Listen: /var/snap/lxd/common/lxd/unix.socket (Stream)
    Tasks: 0 (limit: 2108)
   Memory: 0B
   CGroup: /system.slice/snap.lxd.daemon.unix.socket

Apr 11 21:06:34 s5lp7 systemd[1]: Listening on Socket unix for snap application lxd.daemon.

ubuntu@s5lp7:~$ systemctl status snap.lxd.daemon.service
● snap.lxd.daemon.service - Service for snap application lxd.daemon
   Loaded: loaded (/etc/systemd/system/snap.lxd.daemon.service; static; vendor preset: enabled)
   Active: active (running) since Thu 2019-04-11 21:06:47 UTC; 1h 40min ago
 Main PID: 16900 (daemon.start)
    Tasks: 0 (limit: 2108)
   Memory: 9.0M
   CGroup: /system.slice/snap.lxd.daemon.service
           ‣ 16900 /bin/sh /snap/lxd/10534/commands/daemon.start

Apr 11 22:45:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:45:25+0000 lvl=warn msg="Failed to rollback transaction after error (Local node name: unexpected response type 6): unexpected response type
Apr 11 22:45:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:45:25+0000 lvl=eror msg="Failed to load containers for scheduled snapshots" err="Local node name: unexpected response type 6"
Apr 11 22:46:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:46:25+0000 lvl=warn msg="Failed to rollback transaction after error (Local node name: unexpected response type 6): unexpected response type
Apr 11 22:46:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:46:25+0000 lvl=eror msg="Failed to load containers for snapshot expiry" err="Local node name: unexpected response type 6"
Apr 11 22:46:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:46:25+0000 lvl=warn msg="Failed to rollback transaction after error (Local node name: unexpected response type 6): unexpected response type
Apr 11 22:46:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:46:25+0000 lvl=eror msg="Failed to load containers for scheduled snapshots" err="Local node name: unexpected response type 6"
Apr 11 22:47:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:47:25+0000 lvl=warn msg="Failed to rollback transaction after error (Local node name: unexpected response type 6): unexpected response type
Apr 11 22:47:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:47:25+0000 lvl=eror msg="Failed to load containers for snapshot expiry" err="Local node name: unexpected response type 6"
Apr 11 22:47:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:47:25+0000 lvl=warn msg="Failed to rollback transaction after error (Local node name: unexpected response type 6): unexpected response type
Apr 11 22:47:25 s5lp7 lxd.daemon[16900]: t=2019-04-11T22:47:25+0000 lvl=eror msg="Failed to load containers for scheduled snapshots" err="Local node name: unexpected response type 6"
lines 1-19/19 (END)...skipping...

Restart of snap.lxd.daemon.service seems to clear up the issues:

ubuntu@s5lp7:~$ sudo systemctl restart snap.lxd.daemon.service
ubuntu@s5lp7:~$ systemctl status snap.lxd.daemon.service
● snap.lxd.daemon.service - Service for snap application lxd.daemon
   Loaded: loaded (/etc/systemd/system/snap.lxd.daemon.service; static; vendor preset: enabled)
   Active: active (running) since Thu 2019-04-11 22:48:06 UTC; 3s ago
 Main PID: 23677 (daemon.start)
    Tasks: 0 (limit: 2108)
   Memory: 15.9M
   CGroup: /system.slice/snap.lxd.daemon.service
           ‣ 23677 /bin/sh /snap/lxd/10534/commands/daemon.start

Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: 6: fd: 13: freezer
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: 7: fd: 14: rdma
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: 8: fd: 15: hugetlb
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: 9: fd: 16: blkio
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: 10: fd: 17: net_cls,net_prio
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: 11: fd: 18: name=systemd
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: 12: fd: 19: unified
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: => Starting LXD
Apr 11 22:48:06 s5lp7 lxd.daemon[23677]: t=2019-04-11T22:48:06+0000 lvl=warn msg="CGroup memory swap accounting is disabled, swap limits will be ignored."
Apr 11 22:48:07 s5lp7 lxd.daemon[23677]: => LXD is ready

ubuntu@s5lp7:~$ sudo lxc launch ubuntu:18.04
Creating the container
Container name is: glorious-asp
Starting glorious-asp

[Stéphane Graber (stgraber)]

Does this happen repeatedly?

It's a glitch in dqlite which we've seen happen pretty rarely and that will go away with the complete rewrite of the database layer that's meant to land in a few months.

Normally a simple "systemctl reload snap.lxd.daemon" or "snap restart lxd" gets you rid of this.

We do have daily testing of the LXD snap on all architectures and have only seen this show up once every few weeks so hasn't been worth the effort to debug code that's going away.

If you have a system where this happens every time or have a clear step by step reproducer which causes this to happen reliably, then we will still look into it, otherwise, we'll likely close this.

[John George (jog)]

I did not run into this again, when retesting the released version of 19.04.

[Frank Heimes (fheimes)]

Closing bug according to comment #3.