Snapd postinst script hangs

[Mark Shuttleworth]

On a machine which has been tracking upgrades for a while, I am unable to install new versions of snapd. The install process stalls indefinitely. Processes running suggest this is a hang in the postinst:

~$ ps ax | grep dpkg
   2388 pts/1 Ss+ 0:00 /usr/bin/dpkg --status-fd 25 --configure --pending
   2389 pts/1 S+ 0:00 /bin/sh /var/lib/dpkg/info/snapd.postinst configure 2.43.3+git1.8109f8
   2875 pts/2 S+ 0:00 grep --color=auto dpkg

~$ pstree 2388
dpkg───snapd.postinst───systemctl───systemd-tty-ask

~$ ps ax | grep snapd
    732 ? Ssl 0:00 /usr/lib/snapd/snapd
   2389 pts/1 S+ 0:00 /bin/sh /var/lib/dpkg/info/snapd.postinst configure 2.43.3+git1.8109f8
   2452 pts/1 S+ 0:00 /bin/systemctl start snapd.autoimport.service snapd.core-fixup.service snapd.recovery-chooser-trigger.service snapd.seeded.service snapd.service snapd.snap-repair.timer snapd.socket snapd.system-shutdown.service
   2880 pts/2 S+ 0:00 grep --color=auto snapd

[Paweł Stołowski (stolowski)]

At the moment the main suspect is the systemd-tty-ask (which would block with a password prompt), although it might be a long shot. I've just tried with the latest focal desktop image, there were lots of debs to upgrade (including snapd) but I couldn't reproduce it. The postinst is relatively simple, it just starts all mount units of snaps with a systemctl wrapper.

Could you please:
- paste `pstree -u` output for the pid of systemctl process (the one under 2388's tree)
- paste the output of 'ls -l /proc/<systemctl pid>/fd/0'
- attach /var/log/auth.log

Thank you!

[Paweł Stołowski (stolowski)]

I'm tentatively adding systemd/dpkg.

[Paweł Stołowski (stolowski)]

Also, the list of installed snaps may be relevant in understanding what happens.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Mark Shuttleworth (sabdfl)]

OK, so *now* the situation has cleared on that machine. And there are no snaps installed :/

[Balint Reczey (rbalint)]

@sabdfl How was dpkg started? As root systemctl should not ask for password.

@stolowski The snapd version seems to be a git snapshot, not one from the archive.

Marking as invalid for dpkg and systemd because nothing shows that there would be any issue with their behaviour. Please reopen the bug against one of them if the root cause seem to be in them.

[Paweł Stołowski (stolowski)]

@Mark does 'snap changes' (and then 'snap change <ID>' if you see any failed changes) reveal antyhing interesing? Some of the older focal images had broken seeds that would never succeed, potentially causing other issues.

[Paweł Stołowski (stolowski)]

Ok, reproduced with focal and broken seeds from an older image, symptoms are exactly the same (including ps/pstree output). The problem is caused by blocking on snapd.seeded.service (which waits for seeding to complete, but it's never going to complete with broken seeds).

Given that this is an edge case (we don't expect images with broken seeds) and focal images have been fixed already, I'm lowering the priority. We will discuss what to do to handle this gracefully.

[Mark Shuttleworth (sabdfl)]

Pawel, this is great debugging, thank you. Agree it's an edge case.

Mark

[Silas S. Brown (ssb22)]

Very similar thing happened on Lubuntu 20.04, `apt-get dist-upgrade` said

    Unpacking snapd (2.47.1+20.04) over (2.46.1+20.04) ...
    Setting up snapd (2.47.1+20.04) ...
    Installing new version of config file /etc/apparmor.d/usr.lib.snapd.snap-confine.real ...

and hung. `pstree` just showed `apt-get---dpkg---snapd.postinst` (no children). It ignored `SIGINT` and `SIGTERM`. `ps auxwww` shows

    root 4091 0.0 0.0 2608 1740 pts/1 S+ 09:42 0:00 /bin/sh /var/lib/dpkg/info/snapd.postinst configure 2.46.1+20.04

and `ls -l /proc/4091/fd` gives

    lrwx------ 1 root root 64 Nov 3 11:43 0 -> /dev/pts/1
    l-wx------ 1 root root 64 Nov 3 11:44 1 -> /dev/null
    lr-x------ 1 root root 64 Nov 3 11:44 10 -> /var/lib/dpkg/info/snapd.postinst
    lrwx------ 1 root root 64 Nov 3 11:44 11 -> /dev/pts/1
    lrwx------ 1 root root 64 Nov 3 11:44 2 -> /dev/pts/1

(timestamps being the current time of the `ls`, not the process start time which was about 2 hours earlier) I was connecting to the machine via `ssh` from elsewhere on our home network.

After `kill -9 4091` the parent `dpkg` process was still hung, `ps auxwww` gives:

    root 4090 0.0 0.2 18092 9932 pts/1 Ss+ 09:42 0:00 /usr/bin/dpkg --status-fd 55 --configure --pending

and `ls -l /proc/4090/fd` gives:

    lrwx------ 1 root root 64 Nov 3 11:49 0 -> /dev/pts/1
    lrwx------ 1 root root 64 Nov 3 11:49 1 -> /dev/pts/1
    lrwx------ 1 root root 64 Nov 3 11:49 2 -> /dev/pts/1
    lrwx------ 1 root root 64 Nov 3 11:49 3 -> /var/lib/dpkg/lock
    l-wx------ 1 root root 64 Nov 3 11:49 4 -> /var/lib/dpkg/updates/tmp.i
    lrwx------ 1 root root 64 Nov 3 11:49 5 -> /var/lib/dpkg/triggers/Lock
    l-wx------ 1 root root 64 Nov 3 11:49 55 -> 'pipe:[55607]'
    lr-x------ 1 root root 64 Nov 3 11:49 6 -> /var/lib/dpkg/triggers/Unincorp
    l-wx------ 1 root root 64 Nov 3 11:49 7 -> /var/log/dpkg.log
    lr-x------ 1 root root 64 Nov 3 11:49 8 -> /var/lib/dpkg/diversions

After `kill -9 4090` the original SSH session gets

    E: Sub-process /usr/bin/dpkg exited unexpectedly
    W: Operation was interrupted before it could finish

and dropped back to root prompt. I then tried `dpkg --configure -a` and it apparently went straight through:

    Setting up snapd (2.47.1+20.04) ...
    snapd.failure.service is a disabled or a static unit, not starting it.
    snapd.snap-repair.service is a disabled or a static unit, not starting it.

and then carried on setting up the other packages. So I'm logging the above in the hope that somebody can read more meaning into it than I can.

[Paul Bollerman (paulbollerman)]

As part of our testing cycle we create a LXC container with lxc init ubuntu:20.04 {container}
Running apt update and apt upgrade in this fresh container hangs on snapd postinst as detailed in this bug. We have to support ubuntu 20.04 in our testing, which is why this is a big problem for us. Was there a resolution found?

+ apt update -q
Hit:1 http://archive.ubuntu.com/ubuntu focal InRelease
Get:2 http://archive.ubuntu.com/ubuntu focal-updates InRelease [114 kB]
Get:3 http://archive.ubuntu.com/ubuntu focal-backports InRelease [108 kB]
Get:4 http://security.ubuntu.com/ubuntu focal-security InRelease [114 kB]
Get:5 http://archive.ubuntu.com/ubuntu focal/universe amd64 Packages [8628 kB]
Get:6 http://security.ubuntu.com/ubuntu focal-security/main amd64 Packages [1592 kB]
Get:7 http://archive.ubuntu.com/ubuntu focal/universe Translation-en [5124 kB]
Get:8 http://archive.ubuntu.com/ubuntu focal/universe amd64 c-n-f Metadata [265 kB]
Get:9 http://archive.ubuntu.com/ubuntu focal/multiverse amd64 Packages [144 kB]
Get:10 http://archive.ubuntu.com/ubuntu focal/multiverse Translation-en [104 kB]
Get:11 http://archive.ubuntu.com/ubuntu focal/multiverse amd64 c-n-f Metadata [9136 B]
Get:12 http://archive.ubuntu.com/ubuntu focal-updates/main amd64 Packages [1946 kB]
Get:13 http://security.ubuntu.com/ubuntu focal-security/main Translation-en [271 kB]
Get:14 http://archive.ubuntu.com/ubuntu focal-updates/main Translation-en [352 kB]
Get:15 http://archive.ubuntu.com/ubuntu focal-updates/main amd64 c-n-f Metadata [15.6 kB]
Get:16 http://archive.ubuntu.com/ubuntu focal-updates/restricted amd64 Packages [1141 kB]
Get:17 http://security.ubuntu.com/ubuntu focal-security/main amd64 c-n-f Metadata [10.7 kB]
Get:18 http://security.ubuntu.com/ubuntu focal-security/restricted amd64 Packages [1051 kB]
Get:19 http://archive.ubuntu.com/ubuntu focal-updates/restricted Translation-en [162 kB]
Get:20 http://archive.ubuntu.com/ubuntu focal-updates/restricted amd64 c-n-f Metadata [592 B]
Get:21 http://archive.ubuntu.com/ubuntu focal-updates/universe amd64 Packages [924 kB]
Get:22 http://archive.ubuntu.com/ubuntu focal-updates/universe Translation-en [208 kB]
Get:23 http://archive.ubuntu.com/ubuntu focal-updates/universe amd64 c-n-f Metadata [20.9 kB]
Get:24 http://archive.ubuntu.com/ubuntu focal-updates/multiverse amd64 Packages [24.5 kB]
Get:25 http://archive.ubuntu.com/ubuntu focal-updates/multiverse Translation-en [7336 B]
Get:26 http://archive.ubuntu.com/ubuntu focal-updates/multiverse amd64 c-n-f Metadata [592 B]
Get:27 http://archive.ubuntu.com/ubuntu focal-backports/main amd64 Packages [44.8 kB]
Get:28 http://archive.ubuntu.com/ubuntu focal-backports/main Translation-en [11.3 kB]
Get:29 http://archive.ubuntu.com/ubuntu focal-backports/main amd64 c-n-f Metadata [976 B]
Get:30 http://archive.ubuntu.com/ubuntu focal-backports/restricted amd64 c-n-f Metadata [116 B]
Get:31 http://archive.ubuntu.com/ubuntu focal-backports/universe amd64 Packages [23.7 kB]
Get:32 http://archive.ubuntu.com/ubuntu focal-backports/universe Translation-en [15.9 kB]
Get:33 http://archive.ubuntu.com/ubuntu focal-backports/universe amd64 c-n-f Metadata [860 B]
Get:34 http://archive.ubuntu.com/ubunt...