LXD snap refresh today hung LXD and snapd

LXD
#1

I’m not 100% sure if this should be here on snapcraft forum, but the latest snap refresh has locked up my LXD service and the snap daemon has been thrashing my disk for hours seemingly in infinite loop. I’m on Ubuntu 20.04 and use LXD every day.

According to the logs below the LXD daemon is active, however snapd doesn’t think it started, and likewise lxc cli command just hangs indefinitely.

Hoping for some advice before attempting to kill/restart things. Thank you.

 ➜ snap changes
ID   Status  Spawn               Ready  Summary
116  Doing   today at 10:38 EST  -      Auto-refresh snaps "lxd", "snap-store", "gtk-common-themes"

➜ snap tasks 116
Status  Spawn               Ready               Summary
Done    today at 10:38 EST  today at 10:38 EST  Ensure prerequisites for "lxd" are available
Done    today at 10:38 EST  today at 10:39 EST  Download snap "lxd" (18402) from channel "latest/stable"
Done    today at 10:38 EST  today at 10:39 EST  Fetch and check assertions for snap "lxd" (18402)
Done    today at 10:38 EST  today at 10:39 EST  Mount snap "lxd" (18402)
Done    today at 10:38 EST  today at 10:39 EST  Run pre-refresh hook of "lxd" snap if present
Done    today at 10:38 EST  today at 10:39 EST  Stop snap "lxd" services
Done    today at 10:38 EST  today at 10:39 EST  Remove aliases for snap "lxd"
Done    today at 10:38 EST  today at 10:39 EST  Make current revision for snap "lxd" unavailable
Done    today at 10:38 EST  today at 10:39 EST  Copy snap "lxd" data
Done    today at 10:38 EST  today at 10:39 EST  Setup snap "lxd" (18402) security profiles
Done    today at 10:38 EST  today at 10:39 EST  Make snap "lxd" (18402) available to the system
Done    today at 10:38 EST  today at 10:39 EST  Automatically connect eligible plugs and slots of snap "lxd"
Done    today at 10:38 EST  today at 10:39 EST  Set automatic aliases for snap "lxd"
Done    today at 10:38 EST  today at 10:39 EST  Setup snap "lxd" aliases
Done    today at 10:38 EST  today at 10:39 EST  Run post-refresh hook of "lxd" snap if present
Doing   today at 10:38 EST  -                   Start snap "lxd" (18402) services
Do      today at 10:38 EST  -                   Remove data for snap "lxd" (18251)
Do      today at 10:38 EST  -                   Remove snap "lxd" (18251) from the system
Do      today at 10:38 EST  -                   Clean up "lxd" (18402) install
Do      today at 10:38 EST  -                   Run configure hook of "lxd" snap if present
Do      today at 10:38 EST  -                   Run health check of "lxd" snap
Done    today at 10:38 EST  today at 10:38 EST  Ensure prerequisites for "snap-store" are available
Done    today at 10:38 EST  today at 10:39 EST  Download snap "snap-store" (498) from channel "latest/stable/ubuntu-20.04"
Done    today at 10:38 EST  today at 10:39 EST  Fetch and check assertions for snap "snap-store" (498)
Done    today at 10:38 EST  today at 10:39 EST  Mount snap "snap-store" (498)
Done    today at 10:38 EST  today at 10:39 EST  Run pre-refresh hook of "snap-store" snap if present
Done    today at 10:38 EST  today at 10:39 EST  Stop snap "snap-store" services
Done    today at 10:38 EST  today at 10:39 EST  Remove aliases for snap "snap-store"
Done    today at 10:38 EST  today at 10:39 EST  Make current revision for snap "snap-store" unavailable
Done    today at 10:38 EST  today at 10:39 EST  Copy snap "snap-store" data
Done    today at 10:38 EST  today at 10:39 EST  Setup snap "snap-store" (498) security profiles
Done    today at 10:38 EST  today at 10:39 EST  Make snap "snap-store" (498) available to the system
Done    today at 10:38 EST  today at 10:39 EST  Automatically connect eligible plugs and slots of snap "snap-store"
Done    today at 10:38 EST  today at 10:39 EST  Set automatic aliases for snap "snap-store"
Done    today at 10:38 EST  today at 10:39 EST  Setup snap "snap-store" aliases
Done    today at 10:38 EST  today at 10:39 EST  Run post-refresh hook of "snap-store" snap if present
Done    today at 10:38 EST  today at 10:39 EST  Start snap "snap-store" (498) services
Done    today at 10:38 EST  today at 10:39 EST  Remove data for snap "snap-store" (481)
Done    today at 10:38 EST  today at 10:39 EST  Remove snap "snap-store" (481) from the system
Done    today at 10:38 EST  today at 10:39 EST  Clean up "snap-store" (498) install
Done    today at 10:38 EST  today at 10:39 EST  Run configure hook of "snap-store" snap if present
Done    today at 10:38 EST  today at 10:39 EST  Run health check of "snap-store" snap
Done    today at 10:38 EST  today at 10:38 EST  Ensure prerequisites for "gtk-common-themes" are available
Done    today at 10:38 EST  today at 10:38 EST  Download snap "gtk-common-themes" (1513) from channel "latest/stable/ubuntu-20.04"
Done    today at 10:38 EST  today at 10:38 EST  Fetch and check assertions for snap "gtk-common-themes" (1513)
Done    today at 10:38 EST  today at 10:38 EST  Mount snap "gtk-common-themes" (1513)
Done    today at 10:38 EST  today at 10:38 EST  Run pre-refresh hook of "gtk-common-themes" snap if present
Done    today at 10:38 EST  today at 10:38 EST  Stop snap "gtk-common-themes" services
Done    today at 10:38 EST  today at 10:38 EST  Remove aliases for snap "gtk-common-themes"
Done    today at 10:38 EST  today at 10:38 EST  Make current revision for snap "gtk-common-themes" unavailable
Done    today at 10:38 EST  today at 10:38 EST  Copy snap "gtk-common-themes" data
Done    today at 10:38 EST  today at 10:38 EST  Setup snap "gtk-common-themes" (1513) security profiles
Done    today at 10:38 EST  today at 10:38 EST  Make snap "gtk-common-themes" (1513) available to the system
Done    today at 10:38 EST  today at 10:38 EST  Automatically connect eligible plugs and slots of snap "gtk-common-themes"
Done    today at 10:38 EST  today at 10:38 EST  Set automatic aliases for snap "gtk-common-themes"
Done    today at 10:38 EST  today at 10:38 EST  Setup snap "gtk-common-themes" aliases
Done    today at 10:38 EST  today at 10:38 EST  Run post-refresh hook of "gtk-common-themes" snap if present
Done    today at 10:38 EST  today at 10:38 EST  Start snap "gtk-common-themes" (1513) services
Done    today at 10:38 EST  today at 10:38 EST  Clean up "gtk-common-themes" (1513) install
Done    today at 10:38 EST  today at 10:38 EST  Run configure hook of "gtk-common-themes" snap if present
Done    today at 10:38 EST  today at 10:38 EST  Run health check of "gtk-common-themes" snap
Doing   today at 10:38 EST  -                   Consider re-refresh of "lxd", "snap-store", "gtk-common-themes"
Done    today at 10:39 EST  today at 10:39 EST  Connect snap-store:opengl to snapd:opengl
Done    today at 10:39 EST  today at 10:39 EST  Setup snap "snap-store" (498) security profiles for auto-connections

It’s currently 12:44 EST (2 hours later) than above log.

➜ snap services lxd.daemon
Service     Startup  Current  Notes
lxd.daemon  enabled  active   socket-activated

➜ snap info lxd
name:      lxd
...
services:
  lxd.activate: oneshot, enabled, inactive
  lxd.daemon:   simple, enabled, active
snap-id:      J60k4JY0HppjwOjW8dZdYc8obXKxujRu
tracking:     latest/stable
refresh-date: today at 10:39 EST
channels:
  latest/stable:    4.8         2020-11-25 (18402) 73MB -
  latest/candidate: 4.8         2020-11-24 (18402) 73MB -
  latest/beta:      ↑
  latest/edge:      git-669c722 2020-11-25 (18418) 73MB -
  4.8/stable:       4.8         2020-11-25 (18402) 73MB -
  4.8/candidate:    4.8         2020-11-24 (18402) 73MB -
  4.8/beta:         ↑
  4.8/edge:         ↑

➜ snap logs -n 100 lxd.daemon
2020-11-20T14:34:34Z lxd.daemon[1734]:   9: fd:  14: perf_event
2020-11-20T14:34:34Z lxd.daemon[1734]:  10: fd:  15: cpuset
2020-11-20T14:34:34Z lxd.daemon[1734]:  11: fd:  16: freezer
2020-11-20T14:34:34Z lxd.daemon[1734]:  12: fd:  17: hugetlb
2020-11-20T14:34:34Z lxd.daemon[1734]: Kernel supports pidfds
2020-11-20T14:34:34Z lxd.daemon[1734]: Kernel does not support swap accounting
2020-11-20T14:34:34Z lxd.daemon[1734]: api_extensions:
2020-11-20T14:34:34Z lxd.daemon[1734]: - cgroups
2020-11-20T14:34:34Z lxd.daemon[1734]: - sys_cpu_online
2020-11-20T14:34:34Z lxd.daemon[1734]: - proc_cpuinfo
2020-11-20T14:34:34Z lxd.daemon[1734]: - proc_diskstats
2020-11-20T14:34:34Z lxd.daemon[1734]: - proc_loadavg
2020-11-20T14:34:34Z lxd.daemon[1734]: - proc_meminfo
2020-11-20T14:34:34Z lxd.daemon[1734]: - proc_stat
2020-11-20T14:34:34Z lxd.daemon[1734]: - proc_swaps
2020-11-20T14:34:34Z lxd.daemon[1734]: - proc_uptime
2020-11-20T14:34:34Z lxd.daemon[1734]: - shared_pidns
2020-11-20T14:34:34Z lxd.daemon[1734]: - cpuview_daemon
2020-11-20T14:34:34Z lxd.daemon[1734]: - loadavg_daemon
2020-11-20T14:34:34Z lxd.daemon[1734]: - pidfds
2020-11-20T14:34:36Z lxd.daemon[1328]: => Starting LXD
2020-11-20T14:34:36Z lxd.daemon[2035]: t=2020-11-20T09:34:36-0500 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, disk priority will be ignored"
2020-11-20T14:34:36Z lxd.daemon[2035]: t=2020-11-20T09:34:36-0500 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
2020-11-20T14:34:40Z lxd.daemon[2035]: t=2020-11-20T09:34:40-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk1/root.img\" as backing filesystem is \"btrfs\""
2020-11-20T14:34:40Z lxd.daemon[2035]: t=2020-11-20T09:34:40-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk2/root.img\" as backing filesystem is \"btrfs\""
2020-11-20T14:34:40Z lxd.daemon[2035]: t=2020-11-20T09:34:40-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk3/root.img\" as backing filesystem is \"btrfs\""
2020-11-20T14:34:40Z lxd.daemon[2035]: t=2020-11-20T09:34:40-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/virtual-machines/blkcaptdev/root.img\" as backing filesystem is \"btrfs\""
2020-11-20T14:34:41Z lxd.daemon[1328]: => LXD is ready
2020-11-22T18:17:22Z lxd.daemon[2035]: t=2020-11-22T13:17:22-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk1/root.img\" as backing filesystem is \"btrfs\""
2020-11-22T18:17:22Z lxd.daemon[2035]: t=2020-11-22T13:17:22-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk2/root.img\" as backing filesystem is \"btrfs\""
2020-11-22T18:17:22Z lxd.daemon[2035]: t=2020-11-22T13:17:22-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk3/root.img\" as backing filesystem is \"btrfs\""
2020-11-22T18:17:22Z lxd.daemon[2035]: t=2020-11-22T13:17:22-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/virtual-machines/blkcaptdev/root.img\" as backing filesystem is \"btrfs\""
2020-11-22T18:21:06Z lxd.daemon[2035]: t=2020-11-22T13:21:06-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk1/root.img\" as backing filesystem is \"btrfs\""
2020-11-22T18:21:06Z lxd.daemon[2035]: t=2020-11-22T13:21:06-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk2/root.img\" as backing filesystem is \"btrfs\""
2020-11-22T18:21:06Z lxd.daemon[2035]: t=2020-11-22T13:21:06-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/custom/default_blkcaptdev-disk3/root.img\" as backing filesystem is \"btrfs\""
2020-11-22T18:21:06Z lxd.daemon[2035]: t=2020-11-22T13:21:06-0500 lvl=warn msg="Using writeback cache I/O with \"/var/snap/lxd/common/lxd/storage-pools/default/virtual-machines/blkcaptdev/root.img\" as backing filesystem is \"btrfs\""
2020-11-25T15:39:40Z systemd[1]: Stopping Service for snap application lxd.daemon...
2020-11-25T15:39:40Z lxd.daemon[519681]: => Stop reason is: snap refresh
2020-11-25T15:39:40Z lxd.daemon[519681]: => Stopping LXD
2020-11-25T15:39:42Z lxd.daemon[1328]: => LXD exited cleanly
2020-11-25T15:39:42Z lxd.daemon[519681]: ==> Stopped LXD
2020-11-25T15:39:42Z systemd[1]: snap.lxd.daemon.service: Succeeded.
2020-11-25T15:39:42Z systemd[1]: Stopped Service for snap application lxd.daemon.
2020-11-25T15:39:45Z systemd[1]: Started Service for snap application lxd.daemon.
2020-11-25T15:39:45Z lxd.daemon[519881]: => Preparing the system (18402)
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Loading snap configuration
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Setting up mntns symlink (mnt:[4026533025])
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Setting up kmod wrapper
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Preparing /boot
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Preparing a clean copy of /run
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Preparing /run/bin
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Preparing a clean copy of /etc
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Preparing a clean copy of /usr/share/misc
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Setting up ceph configuration
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Setting up LVM configuration
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Rotating logs
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Setting up ZFS (0.8)
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Escaping the systemd cgroups
2020-11-25T15:39:45Z lxd.daemon[519881]: ====> Detected cgroup V1
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Escaping the systemd process resource limits
2020-11-25T15:39:45Z lxd.daemon[519881]: ==> Disabling shiftfs on this kernel (auto)
2020-11-25T15:39:45Z lxd.daemon[519881]: => Re-using existing LXCFS
2020-11-25T15:39:45Z lxd.daemon[519881]: => Starting LXD
2020-11-25T15:39:45Z lxd.daemon[520000]: t=2020-11-25T10:39:45-0500 lvl=warn msg=" - Couldn't find the CGroup blkio.weight, disk priority will be ignored"
2020-11-25T15:39:45Z lxd.daemon[520000]: t=2020-11-25T10:39:45-0500 lvl=warn msg=" - Couldn't find the CGroup memory swap accounting, swap limits will be ignored"
2020-11-25T16:19:45Z lxd.daemon[1734]: Closed liblxcfs.so
2020-11-25T16:19:45Z lxd.daemon[1734]: Running destructor lxcfs_exit
2020-11-25T16:19:45Z lxd.daemon[1734]: Running constructor lxcfs_init to reload liblxcfs
2020-11-25T16:19:45Z lxd.daemon[1734]: mount namespace: 5
2020-11-25T16:19:45Z lxd.daemon[1734]: hierarchies:
2020-11-25T16:19:45Z lxd.daemon[1734]:   0: fd:   6:
2020-11-25T16:19:45Z lxd.daemon[1734]:   1: fd:   7: name=systemd
2020-11-25T16:19:45Z lxd.daemon[1734]:   2: fd:   8: cpu,cpuacct
2020-11-25T16:19:45Z lxd.daemon[1734]:   3: fd:   9: rdma
2020-11-25T16:19:45Z lxd.daemon[1734]:   4: fd:  10: pids
2020-11-25T16:19:45Z lxd.daemon[1734]:   5: fd:  11: blkio
2020-11-25T16:19:45Z lxd.daemon[1734]:   6: fd:  12: net_cls,net_prio
2020-11-25T16:19:45Z lxd.daemon[1734]:   7: fd:  13: memory
2020-11-25T16:19:45Z lxd.daemon[1734]:   8: fd:  14: devices
2020-11-25T16:19:45Z lxd.daemon[1734]:   9: fd:  15: perf_event
2020-11-25T16:19:45Z lxd.daemon[1734]:  10: fd:  16: cpuset
2020-11-25T16:19:45Z lxd.daemon[1734]:  11: fd:  17: freezer
2020-11-25T16:19:45Z lxd.daemon[1734]:  12: fd:  19: hugetlb
2020-11-25T16:19:45Z lxd.daemon[1734]: Kernel supports pidfds
2020-11-25T16:19:45Z lxd.daemon[1734]: Kernel does not support swap accounting
2020-11-25T16:19:45Z lxd.daemon[1734]: api_extensions:
2020-11-25T16:19:45Z lxd.daemon[1734]: - cgroups
2020-11-25T16:19:45Z lxd.daemon[1734]: - sys_cpu_online
2020-11-25T16:19:45Z lxd.daemon[1734]: - proc_cpuinfo
2020-11-25T16:19:45Z lxd.daemon[1734]: - proc_diskstats
2020-11-25T16:19:45Z lxd.daemon[1734]: - proc_loadavg
2020-11-25T16:19:45Z lxd.daemon[1734]: - proc_meminfo
2020-11-25T16:19:45Z lxd.daemon[1734]: - proc_stat
2020-11-25T16:19:45Z lxd.daemon[1734]: - proc_swaps
2020-11-25T16:19:45Z lxd.daemon[1734]: - proc_uptime
2020-11-25T16:19:45Z lxd.daemon[1734]: - shared_pidns
2020-11-25T16:19:45Z lxd.daemon[1734]: - cpuview_daemon
2020-11-25T16:19:45Z lxd.daemon[1734]: - loadavg_daemon
2020-11-25T16:19:45Z lxd.daemon[1734]: - pidfds
2020-11-25T16:19:45Z lxd.daemon[1734]: Reloaded LXCFS

All the past 2 hours snapd has been hitting my disk:

Total DISK READ:         0.00 B/s | Total DISK WRITE:         4.75 M/s
Current DISK READ:       0.00 B/s | Current DISK WRITE:       4.28 M/s
    TID  PRIO  USER     DISK READ  DISK WRITE  SWAPIN     IO>    COMMAND
   1278 be/4 root        0.00 B/s    2.03 M/s  0.00 %  9.04 % snapd
   1245 be/4 root        0.00 B/s  623.29 K/s  0.00 %  2.80 % snapd
   1267 be/4 root        0.00 B/s  623.29 K/s  0.00 %  2.60 % snapd
   1136 be/4 root        0.00 B/s  415.53 K/s  0.00 %  1.82 % snapd
 520569 be/4 root        0.00 B/s  415.53 K/s  0.00 %  1.81 % snapd
   1298 be/4 root        0.00 B/s  415.53 K/s  0.00 %  1.78 % snapd
 542840 be/4 will        0.00 B/s   25.18 K/s  0.00 %  0.52 % chrome --password-store=basic --profile-directory=Default [ThreadPoolForeg]

➜ sudo fatrace
Failed to add watch for fuse mount /run/user/1000/doc: Permission denied
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): RCO /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): RCO /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/state.json.xXpbGhyCDm6V~
snapd(1085): W /var/lib/snapd/state.json.xXpbGhyCDm6V~
snapd(1085): O /var/lib/snapd
snapd(1085): CW /var/lib/snapd/state.json.xXpbGhyCDm6V~
snapd(1085): C /var/lib/snapd
snapd(1085): O /var/lib/snapd/state.json.lTK8TMnnGDtb~
snapd(1085): W /var/lib/snapd/state.json.lTK8TMnnGDtb~
snapd(1085): O /var/lib/snapd
snapd(1085): CW /var/lib/snapd/state.json.lTK8TMnnGDtb~
snapd(1085): C /var/lib/snapd
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/state.json.cLmnFb2vJwSW~
snapd(1085): W /var/lib/snapd/state.json.cLmnFb2vJwSW~
snapd(1085): O /var/lib/snapd
snapd(1085): CW /var/lib/snapd/state.json.cLmnFb2vJwSW~
snapd(1085): C /var/lib/snapd
snapd(1085): O /var/lib/snapd/state.json.LDr3Kcxpqh7f~
snapd(1085): W /var/lib/snapd/state.json.LDr3Kcxpqh7f~
snapd(1085): O /var/lib/snapd
snapd(1085): CW /var/lib/snapd/state.json.LDr3Kcxpqh7f~
snapd(1085): C /var/lib/snapd
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/model/16/generic/generic-classic
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): R /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): RC /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e/active
snapd(1085): C /var/lib/snapd/assertions/asserts-v0/serial/generic/generic-classic/69d3e787-2f76-4db2-aed9-bf18c2c4e95e
snapd(1085): O /var/lib/snapd/state.json.XjTV151PvGln~
snapd(1085): W /var/lib/snapd/state.json.XjTV151PvGln~
snapd(1085): O /var/lib/snapd
snapd(1085): CW /var/lib/snapd/state.json.XjTV151PvGln~
snapd(1085): C /var/lib/snapd
snapd(1085): O /var/lib/snapd/state.json.dhVk1DrVgPFy~
snapd(1085): W /var/lib/snapd/state.json.dhVk1DrVgPFy~
snapd(1085): O /var/lib/snapd
#2

Does lxc monitor work?

Are you using virtual machines?

#3

lxc monitor hangs indefinitely. Yes I am using VMs. I had a VM and a container running at the time of the snap refresh.

My VM and container have remained accessible, but I can’t manage them with lxc command.

I tried to stop snapd but it failed to stop so the state hasn’t really changed. It looks like the issue in in the lxd.activate service being hung, which is hanging up snapd which doesn’t seem to be able to handle this downstream problem gracefully.

➜ systemctl status snapd.service
● snapd.service - Snap Daemon
     Loaded: loaded (/lib/systemd/system/snapd.service; enabled; vendor preset: enabled)
     Active: failed (Result: timeout) since Wed 2020-11-25 14:49:45 EST; 6min ago
TriggeredBy: ● snapd.socket
    Process: 1085 ExecStart=/usr/lib/snapd/snapd (code=killed, signal=KILL)
   Main PID: 1085 (code=killed, signal=KILL)
      Tasks: 1 (limit: 38362)
     Memory: 1.1G
     CGroup: /system.slice/snapd.service
             └─519811 systemctl start snap.lxd.activate.service

Nov 24 19:00:36 turing snapd[1085]: autorefresh.go:410: auto-refresh: all snaps are up-to-date
Nov 25 10:38:39 turing snapd[1085]: storehelpers.go:551: cannot refresh: snap has no updates available: "barrier", "ch>
Nov 25 14:48:15 turing snapd[1085]: main.go:155: Exiting on terminated signal.
Nov 25 14:48:15 turing systemd[1]: Stopping Snap Daemon...
Nov 25 14:49:45 turing systemd[1]: snapd.service: State 'stop-sigterm' timed out. Killing.
Nov 25 14:49:45 turing systemd[1]: snapd.service: Killing process 1085 (snapd) with signal SIGKILL.
Nov 25 14:49:45 turing systemd[1]: snapd.service: Main process exited, code=killed, status=9/KILL
Nov 25 14:49:45 turing systemd[1]: snapd.service: Failed with result 'timeout'.
Nov 25 14:49:45 turing systemd[1]: Stopped Snap Daemon.
Nov 25 14:49:45 turing systemd[1]: snapd.service: Triggering OnFailure= dependencies.

➜ systemctl status snap.lxd.activate.service
● snap.lxd.activate.service - Service for snap application lxd.activate
     Loaded: loaded (/etc/systemd/system/snap.lxd.activate.service; enabled; vendor preset: enabled)
     Active: activating (start) since Wed 2020-11-25 10:39:44 EST; 4h 17min ago
   Main PID: 519812 (daemon.activate)
      Tasks: 20 (limit: 38362)
     Memory: 56.6M
     CGroup: /system.slice/snap.lxd.activate.service
             ├─519812 /bin/sh /snap/lxd/18402/commands/daemon.activate
             └─519873 lxd activateifneeded

Nov 25 10:39:44 turing systemd[1]: Starting Service for snap application lxd.activate...
Nov 25 10:39:44 turing lxd.activate[519812]: => Starting LXD activation
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Loading snap configuration
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Checking for socket activation support
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Setting LXD socket ownership
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Checking if LXD needs to be activated

 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 Wed 2020-11-25 10:39:45 EST; 4h 18min ago
TriggeredBy: ● snap.lxd.daemon.unix.socket
   Main PID: 519881 (daemon.start)
      Tasks: 0 (limit: 38362)
     Memory: 14.1M
     CGroup: /system.slice/snap.lxd.daemon.service
             ‣ 519881 /bin/sh /snap/lxd/18402/commands/daemon.start

Nov 25 11:19:45 turing lxd.daemon[1734]: - proc_loadavg
Nov 25 11:19:45 turing lxd.daemon[1734]: - proc_meminfo
Nov 25 11:19:45 turing lxd.daemon[1734]: - proc_stat
Nov 25 11:19:45 turing lxd.daemon[1734]: - proc_swaps
Nov 25 11:19:45 turing lxd.daemon[1734]: - proc_uptime
Nov 25 11:19:45 turing lxd.daemon[1734]: - shared_pidns
Nov 25 11:19:45 turing lxd.daemon[1734]: - cpuview_daemon
Nov 25 11:19:45 turing lxd.daemon[1734]: - loadavg_daemon
Nov 25 11:19:45 turing lxd.daemon[1734]: - pidfds
Nov 25 11:19:45 turing lxd.daemon[1734]: Reloaded LXCFS
#4

I’ve seen similar hangs when qemu gets confused, can you try shutting down your VM see if LXD gets unblocked?

1 Like
#5

Wow that did it. As soon as I shutdown the VM lxd.activte crashed.

➜ systemctl status snap.lxd.activate.service
● snap.lxd.activate.service - Service for snap application lxd.activate
     Loaded: loaded (/etc/systemd/system/snap.lxd.activate.service; enabled; vendor preset: enabled)
     Active: inactive (dead) since Wed 2020-11-25 15:01:37 EST; 5min ago
   Main PID: 519812 (code=exited, status=0/SUCCESS)

Nov 20 09:34:32 turing systemd[1]: Starting Service for snap application lxd.activate...
Nov 20 09:34:32 turing lxd.activate[1156]: => Starting LXD activation
Nov 20 09:34:32 turing lxd.activate[1156]: ==> Loading snap configuration
Nov 20 09:34:32 turing lxd.activate[1156]: ==> Checking for socket activation support
Nov 20 09:34:33 turing lxd.activate[1156]: ==> Setting LXD socket ownership
Nov 20 09:34:33 turing lxd.activate[1156]: ==> Checking if LXD needs to be activated
Nov 20 09:34:39 turing systemd[1]: snap.lxd.activate.service: Succeeded.
Nov 20 09:34:39 turing systemd[1]: Finished Service for snap application lxd.activate.
Nov 25 10:39:44 turing systemd[1]: Starting Service for snap application lxd.activate...
Nov 25 10:39:44 turing lxd.activate[519812]: => Starting LXD activation
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Loading snap configuration
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Checking for socket activation support
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Setting LXD socket ownership
Nov 25 10:39:44 turing lxd.activate[519812]: ==> Checking if LXD needs to be activated
Nov 25 15:01:37 turing lxd.activate[519873]: panic: runtime error: invalid memory address or nil pointer dereference
Nov 25 15:01:37 turing lxd.activate[519873]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x9a64b9]
Nov 25 15:01:37 turing lxd.activate[519873]: goroutine 84 [running]:
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*ClusterTx).storagePoolVolumeGetTypeID(0xc0004>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_vol>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).storagePoolVolumeGetTypeID.func1(0xc>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_vol>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).transaction.func1.1(0xc000131980, 0x>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:391 +>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db/query.Transaction(0xc00035add0, 0xc0002e3478, 0>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/query/trans>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).transaction.func1(0x18, 0x18)
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:389 +>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db/query.Retry(0xc0002e3558, 0x20, 0x1489dc0)
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/query/retry>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).retry(0xc00035f280, 0xc0002e3558, 0x>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:404 +>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).transaction(0xc00035f280, 0xc0002e35>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:388 +>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).Transaction(0xc00035f280, 0xc0002e35>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:351 +>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).storagePoolVolumeGetTypeID(0xc00035f>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_vol>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).storagePoolVolumeGetType(0xc00035f28>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_vol>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/db.(*Cluster).GetLocalStoragePoolVolume(...)
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_vol>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/device.(*disk).validateConfig(0xc0002b0910, 0x7f10>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/device/disk.go>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/device.New(0x17ea540, 0xc000214000, 0xc000357860, >
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/device/device_>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).deviceLoad(0xc000214000, >
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drive>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).deviceStop(0xc000214000, >
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drive>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).cleanupDevices(0xc0002140>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drive>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).onStop(0xc000214000, 0x15>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drive>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).getMonitorEventHandler.fu>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drive>
Nov 25 15:01:37 turing lxd.activate[519873]: github.com/lxc/lxd/lxd/instance/drivers/qmp.(*Monitor).run.func2(0xc00048>
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drive>
Nov 25 15:01:37 turing lxd.activate[519873]: created by github.com/lxc/lxd/lxd/instance/drivers/qmp.(*Monitor).run
Nov 25 15:01:37 turing lxd.activate[519873]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drive>
Nov 25 15:01:37 turing lxd.activate[519812]: ====> Activation check failed, forcing activation
Nov 25 15:01:37 turing systemd[1]: snap.lxd.activate.service: Succeeded.
Nov 25 15:01:37 turing systemd[1]: Finished Service for snap application lxd.activate.

● 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 Wed 2020-11-25 10:39:45 EST; 4h 24min ago
TriggeredBy: ● snap.lxd.daemon.unix.socket
   Main PID: 519881 (daemon.start)
      Tasks: 0 (limit: 38362)
     Memory: 13.6M
     CGroup: /system.slice/snap.lxd.daemon.service
             ‣ 519881 /bin/sh /snap/lxd/18402/commands/daemon.start

Nov 25 11:19:45 turing lxd.daemon[1734]: - loadavg_daemon
Nov 25 11:19:45 turing lxd.daemon[1734]: - pidfds
Nov 25 11:19:45 turing lxd.daemon[1734]: Reloaded LXCFS
Nov 25 15:01:37 turing lxd.daemon[520000]: 2020/11/25 15:01:37 http: superfluous response.WriteHeader call from github>
Nov 25 15:01:37 turing lxd.daemon[520000]: 2020/11/25 15:01:37 http: superfluous response.WriteHeader call from github>
Nov 25 15:01:37 turing lxd.daemon[520000]: 2020/11/25 15:01:37 http: superfluous response.WriteHeader call from github>
Nov 25 15:01:37 turing lxd.daemon[520000]: 2020/11/25 15:01:37 http: superfluous response.WriteHeader call from github>
Nov 25 15:01:37 turing lxd.daemon[520000]: 2020/11/25 15:01:37 http: superfluous response.WriteHeader call from github>
Nov 25 15:01:37 turing lxd.daemon[520000]: 2020/11/25 15:01:37 http: superfluous response.WriteHeader call from github>
Nov 25 15:01:38 turing lxd.daemon[519881]: => LXD is ready
#6

This happened again during a refresh today. Shutting down the VMs crashed the check and the refresh completed.

➜ systemctl status snap.lxd.activate.service
● snap.lxd.activate.service - Service for snap application lxd.activate
     Loaded: loaded (/etc/systemd/system/snap.lxd.activate.service; enabled; vendor preset: enabled)
     Active: activating (start) since Sat 2020-12-05 13:04:50 EST; 17min ago
   Main PID: 1510673 (daemon.activate)
      Tasks: 19 (limit: 38362)
     Memory: 55.6M
     CGroup: /system.slice/snap.lxd.activate.service
             ├─1510673 /bin/sh /snap/lxd/18520/commands/daemon.activate
             └─1510727 lxd activateifneeded

Dec 05 13:04:50 turing systemd[1]: Starting Service for snap application lxd.activate...
Dec 05 13:04:50 turing lxd.activate[1510673]: => Starting LXD activation
Dec 05 13:04:50 turing lxd.activate[1510673]: ==> Loading snap configuration
Dec 05 13:04:50 turing lxd.activate[1510673]: ==> Checking for socket activation support
Dec 05 13:04:51 turing lxd.activate[1510673]: ==> Setting LXD socket ownership
Dec 05 13:04:51 turing lxd.activate[1510673]: ==> Checking if LXD needs to be activated

Dec 05 13:04:50 turing lxd.activate[1510673]: => Starting LXD activation
Dec 05 13:04:50 turing lxd.activate[1510673]: ==> Loading snap configuration
Dec 05 13:04:50 turing lxd.activate[1510673]: ==> Checking for socket activation support
Dec 05 13:04:51 turing lxd.activate[1510673]: ==> Setting LXD socket ownership
Dec 05 13:04:51 turing lxd.activate[1510673]: ==> Checking if LXD needs to be activated
Dec 05 13:24:10 turing lxd.activate[1510727]: panic: runtime error: invalid memory address or nil pointer dereference
Dec 05 13:24:10 turing lxd.activate[1510727]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x9a6639]
Dec 05 13:24:10 turing lxd.activate[1510727]: goroutine 604 [running]:
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*ClusterTx).storagePoolVolumeGetTypeID(0xc0004d6ea0, 0xc0004cf1d0, 0x7, 0xc0003ad9b0, 0x10, 0x2, 0x1, 0x0, 0x0, 0xc000494001, ...)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_volumes.go:528 +0x39
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).storagePoolVolumeGetTypeID.func1(0xc0004d6ea0, 0xc000121d00, 0x0)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_volumes.go:518 +0x77
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).transaction.func1.1(0xc000121d00, 0x17c2d60, 0xc000034078)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:391 +0x42
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db/query.Transaction(0xc000494000, 0xc0007b3578, 0xc0004d6ea0, 0x20)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/query/transaction.go:23 +0x173
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).transaction.func1(0x18, 0x18)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:389 +0x66
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db/query.Retry(0xc0007b3658, 0x20, 0x148c300)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/query/retry.go:26 +0xdb
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).retry(0xc0002fb000, 0xc0007b3658, 0x1, 0xc0007b3688)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:404 +0x9d
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).transaction(0xc0002fb000, 0xc0007b36f8, 0xc0002fb000, 0xc0007b36b8)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:388 +0x94
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).Transaction(0xc0002fb000, 0xc0007b36f8, 0x0, 0x0)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/db.go:351 +0x78
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).storagePoolVolumeGetTypeID(0xc0002fb000, 0xc0004cf1d0, 0x7, 0xc0003ad9b0, 0x10, 0x2, 0x1, 0x0, 0xc0007b3810, 0xbc5865, ...)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_volumes.go:516 +0xd6
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).storagePoolVolumeGetType(0xc0002fb000, 0xc0004cf1d0, 0x7, 0xc0003ad9b0, 0x10, 0x2, 0x1, 0x0, 0x10, 0x7f9a7f9ba218, ...)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_volumes.go:278 +0xe5
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/db.(*Cluster).GetLocalStoragePoolVolume(...)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/db/storage_volumes.go:337
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/device.(*disk).validateConfig(0xc00013eaa0, 0x7f9a54117ed8, 0xc000214000, 0x7f9a54117ed8, 0xc000214000)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/device/disk.go:186 +0x1376
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/device.New(0x17ed140, 0xc000214000, 0xc0004981e0, 0xc0003ad890, 0x10, 0xc000232b40, 0xc0004d6960, 0xc0004d6980, 0x3, 0xc0007b3be0, ...)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/device/device_load.go:99 +0x17d
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).deviceLoad(0xc000214000, 0xc0003ad890, 0x10, 0xc0000b1e90, 0x0, 0x0, 0xc0002be1b0, 0x0, 0x0)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drivers/driver_qemu.go:1258 +0x1fb
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).deviceStop(0xc000214000, 0xc0003ad890, 0x10, 0xc0000b1e90, 0x0, 0x0, 0x0)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drivers/driver_qemu.go:1291 +0x337
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).cleanupDevices(0xc000214000)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drivers/driver_qemu.go:3514 +0xb5
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).onStop(0xc000214000, 0x15884cb, 0x4, 0x6, 0xc0004da998)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drivers/driver_qemu.go:509 +0x96
Dec 05 13:24:10 turing lxd.activate[1510727]: github.com/lxc/lxd/lxd/instance/drivers.(*qemu).getMonitorEventHandler.func1(0xc00021e5c0, 0x8, 0xc000254d50)
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drivers/driver_qemu.go:372 +0x245
Dec 05 13:24:10 turing lxd.activate[1510727]: created by github.com/lxc/lxd/lxd/instance/drivers/qmp.(*Monitor).run.func2
Dec 05 13:24:10 turing lxd.activate[1510727]:         /build/lxd/parts/lxd/go/src/github.com/lxc/lxd/lxd/instance/drivers/qmp/monitor.go:134 +0x1e8
Dec 05 13:24:10 turing lxd.activate[1510673]: ====> Activation check failed, forcing activation
Dec 05 13:24:10 turing systemd[1]: snap.lxd.activate.service: Succeeded.
Dec 05 13:24:10 turing systemd[1]: Finished Service for snap application lxd.activate.