Comment 2 for bug 1992324

Revision history for this message
James Dingwall (a-james-launchpad) wrote :

This is the snapd.service journal. During this boot I did the 20.04 to 22.04 upgrade so that could be a contributing factor. I suspect the 'cp' process mentioned is `cp 65 66` (https://github.com/snapcore/snapd/blob/3a9aaabe38e2ac4e45cfa9ca1c0c00522ca1d04f/osutil/cp.go#L186 ?). I'll try a rollback on the snap revision and avoid service restarts/reboot and that will probably work.

```
-- Boot a676a11120cc42a4aaf52d69df4f4286 --
Oct 09 20:14:34 hostname systemd[1]: Starting Snap Daemon...
Oct 09 20:14:34 hostname snapd[9546]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:14:35 hostname snapd[9546]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:14:35 hostname snapd[9546]: overlord.go:263: Acquiring state lock file
Oct 09 20:14:35 hostname snapd[9546]: overlord.go:268: Acquired state lock file
Oct 09 20:14:35 hostname snapd[9546]: daemon.go:247: started snapd/2.57.2 (series 16; classic) ubuntu/20.04 (amd64) linux/5.15.0-48-generic.
Oct 09 20:14:35 hostname snapd[9546]: daemon.go:340: adjusting startup timeout by 2m5s (pessimistic estimate of 30s plus 5s per snap)
Oct 09 20:14:35 hostname snapd[9546]: backend.go:135: snapd enabled NFS support, additional implicit network permissions granted
Oct 09 20:14:35 hostname systemd[1]: Started Snap Daemon.
Oct 09 20:24:35 hostname snapd[9546]: devicemgr.go:2000: no NTP sync after 10m0s, trying auto-refresh anyway
Oct 09 20:24:35 hostname snapd[9546]: storehelpers.go:748: cannot refresh: snap has no updates available: "bare", "core", "core18", "core20", "core22", "cups", "discord", "freecad", "gnome-3-28-1804", "gnome-3-34-1804", "gnome-3-38-2004", "gnome-42-2204", "gtk-common-themes", "kde-frameworks-5-91-qt-5-15-3-core20", "micropolis", "skype", "teams", "zoom-client"
Oct 09 20:29:25 hostname snapd[9546]: api_snaps.go:319: Installing snap "firefox" revision unset
Oct 09 20:38:33 hostname snapd[9546]: main.go:155: Exiting on terminated signal.
Oct 09 20:38:33 hostname systemd[1]: Stopping Snap Daemon...
Oct 09 20:40:03 hostname systemd[1]: snapd.service: State 'stop-sigterm' timed out. Killing.
Oct 09 20:40:03 hostname systemd[1]: snapd.service: Killing process 9546 (snapd) with signal SIGKILL.
Oct 09 20:40:03 hostname systemd[1]: snapd.service: Main process exited, code=killed, status=9/KILL
Oct 09 20:40:03 hostname systemd[1]: snapd.service: Failed with result 'timeout'.
Oct 09 20:40:03 hostname systemd[1]: snapd.service: Unit process 141980 (cp) remains running after unit stopped.
Oct 09 20:40:03 hostname systemd[1]: Stopped Snap Daemon.
Oct 09 20:40:03 hostname systemd[1]: snapd.service: Triggering OnFailure= dependencies.
Oct 09 20:40:03 hostname systemd[1]: snapd.service: Found left-over process 141980 (cp) in control group while starting unit. Ignoring.
Oct 09 20:40:03 hostname systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Oct 09 20:40:03 hostname systemd[1]: Starting Snap Daemon...
Oct 09 20:40:03 hostname snapd[600053]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:40:03 hostname snapd[600053]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:40:04 hostname snapd[600053]: overlord.go:263: Acquiring state lock file
Oct 09 20:40:04 hostname snapd[600053]: overlord.go:268: Acquired state lock file
Oct 09 20:40:04 hostname snapd[600053]: daemon.go:247: started snapd/2.57.2 (series 16; classic) ubuntu/22.04 (amd64) linux/5.15.0-48-generic.
Oct 09 20:40:04 hostname snapd[600053]: daemon.go:340: adjusting startup timeout by 2m10s (pessimistic estimate of 30s plus 5s per snap)
Oct 09 20:40:04 hostname snapd[600053]: backend.go:135: snapd enabled NFS support, additional implicit network permissions granted
Oct 09 20:40:06 hostname snapd[600053]: main.go:155: Exiting on terminated signal.
Oct 09 20:41:34 hostname systemd[1]: snapd.service: State 'stop-sigterm' timed out. Killing.
Oct 09 20:41:34 hostname systemd[1]: snapd.service: Killing process 600053 (snapd) with signal SIGKILL.
Oct 09 20:41:34 hostname systemd[1]: snapd.service: Main process exited, code=killed, status=9/KILL
Oct 09 20:41:34 hostname systemd[1]: snapd.service: Failed with result 'timeout'.
Oct 09 20:41:34 hostname systemd[1]: snapd.service: Unit process 600524 (cp) remains running after unit stopped.
Oct 09 20:41:34 hostname systemd[1]: Stopped Snap Daemon.
Oct 09 20:41:34 hostname systemd[1]: snapd.service: Triggering OnFailure= dependencies.
Oct 09 20:41:34 hostname systemd[1]: snapd.service: Found left-over process 600524 (cp) in control group while starting unit. Ignoring.
Oct 09 20:41:34 hostname systemd[1]: This usually indicates unclean termination of a previous run, or service implementation deficiencies.
Oct 09 20:41:34 hostname systemd[1]: Starting Snap Daemon...
Oct 09 20:41:34 hostname snapd[601538]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:41:34 hostname snapd[601538]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:41:34 hostname snapd[601538]: overlord.go:263: Acquiring state lock file
Oct 09 20:41:34 hostname snapd[601538]: overlord.go:268: Acquired state lock file
Oct 09 20:41:34 hostname snapd[601538]: daemon.go:247: started snapd/2.57.2 (series 16; classic) ubuntu/22.04 (amd64) linux/5.15.0-48-generic.
Oct 09 20:41:34 hostname snapd[601538]: daemon.go:340: adjusting startup timeout by 2m10s (pessimistic estimate of 30s plus 5s per snap)
Oct 09 20:41:34 hostname snapd[601538]: backend.go:135: snapd enabled NFS support, additional implicit network permissions granted
Oct 09 20:41:34 hostname systemd[1]: Started Snap Daemon.
Oct 09 20:45:57 hostname snapd[601538]: api_snaps.go:319: Installing snap "firefox" revision unset
Oct 09 20:49:04 hostname snapd[601538]: main.go:155: Exiting on terminated signal.
Oct 09 20:49:04 hostname systemd[1]: Stopping Snap Daemon...
Oct 09 20:50:34 hostname systemd[1]: snapd.service: State 'stop-sigterm' timed out. Killing.
Oct 09 20:50:34 hostname systemd[1]: snapd.service: Killing process 601538 (snapd) with signal SIGKILL.
Oct 09 20:50:34 hostname systemd[1]: snapd.service: Main process exited, code=killed, status=9/KILL
Oct 09 20:50:34 hostname systemd[1]: snapd.service: Failed with result 'timeout'.
Oct 09 20:50:34 hostname systemd[1]: snapd.service: Unit process 628773 (cp) remains running after unit stopped.
Oct 09 20:50:34 hostname systemd[1]: Stopped Snap Daemon.
Oct 09 20:50:34 hostname systemd[1]: snapd.service: Triggering OnFailure= dependencies.
Oct 09 20:50:34 hostname systemd[1]: snapd.service: Failed to enqueue OnFailure= job, ignoring: Transaction for snapd.failure.service/start is destructive (systemd-fsck@dev-disk-by\x2dpartuuid-fa950742\x2d0e92\x2d477d\x2d8594\x2d3fbc2cbe9522.service has 'stop' job queued, but 'start' is included in transaction).
-- Boot 1fcd53924b49473e8878e2c8b389babb --
Oct 09 20:51:22 hostname systemd[1]: Starting Snap Daemon...
Oct 09 20:51:22 hostname snapd[8755]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:51:22 hostname snapd[8755]: AppArmor status: apparmor is enabled and all features are available
Oct 09 20:51:22 hostname snapd[8755]: overlord.go:263: Acquiring state lock file
Oct 09 20:51:22 hostname snapd[8755]: overlord.go:268: Acquired state lock file
Oct 09 20:51:22 hostname snapd[8755]: daemon.go:247: started snapd/2.57.2 (series 16; classic) ubuntu/22.04 (amd64) linux/5.15.0-48-generic.
Oct 09 20:51:22 hostname snapd[8755]: daemon.go:340: adjusting startup timeout by 2m10s (pessimistic estimate of 30s plus 5s per snap)
Oct 09 20:51:22 hostname snapd[8755]: backend.go:135: snapd enabled NFS support, additional implicit network permissions granted
Oct 09 20:51:23 hostname systemd[1]: Started Snap Daemon.
Oct 09 20:54:21 hostname snapd[8755]: storehelpers.go:748: cannot refresh snap "slack": snap has no updates available
Oct 09 21:22:27 hostname snapd[8755]: storehelpers.go:748: cannot refresh: snap has no updates available: "bare", "core", "core18", "core20", "core22", "cups", "discord", "freecad", "gnome-3-28-1804", "gnome-3-34-1804", "gnome-3-38-2004", "gnome-42-2204", "gtk-common-themes", "kde-frameworks-5-91-qt-5-15-3-core20", "micropolis", "skype", "slack", "teams", "zoom-client"
Oct 10 01:56:24 hostname snapd[8755]: storehelpers.go:748: cannot refresh: snap has no updates available: "bare", "core", "core18", "core20", "core22", "cups", "discord", "freecad", "gnome-3-28-1804", "gnome-3-34-1804", "gnome-3-38-2004", "gnome-42-2204", "gtk-common-themes", "kde-frameworks-5-91-qt-5-15-3-core20", "micropolis", "skype", "slack", "teams", "zoom-client"
Oct 10 01:56:24 hostname snapd[8755]: autorefresh.go:540: auto-refresh: all snaps are up-to-date
Oct 10 09:51:24 hostname snapd[8755]: storehelpers.go:748: cannot refresh: snap has no updates available: "bare", "core", "core18", "core20", "core22", "cups", "discord", "freecad", "gnome-3-28-1804", "gnome-3-34-1804", "gnome-3-38-2004", "gnome-42-2204", "gtk-common-themes", "kde-frameworks-5-91-qt-5-15-3-core20", "micropolis", "skype", "slack", "teams", "zoom-client"
Oct 10 09:51:24 hostname snapd[8755]: autorefresh.go:540: auto-refresh: all snaps are up-to-date
```