Snapd pegged cpu, updates never completing on core

snapd
1

I woke a machine up today which has been off for a few weeks. It did a bunch of updates and restarted a couple of times and now I have snapd consuming lots of CPU and lxd snap never finishes.

This is the change which seems wedged. Is this a lxd problem (tagging @stgraber) or snapd? I can’t remove lxd or get this to finish (it’s been a couple of hours).

Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "lxd" snap if present
Doing   today at 16:07 UTC  -                   Start snap "lxd" (11824) services
Do      today at 16:07 UTC  -                   Remove data for snap "lxd" (11405)
Do      today at 16:07 UTC  -                   Remove snap "lxd" (11405) from the system
Do      today at 16:07 UTC  -                   Clean up "lxd" (11824) install
Do      today at 16:07 UTC  -                   Run configure hook of "lxd" snap if present

popey@localhost:~$ snap remove lxd
error: snap "lxd" has "auto-refresh" change in progress

popey@localhost:~$ snap version
snap    2.41
snapd   2.41
series  16
kernel  4.4.0-161-generic

popey@localhost:~$ snap changes
ID   Status  Spawn               Ready               Summary
391  Doing   today at 16:07 UTC  -                   Auto-refresh 10 snaps

popey@localhost:~$ snap change 391
Status  Spawn               Ready               Summary
Done    today at 16:07 UTC  today at 16:07 UTC  Ensure prerequisites for "core" are available
Done    today at 16:07 UTC  today at 16:08 UTC  Download snap "core" (7713) from channel "stable"
Done    today at 16:07 UTC  today at 16:08 UTC  Fetch and check assertions for snap "core" (7713)
Done    today at 16:07 UTC  today at 16:08 UTC  Mount snap "core" (7713)
Done    today at 16:07 UTC  today at 16:08 UTC  Run pre-refresh hook of "core" snap if present
Done    today at 16:07 UTC  today at 16:08 UTC  Stop snap "core" services
Done    today at 16:07 UTC  today at 16:08 UTC  Remove aliases for snap "core"
Done    today at 16:07 UTC  today at 16:08 UTC  Make current revision for snap "core" unavailable
Done    today at 16:07 UTC  today at 16:08 UTC  Copy snap "core" data
Done    today at 16:07 UTC  today at 16:08 UTC  Setup snap "core" (7713) security profiles
Done    today at 16:07 UTC  today at 16:08 UTC  Make snap "core" (7713) available to the system
Done    today at 16:07 UTC  today at 16:11 UTC  Automatically connect eligible plugs and slots of snap "core"
Done    today at 16:07 UTC  today at 16:11 UTC  Set automatic aliases for snap "core"
Done    today at 16:07 UTC  today at 16:11 UTC  Setup snap "core" aliases
Done    today at 16:07 UTC  today at 16:11 UTC  Run post-refresh hook of "core" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Start snap "core" (7713) services
Done    today at 16:07 UTC  today at 16:11 UTC  Remove data for snap "core" (6964)
Done    today at 16:07 UTC  today at 16:11 UTC  Remove snap "core" (6964) from the system
Done    today at 16:07 UTC  today at 16:11 UTC  Clean up "core" (7713) install
Done    today at 16:07 UTC  today at 16:11 UTC  Run configure hook of "core" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "pc-kernel" are available
Done    today at 16:07 UTC  today at 16:12 UTC  Download snap "pc-kernel" (286) from channel "stable"
Done    today at 16:07 UTC  today at 16:12 UTC  Fetch and check assertions for snap "pc-kernel" (286)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "pc-kernel" (286)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "pc-kernel" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "pc-kernel" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "pc-kernel"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "pc-kernel" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "pc-kernel" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "pc-kernel" (286) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "pc-kernel" (286) available to the system
Done    today at 16:07 UTC  today at 16:28 UTC  Automatically connect eligible plugs and slots of snap "pc-kernel"
Done    today at 16:07 UTC  today at 16:28 UTC  Set automatic aliases for snap "pc-kernel"
Done    today at 16:07 UTC  today at 16:28 UTC  Setup snap "pc-kernel" aliases
Done    today at 16:07 UTC  today at 16:28 UTC  Run post-refresh hook of "pc-kernel" snap if present
Done    today at 16:07 UTC  today at 16:28 UTC  Start snap "pc-kernel" (286) services
Done    today at 16:07 UTC  today at 16:28 UTC  Remove data for snap "pc-kernel" (245)
Done    today at 16:07 UTC  today at 16:28 UTC  Remove snap "pc-kernel" (245) from the system
Done    today at 16:07 UTC  today at 16:28 UTC  Clean up "pc-kernel" (286) install
Done    today at 16:07 UTC  today at 16:28 UTC  Run configure hook of "pc-kernel" snap if present
Done    today at 16:07 UTC  today at 16:07 UTC  Ensure prerequisites for "core18" are available
Done    today at 16:07 UTC  today at 16:07 UTC  Download snap "core18" (1098) from channel "stable"
Done    today at 16:07 UTC  today at 16:07 UTC  Fetch and check assertions for snap "core18" (1098)
Done    today at 16:07 UTC  today at 16:08 UTC  Mount snap "core18" (1098)
Done    today at 16:07 UTC  today at 16:08 UTC  Run pre-refresh hook of "core18" snap if present
Done    today at 16:07 UTC  today at 16:08 UTC  Stop snap "core18" services
Done    today at 16:07 UTC  today at 16:08 UTC  Remove aliases for snap "core18"
Done    today at 16:07 UTC  today at 16:08 UTC  Make current revision for snap "core18" unavailable
Done    today at 16:07 UTC  today at 16:08 UTC  Copy snap "core18" data
Done    today at 16:07 UTC  today at 16:08 UTC  Setup snap "core18" (1098) security profiles
Done    today at 16:07 UTC  today at 16:08 UTC  Make snap "core18" (1098) available to the system
Done    today at 16:07 UTC  today at 16:08 UTC  Automatically connect eligible plugs and slots of snap "core18"
Done    today at 16:07 UTC  today at 16:08 UTC  Set automatic aliases for snap "core18"
Done    today at 16:07 UTC  today at 16:08 UTC  Setup snap "core18" aliases
Done    today at 16:07 UTC  today at 16:08 UTC  Run post-refresh hook of "core18" snap if present
Done    today at 16:07 UTC  today at 16:08 UTC  Start snap "core18" (1098) services
Done    today at 16:07 UTC  today at 16:08 UTC  Remove data for snap "core18" (1049)
Done    today at 16:07 UTC  today at 16:08 UTC  Remove snap "core18" (1049) from the system
Done    today at 16:07 UTC  today at 16:08 UTC  Clean up "core18" (1098) install
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "tizonia" are available
Done    today at 16:07 UTC  today at 16:11 UTC  Download snap "tizonia" (287) from channel "stable"
Done    today at 16:07 UTC  today at 16:11 UTC  Fetch and check assertions for snap "tizonia" (287)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "tizonia" (287)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "tizonia" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "tizonia" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "tizonia"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "tizonia" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "tizonia" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "tizonia" (287) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "tizonia" (287) available to the system
Done    today at 16:07 UTC  today at 16:12 UTC  Automatically connect eligible plugs and slots of snap "tizonia"
Done    today at 16:07 UTC  today at 16:12 UTC  Set automatic aliases for snap "tizonia"
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "tizonia" aliases
Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "tizonia" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Start snap "tizonia" (287) services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove data for snap "tizonia" (273)
Done    today at 16:07 UTC  today at 16:12 UTC  Remove snap "tizonia" (273) from the system
Done    today at 16:07 UTC  today at 16:12 UTC  Clean up "tizonia" (287) install
Done    today at 16:07 UTC  today at 16:12 UTC  Run configure hook of "tizonia" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "lxd" are available
Done    today at 16:07 UTC  today at 16:12 UTC  Download snap "lxd" (11824) from channel "stable"
Done    today at 16:07 UTC  today at 16:12 UTC  Fetch and check assertions for snap "lxd" (11824)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "lxd" (11824)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "lxd" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "lxd" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "lxd"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "lxd" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "lxd" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "lxd" (11824) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "lxd" (11824) available to the system
Done    today at 16:07 UTC  today at 16:12 UTC  Automatically connect eligible plugs and slots of snap "lxd"
Done    today at 16:07 UTC  today at 16:12 UTC  Set automatic aliases for snap "lxd"
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "lxd" aliases
Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "lxd" snap if present
Doing   today at 16:07 UTC  -                   Start snap "lxd" (11824) services
Do      today at 16:07 UTC  -                   Remove data for snap "lxd" (11405)
Do      today at 16:07 UTC  -                   Remove snap "lxd" (11405) from the system
Do      today at 16:07 UTC  -                   Clean up "lxd" (11824) install
Do      today at 16:07 UTC  -                   Run configure hook of "lxd" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "get-iplayer" are available
Done    today at 16:07 UTC  today at 16:11 UTC  Download snap "get-iplayer" (152) from channel "stable"
Done    today at 16:07 UTC  today at 16:12 UTC  Fetch and check assertions for snap "get-iplayer" (152)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "get-iplayer" (152)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "get-iplayer" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "get-iplayer" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "get-iplayer"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "get-iplayer" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "get-iplayer" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "get-iplayer" (152) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "get-iplayer" (152) available to the system
Done    today at 16:07 UTC  today at 16:12 UTC  Automatically connect eligible plugs and slots of snap "get-iplayer"
Done    today at 16:07 UTC  today at 16:12 UTC  Set automatic aliases for snap "get-iplayer"
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "get-iplayer" aliases
Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "get-iplayer" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Start snap "get-iplayer" (152) services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove data for snap "get-iplayer" (125)
Done    today at 16:07 UTC  today at 16:12 UTC  Remove snap "get-iplayer" (125) from the system
Done    today at 16:07 UTC  today at 16:12 UTC  Clean up "get-iplayer" (152) install
Done    today at 16:07 UTC  today at 16:12 UTC  Run configure hook of "get-iplayer" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "irssi" are available
Done    today at 16:07 UTC  today at 16:12 UTC  Download snap "irssi" (638) from channel "edge"
Done    today at 16:07 UTC  today at 16:12 UTC  Fetch and check assertions for snap "irssi" (638)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "irssi" (638)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "irssi" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "irssi" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "irssi"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "irssi" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "irssi" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "irssi" (638) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "irssi" (638) available to the system
Done    today at 16:07 UTC  today at 16:12 UTC  Automatically connect eligible plugs and slots of snap "irssi"
Done    today at 16:07 UTC  today at 16:12 UTC  Set automatic aliases for snap "irssi"
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "irssi" aliases
Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "irssi" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Start snap "irssi" (638) services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove data for snap "irssi" (535)
Done    today at 16:07 UTC  today at 16:12 UTC  Remove snap "irssi" (535) from the system
Done    today at 16:07 UTC  today at 16:12 UTC  Clean up "irssi" (638) install
Done    today at 16:07 UTC  today at 16:12 UTC  Run configure hook of "irssi" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "offlineimap" are available
Done    today at 16:07 UTC  today at 16:12 UTC  Download snap "offlineimap" (210) from channel "stable"
Done    today at 16:07 UTC  today at 16:12 UTC  Fetch and check assertions for snap "offlineimap" (210)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "offlineimap" (210)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "offlineimap" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "offlineimap" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "offlineimap"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "offlineimap" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "offlineimap" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "offlineimap" (210) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "offlineimap" (210) available to the system
Done    today at 16:07 UTC  today at 16:12 UTC  Automatically connect eligible plugs and slots of snap "offlineimap"
Done    today at 16:07 UTC  today at 16:12 UTC  Set automatic aliases for snap "offlineimap"
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "offlineimap" aliases
Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "offlineimap" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Start snap "offlineimap" (210) services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove data for snap "offlineimap" (181)
Done    today at 16:07 UTC  today at 16:12 UTC  Remove snap "offlineimap" (181) from the system
Done    today at 16:07 UTC  today at 16:12 UTC  Clean up "offlineimap" (210) install
Done    today at 16:07 UTC  today at 16:12 UTC  Run configure hook of "offlineimap" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "nethack" are available
Done    today at 16:07 UTC  today at 16:12 UTC  Download snap "nethack" (79) from channel "stable"
Done    today at 16:07 UTC  today at 16:12 UTC  Fetch and check assertions for snap "nethack" (79)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "nethack" (79)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "nethack" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "nethack" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "nethack"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "nethack" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "nethack" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "nethack" (79) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "nethack" (79) available to the system
Done    today at 16:07 UTC  today at 16:12 UTC  Automatically connect eligible plugs and slots of snap "nethack"
Done    today at 16:07 UTC  today at 16:12 UTC  Set automatic aliases for snap "nethack"
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "nethack" aliases
Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "nethack" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Start snap "nethack" (79) services
Done    today at 16:07 UTC  today at 16:12 UTC  Clean up "nethack" (79) install
Done    today at 16:07 UTC  today at 16:12 UTC  Run configure hook of "nethack" snap if present
Done    today at 16:07 UTC  today at 16:11 UTC  Ensure prerequisites for "ascii-patrol" are available
Done    today at 16:07 UTC  today at 16:11 UTC  Download snap "ascii-patrol" (70) from channel "stable"
Done    today at 16:07 UTC  today at 16:12 UTC  Fetch and check assertions for snap "ascii-patrol" (70)
Done    today at 16:07 UTC  today at 16:12 UTC  Mount snap "ascii-patrol" (70)
Done    today at 16:07 UTC  today at 16:12 UTC  Run pre-refresh hook of "ascii-patrol" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Stop snap "ascii-patrol" services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove aliases for snap "ascii-patrol"
Done    today at 16:07 UTC  today at 16:12 UTC  Make current revision for snap "ascii-patrol" unavailable
Done    today at 16:07 UTC  today at 16:12 UTC  Copy snap "ascii-patrol" data
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "ascii-patrol" (70) security profiles
Done    today at 16:07 UTC  today at 16:12 UTC  Make snap "ascii-patrol" (70) available to the system
Done    today at 16:07 UTC  today at 16:12 UTC  Automatically connect eligible plugs and slots of snap "ascii-patrol"
Done    today at 16:07 UTC  today at 16:12 UTC  Set automatic aliases for snap "ascii-patrol"
Done    today at 16:07 UTC  today at 16:12 UTC  Setup snap "ascii-patrol" aliases
Done    today at 16:07 UTC  today at 16:12 UTC  Run post-refresh hook of "ascii-patrol" snap if present
Done    today at 16:07 UTC  today at 16:12 UTC  Start snap "ascii-patrol" (70) services
Done    today at 16:07 UTC  today at 16:12 UTC  Remove data for snap "ascii-patrol" (39)
Done    today at 16:07 UTC  today at 16:12 UTC  Remove snap "ascii-patrol" (39) from the system
Done    today at 16:07 UTC  today at 16:12 UTC  Clean up "ascii-patrol" (70) install
Done    today at 16:07 UTC  today at 16:12 UTC  Run configure hook of "ascii-patrol" snap if present
Doing   today at 16:07 UTC  -                   Consider re-refresh of "pc-kernel", "tizonia", "lxd", "get-iplayer", "offlineimap", "nethack", "ascii-patrol", "core", "core18", "irssi"

......................................................................
Make snap "core" (7713) available to the system

2019-09-10T16:08:10Z INFO Requested system restart.

......................................................................
Automatically connect eligible plugs and slots of snap "core"

2019-09-10T16:08:12Z INFO Waiting for restart...
2019-09-10T16:08:12Z INFO Waiting for restart...
2019-09-10T16:08:12Z INFO Waiting for restart...
2019-09-10T16:08:13Z INFO Waiting for restart...
2019-09-10T16:08:13Z INFO Waiting for restart...
2019-09-10T16:08:13Z INFO Waiting for restart...
2019-09-10T16:08:13Z INFO Waiting for restart...
2019-09-10T16:08:13Z INFO Waiting for restart...
2019-09-10T16:08:13Z INFO Waiting for restart...
2019-09-10T16:08:13Z INFO Waiting for restart...

......................................................................
Make snap "pc-kernel" (286) available to the system

2019-09-10T16:12:42Z INFO Requested system restart.

......................................................................
Automatically connect eligible plugs and slots of snap "pc-kernel"

2019-09-10T16:12:44Z INFO Waiting for restart...
2019-09-10T16:12:44Z INFO Waiting for restart...
2019-09-10T16:12:44Z INFO Waiting for restart...
2019-09-10T16:12:44Z INFO Waiting for restart...
2019-09-10T16:12:44Z INFO Waiting for restart...
2019-09-10T16:12:44Z INFO Waiting for restart...
2019-09-10T16:12:44Z INFO Waiting for restart...
2019-09-10T16:12:45Z INFO Waiting for restart...
2019-09-10T16:12:45Z INFO Waiting for restart...
2019-09-10T16:12:45Z INFO Waiting for restart...

I tried to abort

popey@localhost:~$ snap abort 391
popey@localhost:~$ snap changes
ID   Status  Spawn               Ready               Summary
391  Abort   today at 16:07 UTC  -                   Auto-refresh 10 snaps

Which triggered a reboot. When it came back, it got back in the same state…

Doing   today at 19:02 UTC  -                   Start snap "lxd" (11824) services
Do      today at 19:02 UTC  -                   Remove data for snap "lxd" (11405)
Do      today at 19:02 UTC  -                   Remove snap "lxd" (11405) from the system
Do      today at 19:02 UTC  -                   Clean up "lxd" (11824) install
Do      today at 19:02 UTC  -                   Run configure hook of "lxd" snap if present

How do I unwedge this?

2

What is snap services lxd show? It’s possible that the lxd snap service is stuck, but even then I think there is supposed to be a start-timeout that should kill it if it takes too long

3 
popey@localhost:~$ snap services lxd
Service       Startup  Current   Notes
lxd.activate  enabled  inactive  -
lxd.daemon    enabled  active    socket-activated
4

Is there anything interesting in the logs for the lxd snap’s services? i.e. journalctl -e --no-pager -u snap.lxd.*

Also what does systemd think about the lxd snap’s service states? i.e. systemctl status snap.lxd.*

5 
-- Logs begin at Tue 2019-09-10 19:22:43 UTC, end at Tue 2019-09-10 20:36:11 UTC. --
Sep 10 19:22:49 localhost.localdomain systemd[1]: Listening on Socket unix for snap application lxd.daemon.
Sep 10 19:22:49 localhost.localdomain systemd[1]: Starting Service for snap application lxd.activate...
Sep 10 19:22:51 localhost.localdomain lxd.activate[1916]: => Starting LXD activation
Sep 10 19:22:51 localhost.localdomain lxd.activate[1916]: ==> Loading snap configuration
Sep 10 19:22:51 localhost.localdomain lxd.activate[1916]: ==> Checking for socket activation support
Sep 10 19:22:51 localhost.localdomain lxd.activate[1916]: ==> Setting LXD socket ownership
Sep 10 19:22:51 localhost.localdomain lxd.activate[1916]: ==> Checking if LXD needs to be activated
Sep 10 19:22:53 localhost.localdomain systemd[1]: Started Service for snap application lxd.daemon.
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: => Preparing the system
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ==> Loading snap configuration
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ==> Setting up mntns symlink (mnt:[4026532300])
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ==> Setting up persistent shmounts path
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ====> Making LXD shmounts use the persistent path
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ====> Making LXCFS use the persistent path
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ==> Setting up kmod wrapper
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ==> Preparing /boot
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ==> Preparing a clean copy of /run
Sep 10 19:22:54 localhost.localdomain lxd.daemon[2343]: ==> Preparing a clean copy of /etc
Sep 10 19:22:55 localhost.localdomain systemd[1]: Listening on Socket unix for snap application lxd.daemon.
Sep 10 19:22:55 localhost.localdomain lxd.daemon[2343]: ==> Setting up ceph configuration
Sep 10 19:22:55 localhost.localdomain lxd.daemon[2343]: ==> Setting up LVM configuration
Sep 10 19:22:55 localhost.localdomain lxd.daemon[2343]: ==> Rotating logs
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: ==> Setting up ZFS (0.6)
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: ==> Escaping the systemd cgroups
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: ====> Detected cgroup V1
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: ==> Escaping the systemd process resource limits
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: ==> Increasing the number of inotify user instances
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: ==> Disabling shiftfs on this kernel (auto)
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: => Starting LXCFS
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: => Starting LXD
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: mount namespace: 5
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: hierarchies:
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   0: fd:   6: devices
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   1: fd:   7: perf_event
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   2: fd:   8: freezer
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   3: fd:   9: cpu,cpuacct
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   4: fd:  10: hugetlb
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   5: fd:  11: net_cls,net_prio
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   6: fd:  12: pids
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   7: fd:  13: memory
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   8: fd:  14: cpuset
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:   9: fd:  15: blkio
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]:  10: fd:  16: name=systemd
Sep 10 19:22:56 localhost.localdomain lxd.daemon[2343]: t=2019-09-10T19:22:56+0000 lvl=warn msg="CGroup memory swap accounting is disabled, swap limits will be ignored."

popey@localhost:~$ systemctl status snap.lxd.*
● 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 Tue 2019-09-10 19:22:53 UTC; 1h 13min ago
 Main PID: 2343 (daemon.start)
   CGroup: /system.slice/snap.lxd.daemon.service
           ‣ 2343 /bin/sh /snap/lxd/11824/commands/daemon.start

● 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 Tue 2019-09-10 19:22:49 UTC; 1h 13min ago
 Main PID: 1916 (daemon.activate)
   CGroup: /system.slice/snap.lxd.activate.service
           ├─1916 /bin/sh /snap/lxd/11824/commands/daemon.activate
           └─2147 lxd activateifneeded

● 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 Tue 2019-09-10 19:22:49 UTC; 1h 13min ago
   Listen: /var/snap/lxd/common/lxd/unix.socket (Stream)
6

This looks like at least partially an lxd bug because there is no corresponding “done” status for snap.lxd.activate.service, see

Sep 10 19:22:49 localhost.localdomain systemd[1]: Starting Service for snap application lxd.activate...

For example on my machine I normally see this:

Sep 10 15:49:09 systemd[1]: Starting Service for snap application lxd.activate...
Sep 10 15:49:09 lxd.activate[39644]: => Starting LXD activation
Sep 10 15:49:09 lxd.activate[39644]: ==> Loading snap configuration
Sep 10 15:49:09 lxd.activate[39644]: ==> Checking for socket activation support
Sep 10 15:49:09 lxd.activate[39644]: ==> Setting LXD socket ownership
Sep 10 15:49:09 lxd.activate[39644]: ==> Checking if LXD needs to be activated
Sep 10 15:49:10 lxd.activate[39644]: Error: User "root" has no subuids
Sep 10 15:49:10 lxd.activate[39644]: ====> Activation check failed, forcing activation
Sep 10 15:49:10 systemd[1]: snap.lxd.activate.service: Succeeded.
Sep 10 15:49:10 systemd[1]: Started Service for snap application lxd.activate.

and also that the service is still in the activating state as reported by systemd:

   Active: activating (start) since Tue 2019-09-10 19:22:49 UTC; 1h 13min ago

At least why that is stuck is an lxd bug, however there’s also a bug that at some point snapd should have aborted it and moved on.

Now, to unstuck this you should be able to at least kill the systemd service which I think will likely cause snapd to abandon this refresh, or it may put it back into a loop waiting for the same thing again. Try:

sudo systemctl kill snap.lxd.activate.service
7

That did it!

Thanks @ijohnson

1 Like